From ea603b2c9da82ebb5b79d7e9847e7dd492ad873e Mon Sep 17 00:00:00 2001 From: Rob Ede Date: Mon, 26 Sep 2022 01:30:56 +0100 Subject: [PATCH] upgrade status replacer to response replacer --- actix-web/CHANGES.md | 2 +- actix-web/src/middleware/logger.rs | 155 +++++++++++++++++------------ 2 files changed, 92 insertions(+), 65 deletions(-) diff --git a/actix-web/CHANGES.md b/actix-web/CHANGES.md index 9184e01ac..a018bc248 100644 --- a/actix-web/CHANGES.md +++ b/actix-web/CHANGES.md @@ -4,7 +4,7 @@ ### Added - Add `ContentDisposition::attachment` constructor. [#2867] - Add `ErrorHandlers::default_handler()` (as well as `default_handler_{server, client}()`) to make registering handlers for groups of response statuses easier. [#2784] -- Add `Logger::custom_status_replace()`. [#2631] +- Add `Logger::custom_response_replace()`. [#2631] [#2631]: https://github.com/actix/actix-web/pull/2631 [#2784]: https://github.com/actix/actix-web/pull/2784 diff --git a/actix-web/src/middleware/logger.rs b/actix-web/src/middleware/logger.rs index 56fdd7634..5c4d315f1 100644 --- a/actix-web/src/middleware/logger.rs +++ b/actix-web/src/middleware/logger.rs @@ -24,9 +24,9 @@ use time::{format_description::well_known::Rfc3339, OffsetDateTime}; use crate::{ body::{BodySize, MessageBody}, - http::{header::HeaderName, StatusCode}, + http::header::HeaderName, service::{ServiceRequest, ServiceResponse}, - Error, HttpResponse, Result, + Error, Result, }; /// Middleware for logging request and response summaries to the terminal. @@ -69,11 +69,11 @@ use crate::{ /// `%D` | Time taken to serve the request, in milliseconds /// `%U` | Request URL /// `%{r}a` | "Real IP" remote address **\*** -/// `%{FOO}i` | `request.headers["FOO"]` +/// `%{FOO}i` | `request.headers["FOO"]` /// `%{FOO}o` | `response.headers["FOO"]` /// `%{FOO}e` | `env_var["FOO"]` /// `%{FOO}xi` | [Custom request replacement](Logger::custom_request_replace) labelled "FOO" -/// `%{FOO}xs` | [Custom status replacement](Logger::custom_status_replace) labelled "FOO" +/// `%{FOO}xo` | [Custom response replacement](Logger::custom_response_replace) labelled "FOO" /// /// # Security /// **\*** "Real IP" remote address is calculated using @@ -181,46 +181,48 @@ impl Logger { self } - /// Register a function that receives a StatusCode and returns a String for use in the - /// log line. The label passed as the first argument should match a replacement substring in - /// the logger format like `%{label}xs`. + /// Register a function that receives a `ServiceResponse` and returns a string for use in the + /// log line. + /// + /// The label passed as the first argument should match a replacement substring in + /// the logger format like `%{label}xo`. /// /// It is convention to print "-" to indicate no output instead of an empty string. /// + /// The replacement function does not have access to the response body. + /// /// # Examples /// ``` - /// # use actix_web::http::{header::HeaderValue, StatusCode}; - /// # use actix_web::middleware::Logger; - /// fn log_if_error (status: &StatusCode) -> String { - /// if status.as_u16() >= 400 { + /// # use actix_web::{dev::ServiceResponse, middleware::Logger}; + /// fn log_if_error(res: &ServiceResponse) -> String { + /// if res.status().as_u16() >= 400 { /// "ERROR".to_string() /// } else { /// "-".to_string() /// } /// } - /// Logger::new("example %{ERROR_STATUS}xs") - /// .custom_status_replace("ERROR_STATUS", |status| log_if_error(status) ); + /// + /// Logger::new("example %{ERROR_STATUS}xo") + /// .custom_response_replace("ERROR_STATUS", |res| log_if_error(res) ); /// ``` - pub fn custom_status_replace( + pub fn custom_response_replace( mut self, label: &str, - f: impl Fn(&StatusCode) -> String + 'static, + f: impl Fn(&ServiceResponse) -> String + 'static, ) -> Self { let inner = Rc::get_mut(&mut self.0).unwrap(); let ft = inner.format.0.iter_mut().find( - |ft| matches!(ft, FormatText::CustomStatus(unit_label, _) if label == unit_label), + |ft| matches!(ft, FormatText::CustomResponse(unit_label, _) if label == unit_label), ); - if let Some(FormatText::CustomStatus(_, status_fn)) = ft { - // replace into None or previously registered fn using same label - status_fn.replace(CustomStatusFn { + if let Some(FormatText::CustomResponse(_, res_fn)) = ft { + *res_fn = Some(CustomResponseFn { inner_fn: Rc::new(f), }); } else { - // non-printed response replacement function diagnostic debug!( - "Attempted to register custom status logging function for nonexistent label: {}", + "Attempted to register custom response logging function for non-existent label: {}", label ); } @@ -258,17 +260,16 @@ where fn new_transform(&self, service: S) -> Self::Future { for unit in &self.0.format.0 { - // missing request replacement function diagnostic if let FormatText::CustomRequest(label, None) = unit { warn!( - "No custom request replacement function was registered for label \"{}\".", + "No custom request replacement function was registered for label: {}", label ); } - // missing response replacement function diagnostic - if let FormatText::CustomStatus(label, None) = unit { + + if let FormatText::CustomResponse(label, None) = unit { warn!( - "No custom status replacement function was registered for label \"{}\".", + "No custom response replacement function was registered for label: {}", label ); } @@ -363,11 +364,25 @@ where debug!("Error in response: {:?}", error); } - if let Some(ref mut format) = this.format { + let res = if let Some(ref mut format) = this.format { + // to avoid polluting all the Logger types with the body parameter we swap the body + // out temporarily since it's not usable in custom response functions anyway + + let (req, res) = res.into_parts(); + let (res, body) = res.into_parts(); + + let temp_res = ServiceResponse::new(req, res.map_into_boxed_body()); + for unit in &mut format.0 { - unit.render_response(res.response()); + unit.render_response(&temp_res); } - } + + // re-construct original service response + let (req, res) = temp_res.into_parts(); + ServiceResponse::new(req, res.set_body(body)) + } else { + res + }; let time = *this.time; let format = this.format.take(); @@ -454,7 +469,7 @@ impl Format { /// Returns `None` if the format string syntax is incorrect. pub fn new(s: &str) -> Format { log::trace!("Access log format: {}", s); - let fmt = Regex::new(r"%(\{([A-Za-z0-9\-_]+)\}([aioe]|x[is])|[%atPrUsbTD]?)").unwrap(); + let fmt = Regex::new(r"%(\{([A-Za-z0-9\-_]+)\}([aioe]|x[io])|[%atPrUsbTD]?)").unwrap(); let mut idx = 0; let mut results = Vec::new(); @@ -472,7 +487,7 @@ impl Format { if key.as_str() == "r" { FormatText::RealIpRemoteAddr } else { - unreachable!() + unreachable!("regex and code mismatch") } } "i" => { @@ -483,7 +498,7 @@ impl Format { } "e" => FormatText::EnvironHeader(key.as_str().to_owned()), "xi" => FormatText::CustomRequest(key.as_str().to_owned(), None), - "xs" => FormatText::CustomStatus(key.as_str().to_owned(), None), + "xo" => FormatText::CustomResponse(key.as_str().to_owned(), None), _ => unreachable!(), }) } else { @@ -531,7 +546,7 @@ enum FormatText { ResponseHeader(HeaderName), EnvironHeader(String), CustomRequest(String, Option), - CustomStatus(String, Option), + CustomResponse(String, Option), } #[derive(Clone)] @@ -552,19 +567,19 @@ impl fmt::Debug for CustomRequestFn { } #[derive(Clone)] -struct CustomStatusFn { - inner_fn: Rc String>, +struct CustomResponseFn { + inner_fn: Rc String>, } -impl CustomStatusFn { - fn call(&self, sc: &StatusCode) -> String { - (self.inner_fn)(sc) +impl CustomResponseFn { + fn call(&self, res: &ServiceResponse) -> String { + (self.inner_fn)(res) } } -impl fmt::Debug for CustomStatusFn { +impl fmt::Debug for CustomResponseFn { fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { - f.write_str("custom_status_fn") + f.write_str("custom_response_fn") } } @@ -600,11 +615,12 @@ impl FormatText { } } - fn render_response(&mut self, res: &HttpResponse) { + fn render_response(&mut self, res: &ServiceResponse) { match self { FormatText::ResponseStatus => { *self = FormatText::Str(format!("{}", res.status().as_u16())) } + FormatText::ResponseHeader(ref name) => { let s = if let Some(val) = res.headers().get(name) { if let Ok(s) = val.to_str() { @@ -617,14 +633,16 @@ impl FormatText { }; *self = FormatText::Str(s.to_string()) } - FormatText::CustomStatus(_, status_fn) => { - let s = match status_fn { - Some(f) => FormatText::Str(f.call(&res.status())), + + FormatText::CustomResponse(_, status_fn) => { + let text = match status_fn { + Some(status_fn) => FormatText::Str(status_fn.call(res)), None => FormatText::Str("-".to_owned()), }; - *self = s; + *self = text; } + _ => {} } } @@ -709,8 +727,11 @@ mod tests { use actix_utils::future::ok; use super::*; - use crate::http::{header, StatusCode}; - use crate::test::{self, TestRequest}; + use crate::{ + http::{header, StatusCode}, + test::{self, TestRequest}, + HttpResponse, + }; #[actix_rt::test] async fn test_logger() { @@ -773,9 +794,10 @@ mod tests { unit.render_request(now, &req); } - let resp = HttpResponse::build(StatusCode::OK).force_close().finish(); + let req = TestRequest::default().to_http_request(); + let res = ServiceResponse::new(req, HttpResponse::Ok().finish()); for unit in &mut format.0 { - unit.render_response(&resp); + unit.render_response(&res); } let entry_time = OffsetDateTime::now_utc(); @@ -805,9 +827,10 @@ mod tests { unit.render_request(now, &req); } - let resp = HttpResponse::build(StatusCode::OK).force_close().finish(); + let req = TestRequest::default().to_http_request(); + let res = ServiceResponse::new(req, HttpResponse::Ok().force_close().finish()); for unit in &mut format.0 { - unit.render_response(&resp); + unit.render_response(&res); } let render = |fmt: &mut fmt::Formatter<'_>| { @@ -837,9 +860,10 @@ mod tests { unit.render_request(now, &req); } - let resp = HttpResponse::build(StatusCode::OK).force_close().finish(); + let req = TestRequest::default().to_http_request(); + let res = ServiceResponse::new(req, HttpResponse::Ok().force_close().finish()); for unit in &mut format.0 { - unit.render_response(&resp); + unit.render_response(&res); } let entry_time = OffsetDateTime::now_utc(); @@ -866,9 +890,10 @@ mod tests { unit.render_request(now, &req); } - let resp = HttpResponse::build(StatusCode::OK).force_close().finish(); + let req = TestRequest::default().to_http_request(); + let res = ServiceResponse::new(req, HttpResponse::Ok().force_close().finish()); for unit in &mut format.0 { - unit.render_response(&resp); + unit.render_response(&res); } let render = |fmt: &mut fmt::Formatter<'_>| { @@ -897,9 +922,10 @@ mod tests { unit.render_request(now, &req); } - let resp = HttpResponse::build(StatusCode::OK).force_close().finish(); + let req = TestRequest::default().to_http_request(); + let res = ServiceResponse::new(req, HttpResponse::Ok().finish()); for unit in &mut format.0 { - unit.render_response(&resp); + unit.render_response(&res); } let entry_time = OffsetDateTime::now_utc(); @@ -940,11 +966,11 @@ mod tests { } #[actix_rt::test] - async fn test_custom_closure_status_log() { - let mut logger = Logger::new("test %{CUSTOM}xs").custom_status_replace( + async fn test_custom_closure_response_log() { + let mut logger = Logger::new("test %{CUSTOM}xo").custom_response_replace( "CUSTOM", - |sc: &StatusCode| -> String { - if sc.as_u16() == 200 { + |res: &ServiceResponse| -> String { + if res.status().as_u16() == 200 { String::from("custom_log") } else { String::from("-") @@ -954,13 +980,14 @@ mod tests { let mut unit = Rc::get_mut(&mut logger.0).unwrap().format.0[1].clone(); let label = match &unit { - FormatText::CustomStatus(label, _) => label, - ft => panic!("expected CustomStatus, found {:?}", ft), + FormatText::CustomResponse(label, _) => label, + ft => panic!("expected CustomResponse, found {:?}", ft), }; assert_eq!(label, "CUSTOM"); - let resp_ok = HttpResponse::build(StatusCode::OK).force_close().finish(); + let req = TestRequest::default().to_http_request(); + let resp_ok = ServiceResponse::new(req, HttpResponse::Ok().finish()); let now = OffsetDateTime::now_utc(); unit.render_response(&resp_ok);