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}