rws_server/log/
mod.rs

1use std::net::SocketAddr;
2use std::thread;
3use crate::entry_point::command_line_args::CommandLineArgument;
4use crate::request::Request;
5use crate::response::Response;
6
7#[cfg(test)]
8mod tests;
9#[doc(hidden)]
10pub mod access_sink;
11pub mod tail;
12
13/// Logging helpers for access logs and server info.
14///
15/// [`Log::combined`] produces standard Combined Log Format lines compatible with
16/// GoAccess, AWStats, and similar tools. All three server code paths (HTTP/1.1,
17/// HTTP/2, HTTP/3) use it.
18pub struct Log;
19
20/// Called for every access-logged request, before the line is written: the
21/// traffic insights (`traffic`, above this layer) set it when enabled.
22static ACCESS_OBSERVER: std::sync::OnceLock<fn(&Request, &Response, std::net::IpAddr)> = std::sync::OnceLock::new();
23
24/// Set the [`Log::log_access`] observer (once; later calls are ignored).
25#[doc(hidden)]
26pub fn set_access_observer(observe: fn(&Request, &Response, std::net::IpAddr)) {
27    let _ = ACCESS_OBSERVER.set(observe);
28}
29
30impl Log {
31    pub fn request_response(request: &Request, response: &Response, peer_addr: &SocketAddr) -> String {
32        let mut request_headers = "".to_string();
33        for header in &request.headers {
34            if &header.name.chars().count() > &0 {
35                request_headers = [
36                    request_headers,
37                    "\n  ".to_string(),
38                    header.name.to_string(),
39                    ": ".to_string(),
40                    header.value.to_string()
41                ].join("");
42            }
43        }
44
45        let mut response_headers = "".to_string();
46        for header in &response.headers {
47            if &header.name.chars().count() > &0 {
48                response_headers = [
49                    response_headers,
50                    "\n  ".to_string(),
51                    header.name.to_string(),
52                    ": ".to_string(),
53                    header.value.to_string()
54                ].join("");
55            }
56        }
57
58        let mut response_body_length = 0;
59        let mut response_body_parts_number = 0;
60        for content_range in &response.content_range_list {
61            let boxed_parse = content_range.size.parse::<i32>();
62            if boxed_parse.is_ok() {
63                response_body_length += boxed_parse.unwrap();
64                response_body_parts_number += 1;
65            }
66        }
67
68        let current_thread = thread::current();
69        let thread_id = current_thread.name().unwrap();
70
71        let log_request_response = format!("\n\nRequest (thread id: {} peer address is {}):\n  {} {} {}  {}\n  Body: {} byte(s) total (including default initialization vector)\nEnd of Request\nResponse:\n  {} {} {}\n\n  Body: {} part(s), {} byte(s) total\nEnd of Response",
72                                           thread_id,
73                                           peer_addr,
74                                           &request.http_version,
75                                           &request.method,
76                                           &request.request_uri,
77                                           request_headers,
78                                           request.body.len(),
79
80                                           &response.status_code,
81                                           &response.reason_phrase,
82                                           response_headers,
83                                           response_body_parts_number,
84                                           response_body_length);
85
86        log_request_response
87    }
88
89    pub fn usage_information() -> String {
90        let mut log = "Usage:\n\n".to_string();
91        let command_line_arg_list = CommandLineArgument::get_command_line_arg_list();
92        for arg in command_line_arg_list {
93            let flags = if arg.short_form.is_empty() {
94                format!("--{}", arg.long_form)
95            } else {
96                format!("-{} or --{}", arg.short_form, arg.long_form)
97            };
98            let argument_info = format!("  {} environment variable\n  {} as command line line argument\n  {}\n\n", arg.environment_variable, flags, arg._hint.unwrap());
99            log = [log, argument_info].join("");
100        }
101        log = [log, "End of usage section\n\n".to_string()].join("");
102        log
103    }
104
105    /// The user rws runs as, for the startup banner: `$USER`, `$LOGNAME` or
106    /// `%USERNAME%`, else `"unknown"`. Deliberately not `whoami` (what
107    /// `FileExt::get_current_user` runs): minimal container images such as
108    /// distroless have no `whoami`, and the banner's `unwrap()` on that
109    /// error crashed the published Docker image at startup.
110    pub fn current_user() -> String {
111        ["USER", "LOGNAME", "USERNAME"]
112            .iter()
113            .find_map(|var| std::env::var(var).ok().filter(|v| !v.trim().is_empty()))
114            .unwrap_or_else(|| "unknown".to_string())
115    }
116
117    pub fn info(name: &str) -> String {
118        let mut log = format!("{}\n", name).to_string();
119        const VERSION: &str = env!("CARGO_PKG_VERSION");
120        const AUTHORS: &str = env!("CARGO_PKG_AUTHORS");
121        const REPOSITORY: &str = env!("CARGO_PKG_REPOSITORY");
122        const DESCRIPTION: &str = env!("CARGO_PKG_DESCRIPTION");
123        const RUST_VERSION: &str = env!("CARGO_PKG_RUST_VERSION");
124        const LICENSE: &str = env!("CARGO_PKG_LICENSE");
125        let user = Log::current_user();
126        let working_directory = crate::app::controller::static_resource::working_directory().to_string();
127
128        let version = format!("Version:           {}\n", VERSION);
129        log = [log, version].join("");
130
131        let authors = format!("Authors:           {}\n", AUTHORS);
132        log = [log, authors].join("");
133
134        let repository = format!("Repository:        {}\n", REPOSITORY);
135        log = [log, repository].join("");
136
137        let description = format!("Description:       {}\n", DESCRIPTION);
138        log = [log, description].join("");
139
140        let rust_version = format!("Rust Version:      {}\n", RUST_VERSION);
141        log = [log, rust_version].join("");
142
143        let license = format!("License:           {}\n", LICENSE);
144        log = [log, license].join("");
145
146        let license = format!("User:              {}\n", user);
147        log = [log, license].join("");
148
149        let license = format!("Working Directory: {}\n", working_directory);
150        log = [log, license].join("");
151
152        log
153    }
154
155    /// Returns a structured JSON log line for one request/response pair:
156    /// `time`, `remote_addr`, `method`, `path`, `protocol`, `status`, `bytes`,
157    /// then `host`, `user_agent` and `referer` when the request has them.
158    ///
159    /// Enable with `RWS_CONFIG_LOG_FORMAT=json`. Useful for log aggregators
160    /// (Loki, Fluentd, Datadog) that ingest JSON from pod stdout.
161    pub fn json(request: &Request, response: &Response, peer_addr: &SocketAddr) -> String {
162        let mut line = Vec::with_capacity(160);
163        Log::write_json(&mut line, request, response, peer_addr);
164        bytes_to_string(line)
165    }
166
167    /// [`Log::json`] appended to `out`, without intermediate strings.
168    fn write_json(out: &mut Vec<u8>, request: &Request, response: &Response, peer_addr: &SocketAddr) {
169        use std::io::Write;
170        let body_size: usize = response.content_range_list.iter().map(|cr| cr.body.len()).sum();
171        out.extend_from_slice(b"{\"time\":\"");
172        with_timestamps(|iso, _| out.extend_from_slice(iso.as_bytes()));
173        out.extend_from_slice(b"\",\"remote_addr\":\"");
174        let _ = write!(out, "{}", peer_addr.ip());
175        out.extend_from_slice(b"\",\"method\":\"");
176        push_json_escaped(out, &request.method);
177        out.extend_from_slice(b"\",\"path\":\"");
178        push_json_escaped(out, &request.request_uri);
179        out.extend_from_slice(b"\",\"protocol\":\"");
180        push_json_escaped(out, &request.http_version);
181        out.extend_from_slice(b"\",\"status\":");
182        let _ = write!(out, "{}", response.status_code);
183        out.extend_from_slice(b",\"bytes\":");
184        out.extend_from_slice(crate::ext::decimal::Decimal::new(body_size as u128).as_str().as_bytes());
185        // Who asked, for what site, from where (18.15.0): only when sent.
186        for (key, name) in [(&b",\"host\":\""[..], "host"), (&b",\"user_agent\":\""[..], "user-agent"), (&b",\"referer\":\""[..], "referer")] {
187            if let Some(header) = request.header(name).filter(|h| !h.value.is_empty()) {
188                out.extend_from_slice(key);
189                push_json_escaped(out, &header.value);
190                out.push(b'"');
191            }
192        }
193        out.push(b'}');
194    }
195
196    /// Writes one access log line to stdout using the format configured by
197    /// `RWS_CONFIG_LOG_FORMAT` (`"combined"` or `"json"`). Call this instead of
198    /// `Log::combined` so that format selection is centralised.
199    ///
200    /// Lines are buffered per thread and written by a background thread every
201    /// 100 ms (and when a thread's buffer passes 32 KiB, when the thread
202    /// exits, and at process exit); [`Log::flush_access_log`] writes them now.
203    pub fn log_access(request: &Request, response: &Response, peer_addr: &SocketAddr) {
204        // The client behind a trusted proxy (`ip_filter::client_ip`), not the
205        // proxy; only looked up when the request says it was forwarded.
206        let client;
207        let peer_addr = if request.header("x-forwarded-for").is_some() || request.header("forwarded").is_some() {
208            client = crate::ip_filter::client_ip(request, &peer_addr.ip().to_string())
209                .parse::<std::net::IpAddr>()
210                .map_or(*peer_addr, |ip| SocketAddr::new(ip, peer_addr.port()));
211            &client
212        } else {
213            peer_addr
214        };
215        // Traffic insights count every request, whether lines are written.
216        if let Some(observe) = ACCESS_OBSERVER.get() {
217            observe(request, response, peer_addr.ip());
218        }
219        let config = crate::server_config::ServerConfig::current();
220        let format = &config.log_format;
221        if format.eq_ignore_ascii_case("off") || format.eq_ignore_ascii_case("none") {
222            return;
223        }
224        let json = format == "json";
225        access_sink::write_line(|out| {
226            if json {
227                Log::write_json(out, request, response, peer_addr)
228            } else {
229                Log::write_combined(out, request, response, peer_addr)
230            }
231        });
232    }
233
234    /// Have `SIGUSR1` reopen the access-log file (`RWS_CONFIG_ACCESS_LOG`)
235    /// before its next write, for logrotate; does nothing when the log goes
236    /// to stdout. The `rws` binary calls it at startup.
237    pub fn reopen_access_log_on_sigusr1() {
238        access_sink::install_reopen_signal();
239    }
240
241    /// Reopen the access-log file before its next write — what `SIGUSR1`
242    /// does, for a program that moves the file itself.
243    pub fn reopen_access_log() {
244        access_sink::reopen();
245    }
246
247    /// Write out the buffered access-log lines now (they're otherwise written
248    /// within 100 ms) — e.g. before exiting without returning from `main`.
249    pub fn flush_access_log() {
250        access_sink::flush();
251    }
252
253    /// The access-log line for `RWS_CONFIG_LOG_FORMAT`: `json` (the `rws`
254    /// binary's default), Combined Log Format for any other value (including
255    /// unset, in library use), or `None` for `off`/`none` — no per-request
256    /// line, e.g. behind a proxy that already logs or when benchmarking.
257    /// Taken from `ServerConfig::current()`, so it's hot-reloadable.
258    pub fn access_log_line(request: &Request, response: &Response, peer_addr: &SocketAddr) -> Option<String> {
259        let config = crate::server_config::ServerConfig::current();
260        let format = &config.log_format;
261        if format.eq_ignore_ascii_case("off") || format.eq_ignore_ascii_case("none") {
262            return None;
263        }
264        Some(if format == "json" {
265            Log::json(request, response, peer_addr)
266        } else {
267            Log::combined(request, response, peer_addr)
268        })
269    }
270
271    fn format_iso8601(secs: u64) -> String {
272        let sec = secs % 60;
273        let min = (secs / 60) % 60;
274        let hour = (secs / 3600) % 24;
275        let days = secs / 86400;
276        let (year, month, day) = Log::days_to_ymd(days);
277        format!("{:04}-{:02}-{:02}T{:02}:{:02}:{:02}Z", year, month, day, hour, min, sec)
278    }
279
280    /// Returns a Combined Log Format (CLF) line for one request/response pair:
281    /// `IP - - [DD/Mon/YYYY:HH:MM:SS +0000] "METHOD URI VERSION" STATUS SIZE`
282    pub fn combined(request: &Request, response: &Response, peer_addr: &SocketAddr) -> String {
283        let mut line = Vec::with_capacity(128);
284        Log::write_combined(&mut line, request, response, peer_addr);
285        bytes_to_string(line)
286    }
287
288    /// [`Log::combined`] appended to `out`, without intermediate strings.
289    fn write_combined(out: &mut Vec<u8>, request: &Request, response: &Response, peer_addr: &SocketAddr) {
290        use std::io::Write;
291        let body_size: usize = response.content_range_list.iter().map(|cr| cr.body.len()).sum();
292        let _ = write!(out, "{}", peer_addr.ip());
293        out.extend_from_slice(b" - - [");
294        with_timestamps(|_, clf| out.extend_from_slice(clf.as_bytes()));
295        out.extend_from_slice(b"] \"");
296        out.extend_from_slice(request.method.as_bytes());
297        out.push(b' ');
298        out.extend_from_slice(request.request_uri.as_bytes());
299        out.push(b' ');
300        out.extend_from_slice(request.http_version.as_bytes());
301        out.extend_from_slice(b"\" ");
302        let _ = write!(out, "{}", response.status_code);
303        out.push(b' ');
304        if body_size > 0 {
305            out.extend_from_slice(crate::ext::decimal::Decimal::new(body_size as u128).as_str().as_bytes());
306        } else {
307            out.push(b'-');
308        }
309    }
310
311    fn format_clf_timestamp(secs: u64) -> String {
312        let sec = secs % 60;
313        let min = (secs / 60) % 60;
314        let hour = (secs / 3600) % 24;
315        let days = secs / 86400;
316        let (year, month, day) = Log::days_to_ymd(days);
317        const MONTHS: [&str; 12] = ["Jan","Feb","Mar","Apr","May","Jun","Jul","Aug","Sep","Oct","Nov","Dec"];
318        format!("{:02}/{}/{:04}:{:02}:{:02}:{:02} +0000",
319            day, MONTHS[(month - 1) as usize], year, hour, min, sec)
320    }
321
322    fn days_to_ymd(days: u64) -> (u64, u64, u64) {
323        let z = days + 719468;
324        let era = z / 146097;
325        let doe = z % 146097;
326        let yoe = (doe - doe / 1460 + doe / 36524 - doe / 146096) / 365;
327        let y = yoe + era * 400;
328        let doy = doe - (365 * yoe + yoe / 4 - yoe / 100);
329        let mp = (5 * doy + 2) / 153;
330        let d = doy - (153 * mp + 2) / 5 + 1;
331        let m = if mp < 10 { mp + 3 } else { mp - 9 };
332        let y = if m <= 2 { y + 1 } else { y };
333        (y, m, d)
334    }
335
336    pub fn server_url_thread_count(protocol: &str, bind_addr: &String, thread_count: i32) -> String {
337        let url = format!("Server is up and running at: {}://{}\n", protocol, &bind_addr);
338        let thread_count = format!("Spawned {} thread(s) to handle incoming requests\n", thread_count);
339        [url, thread_count].join("")
340    }
341}
342/// The current second as ISO 8601 (`2026-10-29T12:00:00Z`), cached per
343/// thread like the access log's.
344#[doc(hidden)]
345pub fn iso8601_now(use_it: impl FnOnce(&str)) {
346    with_timestamps(|iso, _| use_it(iso));
347}
348
349/// The current second's ISO 8601 and Combined Log Format timestamps,
350/// formatted at most once per second per thread.
351fn with_timestamps(use_them: impl FnOnce(&str, &str)) {
352    use std::cell::RefCell;
353    use std::time::{SystemTime, UNIX_EPOCH};
354    thread_local! {
355        static CACHED: RefCell<(u64, String, String)> = const { RefCell::new((u64::MAX, String::new(), String::new())) };
356    }
357    let secs = SystemTime::now().duration_since(UNIX_EPOCH).unwrap_or_default().as_secs();
358    CACHED.with(|cached| {
359        let mut cached = cached.borrow_mut();
360        if cached.0 != secs {
361            *cached = (secs, Log::format_iso8601(secs), Log::format_clf_timestamp(secs));
362        }
363        use_them(&cached.1, &cached.2);
364    });
365}
366
367/// `s` JSON-escaped as the access log always did it: backslash, double
368/// quote, newline and carriage return.
369fn push_json_escaped(out: &mut Vec<u8>, s: &str) {
370    for b in s.bytes() {
371        match b {
372            b'\\' => out.extend_from_slice(b"\\\\"),
373            b'"' => out.extend_from_slice(b"\\\""),
374            b'\n' => out.extend_from_slice(b"\\n"),
375            b'\r' => out.extend_from_slice(b"\\r"),
376            _ => out.push(b),
377        }
378    }
379}
380
381/// A line built only from `&str` pieces is UTF-8.
382fn bytes_to_string(bytes: Vec<u8>) -> String {
383    String::from_utf8(bytes).unwrap_or_else(|e| String::from_utf8_lossy(e.as_bytes()).into_owned())
384}
rws_server/log/mod.rs

rws_server/log/
mod.rs
