actix_web/middleware/
logger.rs

1//! For middleware documentation, see [`Logger`].
2
3use std::{
4    borrow::Cow,
5    collections::HashSet,
6    env,
7    fmt::{self, Display as _},
8    future::Future,
9    marker::PhantomData,
10    pin::Pin,
11    rc::Rc,
12    task::{Context, Poll},
13};
14
15use actix_service::{Service, Transform};
16use actix_utils::future::{ready, Ready};
17use bytes::Bytes;
18use futures_core::ready;
19use log::{debug, warn};
20use pin_project_lite::pin_project;
21#[cfg(feature = "unicode")]
22use regex::Regex;
23#[cfg(not(feature = "unicode"))]
24use regex_lite::Regex;
25use time::{format_description::well_known::Rfc3339, OffsetDateTime};
26
27use crate::{
28    body::{BodySize, MessageBody},
29    http::header::HeaderName,
30    service::{ServiceRequest, ServiceResponse},
31    Error, Result,
32};
33
34/// Middleware for logging request and response summaries to the terminal.
35///
36/// This middleware uses the `log` crate to output information. Enable `log`'s output for the
37/// "actix_web" scope using [`env_logger`](https://docs.rs/env_logger) or similar crate.
38///
39/// # Default Format
40/// The [`default`](Logger::default) Logger uses the following format:
41///
42/// ```plain
43/// %a "%r" %s %b "%{Referer}i" "%{User-Agent}i" %T
44///
45/// Example Output:
46/// 127.0.0.1:54278 "GET /test HTTP/1.1" 404 20 "-" "HTTPie/2.2.0" 0.001074
47/// ```
48///
49/// # Examples
50/// ```
51/// use actix_web::{middleware::Logger, App};
52///
53/// // access logs are printed with the INFO level so ensure it is enabled by default
54/// env_logger::init_from_env(env_logger::Env::new().default_filter_or("info"));
55///
56/// let app = App::new()
57///     // .wrap(Logger::default())
58///     .wrap(Logger::new("%a %{User-Agent}i"));
59/// ```
60///
61/// # Format
62/// Variable | Description
63/// -------- | -----------
64/// `%%` | The percent sign
65/// `%a` | Peer IP address (or IP address of reverse proxy if used)
66/// `%t` | Time when the request started processing (in RFC 3339 format)
67/// `%r` | First line of request (Example: `GET /test HTTP/1.1`)
68/// `%s` | Response status code
69/// `%b` | Size of response in bytes, including HTTP headers
70/// `%T` | Time taken to serve the request, in seconds to 6 decimal places
71/// `%D` | Time taken to serve the request, in milliseconds
72/// `%U` | Request URL
73/// `%{r}a` | "Real IP" remote address **\***
74/// `%{FOO}i` | `request.headers["FOO"]`
75/// `%{FOO}o` | `response.headers["FOO"]`
76/// `%{FOO}e` | `env_var["FOO"]`
77/// `%{FOO}xi` | [Custom request replacement](Logger::custom_request_replace) labelled "FOO"
78/// `%{FOO}xo` | [Custom response replacement](Logger::custom_response_replace) labelled "FOO"
79///
80/// # Security
81/// **\*** "Real IP" remote address is calculated using
82/// [`ConnectionInfo::realip_remote_addr()`](crate::dev::ConnectionInfo::realip_remote_addr())
83///
84/// If you use this value, ensure that all requests come from trusted hosts. Otherwise, it is
85/// trivial for the remote client to falsify their source IP address.
86#[derive(Debug)]
87pub struct Logger(Rc<Inner>);
88
89#[derive(Debug, Clone)]
90struct Inner {
91    format: Format,
92    exclude: HashSet<String>,
93    exclude_regex: Vec<Regex>,
94    log_target: Cow<'static, str>,
95}
96
97impl Logger {
98    /// Create `Logger` middleware with the specified `format`.
99    pub fn new(format: &str) -> Logger {
100        Logger(Rc::new(Inner {
101            format: Format::new(format),
102            exclude: HashSet::new(),
103            exclude_regex: Vec::new(),
104            log_target: Cow::Borrowed(module_path!()),
105        }))
106    }
107
108    /// Ignore and do not log access info for specified path.
109    pub fn exclude<T: Into<String>>(mut self, path: T) -> Self {
110        Rc::get_mut(&mut self.0)
111            .unwrap()
112            .exclude
113            .insert(path.into());
114        self
115    }
116
117    /// Ignore and do not log access info for paths that match regex.
118    pub fn exclude_regex<T: Into<String>>(mut self, path: T) -> Self {
119        let inner = Rc::get_mut(&mut self.0).unwrap();
120        inner.exclude_regex.push(Regex::new(&path.into()).unwrap());
121        self
122    }
123
124    /// Sets the logging target to `target`.
125    ///
126    /// By default, the log target is `module_path!()` of the log call location. In our case, that
127    /// would be `actix_web::middleware::logger`.
128    ///
129    /// # Examples
130    /// Using `.log_target("http_log")` would have this effect on request logs:
131    /// ```diff
132    /// - [2015-10-21T07:28:00Z INFO  actix_web::middleware::logger] 127.0.0.1 "GET / HTTP/1.1" 200 88 "-" "dmc/1.0" 0.001985
133    /// + [2015-10-21T07:28:00Z INFO  http_log] 127.0.0.1 "GET / HTTP/1.1" 200 88 "-" "dmc/1.0" 0.001985
134    ///                               ^^^^^^^^
135    /// ```
136    pub fn log_target(mut self, target: impl Into<Cow<'static, str>>) -> Self {
137        let inner = Rc::get_mut(&mut self.0).unwrap();
138        inner.log_target = target.into();
139        self
140    }
141
142    /// Register a function that receives a ServiceRequest and returns a String for use in the
143    /// log line. The label passed as the first argument should match a replacement substring in
144    /// the logger format like `%{label}xi`.
145    ///
146    /// It is convention to print "-" to indicate no output instead of an empty string.
147    ///
148    /// # Examples
149    /// ```
150    /// # use actix_web::http::{header::HeaderValue};
151    /// # use actix_web::middleware::Logger;
152    /// # fn parse_jwt_id (_req: Option<&HeaderValue>) -> String { "jwt_uid".to_owned() }
153    /// Logger::new("example %{JWT_ID}xi")
154    ///     .custom_request_replace("JWT_ID", |req| parse_jwt_id(req.headers().get("Authorization")));
155    /// ```
156    pub fn custom_request_replace(
157        mut self,
158        label: &str,
159        f: impl Fn(&ServiceRequest) -> String + 'static,
160    ) -> Self {
161        let inner = Rc::get_mut(&mut self.0).unwrap();
162
163        let ft = inner.format.0.iter_mut().find(
164            |ft| matches!(ft, FormatText::CustomRequest(unit_label, _) if label == unit_label),
165        );
166
167        if let Some(FormatText::CustomRequest(_, request_fn)) = ft {
168            // replace into None or previously registered fn using same label
169            request_fn.replace(CustomRequestFn {
170                inner_fn: Rc::new(f),
171            });
172        } else {
173            // non-printed request replacement function diagnostic
174            debug!(
175                "Attempted to register custom request logging function for nonexistent label: {}",
176                label
177            );
178        }
179
180        self
181    }
182
183    /// Register a function that receives a `ServiceResponse` and returns a string for use in the
184    /// log line.
185    ///
186    /// The label passed as the first argument should match a replacement substring in
187    /// the logger format like `%{label}xo`.
188    ///
189    /// It is convention to print "-" to indicate no output instead of an empty string.
190    ///
191    /// The replacement function does not have access to the response body.
192    ///
193    /// # Examples
194    /// ```
195    /// # use actix_web::{dev::ServiceResponse, middleware::Logger};
196    /// fn log_if_error(res: &ServiceResponse) -> String {
197    ///     if res.status().as_u16() >= 400 {
198    ///         "ERROR".to_string()
199    ///     } else {
200    ///         "-".to_string()
201    ///     }
202    /// }
203    ///
204    /// Logger::new("example %{ERROR_STATUS}xo")
205    ///     .custom_response_replace("ERROR_STATUS", |res| log_if_error(res) );
206    /// ```
207    pub fn custom_response_replace(
208        mut self,
209        label: &str,
210        f: impl Fn(&ServiceResponse) -> String + 'static,
211    ) -> Self {
212        let inner = Rc::get_mut(&mut self.0).unwrap();
213
214        let ft = inner.format.0.iter_mut().find(
215            |ft| matches!(ft, FormatText::CustomResponse(unit_label, _) if label == unit_label),
216        );
217
218        if let Some(FormatText::CustomResponse(_, res_fn)) = ft {
219            *res_fn = Some(CustomResponseFn {
220                inner_fn: Rc::new(f),
221            });
222        } else {
223            debug!(
224                "Attempted to register custom response logging function for non-existent label: {}",
225                label
226            );
227        }
228
229        self
230    }
231}
232
233impl Default for Logger {
234    /// Create `Logger` middleware with format:
235    ///
236    /// ```plain
237    /// %a "%r" %s %b "%{Referer}i" "%{User-Agent}i" %T
238    /// ```
239    fn default() -> Logger {
240        Logger(Rc::new(Inner {
241            format: Format::default(),
242            exclude: HashSet::new(),
243            exclude_regex: Vec::new(),
244            log_target: Cow::Borrowed(module_path!()),
245        }))
246    }
247}
248
249impl<S, B> Transform<S, ServiceRequest> for Logger
250where
251    S: Service<ServiceRequest, Response = ServiceResponse<B>, Error = Error>,
252    B: MessageBody,
253{
254    type Response = ServiceResponse<StreamLog<B>>;
255    type Error = Error;
256    type Transform = LoggerMiddleware<S>;
257    type InitError = ();
258    type Future = Ready<Result<Self::Transform, Self::InitError>>;
259
260    fn new_transform(&self, service: S) -> Self::Future {
261        for unit in &self.0.format.0 {
262            if let FormatText::CustomRequest(label, None) = unit {
263                warn!(
264                    "No custom request replacement function was registered for label: {}",
265                    label
266                );
267            }
268
269            if let FormatText::CustomResponse(label, None) = unit {
270                warn!(
271                    "No custom response replacement function was registered for label: {}",
272                    label
273                );
274            }
275        }
276
277        ready(Ok(LoggerMiddleware {
278            service,
279            inner: Rc::clone(&self.0),
280        }))
281    }
282}
283
284/// Logger middleware service.
285pub struct LoggerMiddleware<S> {
286    inner: Rc<Inner>,
287    service: S,
288}
289
290impl<S, B> Service<ServiceRequest> for LoggerMiddleware<S>
291where
292    S: Service<ServiceRequest, Response = ServiceResponse<B>, Error = Error>,
293    B: MessageBody,
294{
295    type Response = ServiceResponse<StreamLog<B>>;
296    type Error = Error;
297    type Future = LoggerResponse<S, B>;
298
299    actix_service::forward_ready!(service);
300
301    fn call(&self, req: ServiceRequest) -> Self::Future {
302        let excluded = self.inner.exclude.contains(req.path())
303            || self
304                .inner
305                .exclude_regex
306                .iter()
307                .any(|r| r.is_match(req.path()));
308
309        if excluded {
310            LoggerResponse {
311                fut: self.service.call(req),
312                format: None,
313                time: OffsetDateTime::now_utc(),
314                log_target: Cow::Borrowed(""),
315                _phantom: PhantomData,
316            }
317        } else {
318            let now = OffsetDateTime::now_utc();
319            let mut format = self.inner.format.clone();
320
321            for unit in &mut format.0 {
322                unit.render_request(now, &req);
323            }
324
325            LoggerResponse {
326                fut: self.service.call(req),
327                format: Some(format),
328                time: now,
329                log_target: self.inner.log_target.clone(),
330                _phantom: PhantomData,
331            }
332        }
333    }
334}
335
336pin_project! {
337    pub struct LoggerResponse<S, B>
338    where
339        B: MessageBody,
340        S: Service<ServiceRequest>,
341    {
342        #[pin]
343        fut: S::Future,
344        time: OffsetDateTime,
345        format: Option<Format>,
346        log_target: Cow<'static, str>,
347        _phantom: PhantomData<B>,
348    }
349}
350
351impl<S, B> Future for LoggerResponse<S, B>
352where
353    B: MessageBody,
354    S: Service<ServiceRequest, Response = ServiceResponse<B>, Error = Error>,
355{
356    type Output = Result<ServiceResponse<StreamLog<B>>, Error>;
357
358    fn poll(self: Pin<&mut Self>, cx: &mut Context<'_>) -> Poll<Self::Output> {
359        let this = self.project();
360
361        let res = match ready!(this.fut.poll(cx)) {
362            Ok(res) => res,
363            Err(err) => return Poll::Ready(Err(err)),
364        };
365
366        if let Some(error) = res.response().error() {
367            debug!("Error in response: {:?}", error);
368        }
369
370        let res = if let Some(ref mut format) = this.format {
371            // to avoid polluting all the Logger types with the body parameter we swap the body
372            // out temporarily since it's not usable in custom response functions anyway
373
374            let (req, res) = res.into_parts();
375            let (res, body) = res.into_parts();
376
377            let temp_res = ServiceResponse::new(req, res.map_into_boxed_body());
378
379            for unit in &mut format.0 {
380                unit.render_response(&temp_res);
381            }
382
383            // re-construct original service response
384            let (req, res) = temp_res.into_parts();
385            ServiceResponse::new(req, res.set_body(body))
386        } else {
387            res
388        };
389
390        let time = *this.time;
391        let format = this.format.take();
392        let log_target = this.log_target.clone();
393
394        Poll::Ready(Ok(res.map_body(move |_, body| StreamLog {
395            body,
396            time,
397            format,
398            size: 0,
399            log_target,
400        })))
401    }
402}
403
404pin_project! {
405    pub struct StreamLog<B> {
406        #[pin]
407        body: B,
408        format: Option<Format>,
409        size: usize,
410        time: OffsetDateTime,
411        log_target: Cow<'static, str>,
412    }
413
414    impl<B> PinnedDrop for StreamLog<B> {
415        fn drop(this: Pin<&mut Self>) {
416            if let Some(ref format) = this.format {
417                let render = |fmt: &mut fmt::Formatter<'_>| {
418                    for unit in &format.0 {
419                        unit.render(fmt, this.size, this.time)?;
420                    }
421                    Ok(())
422                };
423
424                log::info!(
425                    target: this.log_target.as_ref(),
426                    "{}", FormatDisplay(&render)
427                );
428            }
429        }
430    }
431}
432
433impl<B: MessageBody> MessageBody for StreamLog<B> {
434    type Error = B::Error;
435
436    #[inline]
437    fn size(&self) -> BodySize {
438        self.body.size()
439    }
440
441    fn poll_next(
442        self: Pin<&mut Self>,
443        cx: &mut Context<'_>,
444    ) -> Poll<Option<Result<Bytes, Self::Error>>> {
445        let this = self.project();
446
447        match ready!(this.body.poll_next(cx)) {
448            Some(Ok(chunk)) => {
449                *this.size += chunk.len();
450                Poll::Ready(Some(Ok(chunk)))
451            }
452            Some(Err(err)) => Poll::Ready(Some(Err(err))),
453            None => Poll::Ready(None),
454        }
455    }
456}
457
458/// A formatting style for the `Logger` consisting of multiple concatenated `FormatText` items.
459#[derive(Debug, Clone)]
460struct Format(Vec<FormatText>);
461
462impl Default for Format {
463    /// Return the default formatting style for the `Logger`:
464    fn default() -> Format {
465        Format::new(r#"%a "%r" %s %b "%{Referer}i" "%{User-Agent}i" %T"#)
466    }
467}
468
469impl Format {
470    /// Create a `Format` from a format string.
471    ///
472    /// Returns `None` if the format string syntax is incorrect.
473    pub fn new(s: &str) -> Format {
474        log::trace!("Access log format: {}", s);
475        let fmt = Regex::new(r"%(\{([A-Za-z0-9\-_]+)\}([aioe]|x[io])|[%atPrUsbTD]?)").unwrap();
476
477        let mut idx = 0;
478        let mut results = Vec::new();
479        for cap in fmt.captures_iter(s) {
480            let m = cap.get(0).unwrap();
481            let pos = m.start();
482            if idx != pos {
483                results.push(FormatText::Str(s[idx..pos].to_owned()));
484            }
485            idx = m.end();
486
487            if let Some(key) = cap.get(2) {
488                results.push(match cap.get(3).unwrap().as_str() {
489                    "a" => {
490                        if key.as_str() == "r" {
491                            FormatText::RealIpRemoteAddr
492                        } else {
493                            unreachable!("regex and code mismatch")
494                        }
495                    }
496                    "i" => FormatText::RequestHeader(HeaderName::try_from(key.as_str()).unwrap()),
497                    "o" => FormatText::ResponseHeader(HeaderName::try_from(key.as_str()).unwrap()),
498                    "e" => FormatText::EnvironHeader(key.as_str().to_owned()),
499                    "xi" => FormatText::CustomRequest(key.as_str().to_owned(), None),
500                    "xo" => FormatText::CustomResponse(key.as_str().to_owned(), None),
501                    _ => unreachable!(),
502                })
503            } else {
504                let m = cap.get(1).unwrap();
505                results.push(match m.as_str() {
506                    "%" => FormatText::Percent,
507                    "a" => FormatText::RemoteAddr,
508                    "t" => FormatText::RequestTime,
509                    "r" => FormatText::RequestLine,
510                    "s" => FormatText::ResponseStatus,
511                    "b" => FormatText::ResponseSize,
512                    "U" => FormatText::UrlPath,
513                    "T" => FormatText::Time,
514                    "D" => FormatText::TimeMillis,
515                    _ => FormatText::Str(m.as_str().to_owned()),
516                });
517            }
518        }
519        if idx != s.len() {
520            results.push(FormatText::Str(s[idx..].to_owned()));
521        }
522
523        Format(results)
524    }
525}
526
527/// A string of text to be logged.
528///
529/// This is either one of the data fields supported by the `Logger`, or a custom `String`.
530#[non_exhaustive]
531#[derive(Debug, Clone)]
532enum FormatText {
533    Str(String),
534    Percent,
535    RequestLine,
536    RequestTime,
537    ResponseStatus,
538    ResponseSize,
539    Time,
540    TimeMillis,
541    RemoteAddr,
542    RealIpRemoteAddr,
543    UrlPath,
544    RequestHeader(HeaderName),
545    ResponseHeader(HeaderName),
546    EnvironHeader(String),
547    CustomRequest(String, Option<CustomRequestFn>),
548    CustomResponse(String, Option<CustomResponseFn>),
549}
550
551#[derive(Clone)]
552struct CustomRequestFn {
553    inner_fn: Rc<dyn Fn(&ServiceRequest) -> String>,
554}
555
556impl CustomRequestFn {
557    fn call(&self, req: &ServiceRequest) -> String {
558        (self.inner_fn)(req)
559    }
560}
561
562impl fmt::Debug for CustomRequestFn {
563    fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
564        f.write_str("custom_request_fn")
565    }
566}
567
568#[derive(Clone)]
569struct CustomResponseFn {
570    inner_fn: Rc<dyn Fn(&ServiceResponse) -> String>,
571}
572
573impl CustomResponseFn {
574    fn call(&self, res: &ServiceResponse) -> String {
575        (self.inner_fn)(res)
576    }
577}
578
579impl fmt::Debug for CustomResponseFn {
580    fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
581        f.write_str("custom_response_fn")
582    }
583}
584
585impl FormatText {
586    fn render(
587        &self,
588        fmt: &mut fmt::Formatter<'_>,
589        size: usize,
590        entry_time: OffsetDateTime,
591    ) -> Result<(), fmt::Error> {
592        match self {
593            FormatText::Str(ref string) => fmt.write_str(string),
594            FormatText::Percent => "%".fmt(fmt),
595            FormatText::ResponseSize => size.fmt(fmt),
596            FormatText::Time => {
597                let rt = OffsetDateTime::now_utc() - entry_time;
598                let rt = rt.as_seconds_f64();
599                fmt.write_fmt(format_args!("{:.6}", rt))
600            }
601            FormatText::TimeMillis => {
602                let rt = OffsetDateTime::now_utc() - entry_time;
603                let rt = (rt.whole_nanoseconds() as f64) / 1_000_000.0;
604                fmt.write_fmt(format_args!("{:.6}", rt))
605            }
606            FormatText::EnvironHeader(ref name) => {
607                if let Ok(val) = env::var(name) {
608                    fmt.write_fmt(format_args!("{}", val))
609                } else {
610                    "-".fmt(fmt)
611                }
612            }
613            _ => Ok(()),
614        }
615    }
616
617    fn render_response(&mut self, res: &ServiceResponse) {
618        match self {
619            FormatText::ResponseStatus => {
620                *self = FormatText::Str(format!("{}", res.status().as_u16()))
621            }
622
623            FormatText::ResponseHeader(ref name) => {
624                let s = if let Some(val) = res.headers().get(name) {
625                    val.to_str().unwrap_or("-")
626                } else {
627                    "-"
628                };
629                *self = FormatText::Str(s.to_string())
630            }
631
632            FormatText::CustomResponse(_, res_fn) => {
633                let text = match res_fn {
634                    Some(res_fn) => FormatText::Str(res_fn.call(res)),
635                    None => FormatText::Str("-".to_owned()),
636                };
637
638                *self = text;
639            }
640
641            _ => {}
642        }
643    }
644
645    fn render_request(&mut self, now: OffsetDateTime, req: &ServiceRequest) {
646        match self {
647            FormatText::RequestLine => {
648                *self = if req.query_string().is_empty() {
649                    FormatText::Str(format!(
650                        "{} {} {:?}",
651                        req.method(),
652                        req.path(),
653                        req.version()
654                    ))
655                } else {
656                    FormatText::Str(format!(
657                        "{} {}?{} {:?}",
658                        req.method(),
659                        req.path(),
660                        req.query_string(),
661                        req.version()
662                    ))
663                };
664            }
665            FormatText::UrlPath => *self = FormatText::Str(req.path().to_string()),
666            FormatText::RequestTime => *self = FormatText::Str(now.format(&Rfc3339).unwrap()),
667            FormatText::RequestHeader(ref name) => {
668                let s = if let Some(val) = req.headers().get(name) {
669                    val.to_str().unwrap_or("-")
670                } else {
671                    "-"
672                };
673                *self = FormatText::Str(s.to_string());
674            }
675            FormatText::RemoteAddr => {
676                let s = if let Some(peer) = req.connection_info().peer_addr() {
677                    FormatText::Str((*peer).to_string())
678                } else {
679                    FormatText::Str("-".to_string())
680                };
681                *self = s;
682            }
683            FormatText::RealIpRemoteAddr => {
684                let s = if let Some(remote) = req.connection_info().realip_remote_addr() {
685                    FormatText::Str(remote.to_string())
686                } else {
687                    FormatText::Str("-".to_string())
688                };
689                *self = s;
690            }
691            FormatText::CustomRequest(_, request_fn) => {
692                let s = match request_fn {
693                    Some(f) => FormatText::Str(f.call(req)),
694                    None => FormatText::Str("-".to_owned()),
695                };
696
697                *self = s;
698            }
699            _ => {}
700        }
701    }
702}
703
704/// Converter to get a String from something that writes to a Formatter.
705pub(crate) struct FormatDisplay<'a>(&'a dyn Fn(&mut fmt::Formatter<'_>) -> Result<(), fmt::Error>);
706
707impl fmt::Display for FormatDisplay<'_> {
708    fn fmt(&self, fmt: &mut fmt::Formatter<'_>) -> Result<(), fmt::Error> {
709        (self.0)(fmt)
710    }
711}
712
713#[cfg(test)]
714mod tests {
715    use actix_service::IntoService;
716    use actix_utils::future::ok;
717
718    use super::*;
719    use crate::{
720        http::{header, StatusCode},
721        test::{self, TestRequest},
722        HttpResponse,
723    };
724
725    #[actix_rt::test]
726    async fn test_logger() {
727        let srv = |req: ServiceRequest| {
728            ok(req.into_response(
729                HttpResponse::build(StatusCode::OK)
730                    .insert_header(("X-Test", "ttt"))
731                    .finish(),
732            ))
733        };
734        let logger = Logger::new("%% %{User-Agent}i %{X-Test}o %{HOME}e %D test");
735
736        let srv = logger.new_transform(srv.into_service()).await.unwrap();
737
738        let req = TestRequest::default()
739            .insert_header((
740                header::USER_AGENT,
741                header::HeaderValue::from_static("ACTIX-WEB"),
742            ))
743            .to_srv_request();
744        let _res = srv.call(req).await;
745    }
746
747    #[actix_rt::test]
748    async fn test_logger_exclude_regex() {
749        let srv = |req: ServiceRequest| {
750            ok(req.into_response(
751                HttpResponse::build(StatusCode::OK)
752                    .insert_header(("X-Test", "ttt"))
753                    .finish(),
754            ))
755        };
756        let logger =
757            Logger::new("%% %{User-Agent}i %{X-Test}o %{HOME}e %D test").exclude_regex("\\w");
758
759        let srv = logger.new_transform(srv.into_service()).await.unwrap();
760
761        let req = TestRequest::default()
762            .insert_header((
763                header::USER_AGENT,
764                header::HeaderValue::from_static("ACTIX-WEB"),
765            ))
766            .to_srv_request();
767        let _res = srv.call(req).await.unwrap();
768    }
769
770    #[actix_rt::test]
771    async fn test_escape_percent() {
772        let mut format = Format::new("%%{r}a");
773
774        let req = TestRequest::default()
775            .insert_header((
776                header::FORWARDED,
777                header::HeaderValue::from_static("for=192.0.2.60;proto=http;by=203.0.113.43"),
778            ))
779            .to_srv_request();
780
781        let now = OffsetDateTime::now_utc();
782        for unit in &mut format.0 {
783            unit.render_request(now, &req);
784        }
785
786        let req = TestRequest::default().to_http_request();
787        let res = ServiceResponse::new(req, HttpResponse::Ok().finish());
788        for unit in &mut format.0 {
789            unit.render_response(&res);
790        }
791
792        let entry_time = OffsetDateTime::now_utc();
793        let render = |fmt: &mut fmt::Formatter<'_>| {
794            for unit in &format.0 {
795                unit.render(fmt, 1024, entry_time)?;
796            }
797            Ok(())
798        };
799        let s = format!("{}", FormatDisplay(&render));
800        assert_eq!(s, "%{r}a");
801    }
802
803    #[actix_rt::test]
804    async fn test_url_path() {
805        let mut format = Format::new("%T %U");
806        let req = TestRequest::default()
807            .insert_header((
808                header::USER_AGENT,
809                header::HeaderValue::from_static("ACTIX-WEB"),
810            ))
811            .uri("/test/route/yeah")
812            .to_srv_request();
813
814        let now = OffsetDateTime::now_utc();
815        for unit in &mut format.0 {
816            unit.render_request(now, &req);
817        }
818
819        let req = TestRequest::default().to_http_request();
820        let res = ServiceResponse::new(req, HttpResponse::Ok().force_close().finish());
821        for unit in &mut format.0 {
822            unit.render_response(&res);
823        }
824
825        let render = |fmt: &mut fmt::Formatter<'_>| {
826            for unit in &format.0 {
827                unit.render(fmt, 1024, now)?;
828            }
829            Ok(())
830        };
831        let s = format!("{}", FormatDisplay(&render));
832        assert!(s.contains("/test/route/yeah"));
833    }
834
835    #[actix_rt::test]
836    async fn test_default_format() {
837        let mut format = Format::default();
838
839        let req = TestRequest::default()
840            .insert_header((
841                header::USER_AGENT,
842                header::HeaderValue::from_static("ACTIX-WEB"),
843            ))
844            .peer_addr("127.0.0.1:8081".parse().unwrap())
845            .to_srv_request();
846
847        let now = OffsetDateTime::now_utc();
848        for unit in &mut format.0 {
849            unit.render_request(now, &req);
850        }
851
852        let req = TestRequest::default().to_http_request();
853        let res = ServiceResponse::new(req, HttpResponse::Ok().force_close().finish());
854        for unit in &mut format.0 {
855            unit.render_response(&res);
856        }
857
858        let entry_time = OffsetDateTime::now_utc();
859        let render = |fmt: &mut fmt::Formatter<'_>| {
860            for unit in &format.0 {
861                unit.render(fmt, 1024, entry_time)?;
862            }
863            Ok(())
864        };
865        let s = format!("{}", FormatDisplay(&render));
866        assert!(s.contains("GET / HTTP/1.1"));
867        assert!(s.contains("127.0.0.1"));
868        assert!(s.contains("200 1024"));
869        assert!(s.contains("ACTIX-WEB"));
870    }
871
872    #[actix_rt::test]
873    async fn test_request_time_format() {
874        let mut format = Format::new("%t");
875        let req = TestRequest::default().to_srv_request();
876
877        let now = OffsetDateTime::now_utc();
878        for unit in &mut format.0 {
879            unit.render_request(now, &req);
880        }
881
882        let req = TestRequest::default().to_http_request();
883        let res = ServiceResponse::new(req, HttpResponse::Ok().force_close().finish());
884        for unit in &mut format.0 {
885            unit.render_response(&res);
886        }
887
888        let render = |fmt: &mut fmt::Formatter<'_>| {
889            for unit in &format.0 {
890                unit.render(fmt, 1024, now)?;
891            }
892            Ok(())
893        };
894        let s = format!("{}", FormatDisplay(&render));
895        assert!(s.contains(&now.format(&Rfc3339).unwrap()));
896    }
897
898    #[actix_rt::test]
899    async fn test_remote_addr_format() {
900        let mut format = Format::new("%{r}a");
901
902        let req = TestRequest::default()
903            .insert_header((
904                header::FORWARDED,
905                header::HeaderValue::from_static("for=192.0.2.60;proto=http;by=203.0.113.43"),
906            ))
907            .to_srv_request();
908
909        let now = OffsetDateTime::now_utc();
910        for unit in &mut format.0 {
911            unit.render_request(now, &req);
912        }
913
914        let req = TestRequest::default().to_http_request();
915        let res = ServiceResponse::new(req, HttpResponse::Ok().finish());
916        for unit in &mut format.0 {
917            unit.render_response(&res);
918        }
919
920        let entry_time = OffsetDateTime::now_utc();
921        let render = |fmt: &mut fmt::Formatter<'_>| {
922            for unit in &format.0 {
923                unit.render(fmt, 1024, entry_time)?;
924            }
925            Ok(())
926        };
927        let s = format!("{}", FormatDisplay(&render));
928        assert!(s.contains("192.0.2.60"));
929    }
930
931    #[actix_rt::test]
932    async fn test_custom_closure_req_log() {
933        let mut logger = Logger::new("test %{CUSTOM}xi")
934            .custom_request_replace("CUSTOM", |_req: &ServiceRequest| -> String {
935                String::from("custom_log")
936            });
937        let mut unit = Rc::get_mut(&mut logger.0).unwrap().format.0[1].clone();
938
939        let label = match &unit {
940            FormatText::CustomRequest(label, _) => label,
941            ft => panic!("expected CustomRequest, found {:?}", ft),
942        };
943
944        assert_eq!(label, "CUSTOM");
945
946        let req = TestRequest::default().to_srv_request();
947        let now = OffsetDateTime::now_utc();
948
949        unit.render_request(now, &req);
950
951        let render = |fmt: &mut fmt::Formatter<'_>| unit.render(fmt, 1024, now);
952
953        let log_output = FormatDisplay(&render).to_string();
954        assert_eq!(log_output, "custom_log");
955    }
956
957    #[actix_rt::test]
958    async fn test_custom_closure_response_log() {
959        let mut logger = Logger::new("test %{CUSTOM}xo").custom_response_replace(
960            "CUSTOM",
961            |res: &ServiceResponse| -> String {
962                if res.status().as_u16() == 200 {
963                    String::from("custom_log")
964                } else {
965                    String::from("-")
966                }
967            },
968        );
969        let mut unit = Rc::get_mut(&mut logger.0).unwrap().format.0[1].clone();
970
971        let label = match &unit {
972            FormatText::CustomResponse(label, _) => label,
973            ft => panic!("expected CustomResponse, found {:?}", ft),
974        };
975
976        assert_eq!(label, "CUSTOM");
977
978        let req = TestRequest::default().to_http_request();
979        let resp_ok = ServiceResponse::new(req, HttpResponse::Ok().finish());
980        let now = OffsetDateTime::now_utc();
981        unit.render_response(&resp_ok);
982
983        let render = |fmt: &mut fmt::Formatter<'_>| unit.render(fmt, 1024, now);
984
985        let log_output = FormatDisplay(&render).to_string();
986        assert_eq!(log_output, "custom_log");
987    }
988
989    #[actix_rt::test]
990    async fn test_closure_logger_in_middleware() {
991        let captured = "custom log replacement";
992
993        let logger = Logger::new("%{CUSTOM}xi")
994            .custom_request_replace("CUSTOM", move |_req: &ServiceRequest| -> String {
995                captured.to_owned()
996            });
997
998        let srv = logger.new_transform(test::ok_service()).await.unwrap();
999
1000        let req = TestRequest::default().to_srv_request();
1001        srv.call(req).await.unwrap();
1002    }
1003}
actix_web/middleware/logger.rs

actix_web/middleware/
logger.rs
