rouille/
log.rs

1// Copyright (c) 2016 The Rouille developers
2// Licensed under the Apache License, Version 2.0
3// <LICENSE-APACHE or
4// http://www.apache.org/licenses/LICENSE-2.0> or the MIT
5// license <LICENSE-MIT or http://opensource.org/licenses/MIT>,
6// at your option. All files in the project carrying such
7// notice may not be copied, modified, or distributed except
8// according to those terms.
9
10use std::io::Write;
11use std::panic;
12use std::time::Duration;
13use std::time::Instant;
14
15use chrono;
16
17use Request;
18use Response;
19
20/// Adds a log entry to the given writer for each request.
21///
22/// Writes a line to the given "writer" after processing each request.
23/// Log line info has the format:
24/// `"{%Y-%m-%d %H:%M%S%.6f} UTC - {METHOD} {URL} - {ELAPSED_TIME} - {RESP_SATUS}"`
25///
26/// If you would like to customize the log output or functionality (such as integrating
27/// with the [`log`](https://docs.rs/log) crate, see [`rouille::log_custom`](fn.log_custom.html))
28///
29/// # Example
30///
31/// ```
32/// use std::io;
33/// use rouille::{Request, Response};
34///
35/// fn handle(request: &Request) -> Response {
36///     rouille::log(request, io::stdout(), || {
37///         Response::text("hello world")
38///     })
39/// }
40/// ```
41pub fn log<W, F>(rq: &Request, mut output: W, f: F) -> Response
42where
43    W: Write,
44    F: FnOnce() -> Response,
45{
46    let start_instant = Instant::now();
47    let rq_line = format!(
48        "{} UTC - {} {}",
49        chrono::Utc::now().format("%Y-%m-%d %H:%M:%S%.6f"),
50        rq.method(),
51        rq.raw_url()
52    );
53
54    // Calling the handler and catching potential panics.
55    // Note that this we always resume unwinding afterwards, we can ignore the small panic-safety
56    // mechanism of `catch_unwind`.
57    let response = panic::catch_unwind(panic::AssertUnwindSafe(f));
58
59    let elapsed_time = format_time(start_instant.elapsed());
60
61    match response {
62        Ok(response) => {
63            let _ = writeln!(
64                output,
65                "{} - {} - {}",
66                rq_line, elapsed_time, response.status_code
67            );
68            response
69        }
70        Err(payload) => {
71            // There is probably no point in printing the payload, as this is done by the panic
72            // handler.
73            let _ = writeln!(output, "{} - {} - PANIC!", rq_line, elapsed_time);
74            panic::resume_unwind(payload);
75        }
76    }
77}
78
79/// Calls custom logging functions after processing a request.
80///
81/// This is nearly identical to the [`rouille::log`](fn.log.html) function except it
82/// takes two logging functions that will be called with access to the request/response
83/// structs and the total execution duration of the handler.
84///
85/// # Example
86///
87/// ```
88/// #[macro_use] extern crate log;
89/// extern crate chrono;
90/// # extern crate rouille;
91/// use rouille::{Request, Response};
92///
93///
94/// fn handle(request: &Request) -> Response {
95///     let now = chrono::Utc::now().format("%Y-%m-%d %H:%M:%S%.6f");
96///     let log_ok = |req: &Request, resp: &Response, _elap: std::time::Duration| {
97///         info!("{} {} {}", now, req.method(), req.raw_url());
98///     };
99///     let log_err = |req: &Request, _elap: std::time::Duration| {
100///         error!("{} Handler panicked: {} {}", now, req.method(), req.raw_url());
101///     };
102///     rouille::log_custom(request, log_ok, log_err, || {
103///         Response::text("hello world")
104///     })
105/// }
106/// #
107/// # fn main() { }
108/// ```
109pub fn log_custom<L, E, F>(req: &Request, log_ok_f: L, log_err_f: E, handler: F) -> Response
110where
111    L: Fn(&Request, &Response, Duration),
112    E: Fn(&Request, Duration),
113    F: FnOnce() -> Response,
114{
115    let start_instant = Instant::now();
116
117    // Call the handler and catch panics.
118    // Note that we always resume unwinding afterwards.
119    // We can ignore the small panic-safety mechanism of `catch_unwind`.
120    let response = panic::catch_unwind(panic::AssertUnwindSafe(handler));
121    let elapsed = start_instant.elapsed();
122
123    match response {
124        Ok(response) => {
125            log_ok_f(req, &response, elapsed);
126            response
127        }
128        Err(payload) => {
129            log_err_f(req, elapsed);
130            // The panic handler will print the payload contents
131            panic::resume_unwind(payload);
132        }
133    }
134}
135
136fn format_time(duration: Duration) -> String {
137    let secs_part = match duration.as_secs().checked_mul(1_000_000_000) {
138        Some(v) => v,
139        None => return format!("{}s", duration.as_secs() as f64),
140    };
141
142    let duration_in_ns = secs_part + u64::from(duration.subsec_nanos());
143
144    if duration_in_ns < 1_000 {
145        format!("{}ns", duration_in_ns)
146    } else if duration_in_ns < 1_000_000 {
147        format!("{:.1}us", duration_in_ns as f64 / 1_000.0)
148    } else if duration_in_ns < 1_000_000_000 {
149        format!("{:.1}ms", duration_in_ns as f64 / 1_000_000.0)
150    } else {
151        format!("{:.1}s", duration_in_ns as f64 / 1_000_000_000.0)
152    }
153}