blockscout_tracing_actix_web/
middleware.rs

1use crate::{DefaultRootSpanBuilder, RequestId, RootSpan, RootSpanBuilder};
2use actix_web::body::{BodySize, MessageBody};
3use actix_web::dev::{Service, ServiceRequest, ServiceResponse, Transform};
4use actix_web::http::StatusCode;
5use actix_web::web::Bytes;
6use actix_web::{Error, HttpMessage, ResponseError};
7use std::future::{ready, Future, Ready};
8use std::pin::Pin;
9use std::task::{Context, Poll};
10use tracing::Span;
11
12/// `TracingLogger` is a middleware to capture structured diagnostic when processing an HTTP request.
13/// Check the crate-level documentation for an in-depth introduction.
14///
15/// `TracingLogger` is designed as a drop-in replacement of [`actix-web`]'s [`Logger`].
16///
17/// # Usage
18///
19/// Register `TracingLogger` as a middleware for your application using `.wrap` on `App`.  
20/// In this example we add a [`tracing::Subscriber`] to output structured logs to the console.
21///
22/// ```rust
23/// use actix_web::App;
24/// use tracing::{Subscriber, subscriber::set_global_default};
25/// use tracing_actix_web::TracingLogger;
26/// use tracing_log::LogTracer;
27/// use tracing_bunyan_formatter::{BunyanFormattingLayer, JsonStorageLayer};
28/// use tracing_subscriber::{layer::SubscriberExt, EnvFilter, Registry};
29///
30/// /// Compose multiple layers into a `tracing`'s subscriber.
31/// pub fn get_subscriber(
32///     name: String,
33///     env_filter: String
34/// ) -> impl Subscriber + Send + Sync {
35///     let env_filter = EnvFilter::try_from_default_env()
36///         .unwrap_or(EnvFilter::new(env_filter));
37///     let formatting_layer = BunyanFormattingLayer::new(
38///         name.into(),
39///         std::io::stdout
40///     );
41///     Registry::default()
42///         .with(env_filter)
43///         .with(JsonStorageLayer)
44///         .with(formatting_layer)
45/// }
46///
47/// /// Register a subscriber as global default to process span data.
48/// ///
49/// /// It should only be called once!
50/// pub fn init_subscriber(subscriber: impl Subscriber + Send + Sync) {
51///     LogTracer::init().expect("Failed to set logger");
52///     set_global_default(subscriber).expect("Failed to set subscriber");
53/// }
54///
55/// fn main() {
56///     let subscriber = get_subscriber("app".into(), "info".into());
57///     init_subscriber(subscriber);
58///
59///     let app = App::new().wrap(TracingLogger::default());
60/// }
61/// ```
62///
63/// Like [`actix-web`]'s [`Logger`], in order to use `TracingLogger` inside a Scope, Resource, or
64/// Condition, the [`Compat`] middleware must be used.
65///
66/// ```rust
67/// use actix_web::middleware::Compat;
68/// use actix_web::{web, App};
69/// use tracing_actix_web::TracingLogger;
70///
71/// let app = App::new()
72///     .service(
73///         web::scope("/some/route")
74///             .wrap(Compat::new(TracingLogger::default())),
75///     );
76/// ```
77///
78/// [`actix-web`]: https://docs.rs/actix-web
79/// [`Logger`]: https://docs.rs/actix-web/4.0.0-beta.13/actix_web/middleware/struct.Logger.html
80/// [`Compat`]: https://docs.rs/actix-web/4.0.0-beta.13/actix_web/middleware/struct.Compat.html
81/// [`tracing`]: https://docs.rs/tracing
82pub struct TracingLogger<RootSpan: RootSpanBuilder> {
83    root_span_builder: std::marker::PhantomData<RootSpan>,
84}
85
86impl<RootSpan: RootSpanBuilder> Clone for TracingLogger<RootSpan> {
87    fn clone(&self) -> Self {
88        Self::new()
89    }
90}
91
92impl Default for TracingLogger<DefaultRootSpanBuilder> {
93    fn default() -> Self {
94        TracingLogger::new()
95    }
96}
97
98impl<RootSpan: RootSpanBuilder> TracingLogger<RootSpan> {
99    pub fn new() -> TracingLogger<RootSpan> {
100        TracingLogger {
101            root_span_builder: Default::default(),
102        }
103    }
104}
105
106impl<S, B, RootSpan> Transform<S, ServiceRequest> for TracingLogger<RootSpan>
107where
108    S: Service<ServiceRequest, Response = ServiceResponse<B>, Error = Error>,
109    S::Future: 'static,
110    B: MessageBody + 'static,
111    RootSpan: RootSpanBuilder,
112{
113    type Response = ServiceResponse<StreamSpan<B>>;
114    type Error = Error;
115    type Transform = TracingLoggerMiddleware<S, RootSpan>;
116    type InitError = ();
117    type Future = Ready<Result<Self::Transform, Self::InitError>>;
118
119    fn new_transform(&self, service: S) -> Self::Future {
120        ready(Ok(TracingLoggerMiddleware {
121            service,
122            root_span_builder: std::marker::PhantomData,
123        }))
124    }
125}
126
127pub struct SkipHttpTrace;
128
129#[doc(hidden)]
130pub struct TracingLoggerMiddleware<S, RootSpanBuilder> {
131    service: S,
132    root_span_builder: std::marker::PhantomData<RootSpanBuilder>,
133}
134
135#[allow(clippy::type_complexity)]
136impl<S, B, RootSpanType> Service<ServiceRequest> for TracingLoggerMiddleware<S, RootSpanType>
137where
138    S: Service<ServiceRequest, Response = ServiceResponse<B>, Error = Error>,
139    S::Future: 'static,
140    B: MessageBody + 'static,
141    RootSpanType: RootSpanBuilder,
142{
143    type Response = ServiceResponse<StreamSpan<B>>;
144    type Error = Error;
145    type Future = TracingResponse<S::Future, RootSpanType>;
146
147    actix_web::dev::forward_ready!(service);
148
149    fn call(&self, req: ServiceRequest) -> Self::Future {
150        req.extensions_mut().insert(RequestId::generate());
151        let root_span = RootSpanType::on_request_start(&req);
152
153        let root_span_wrapper = RootSpan::new(root_span.clone());
154        req.extensions_mut().insert(root_span_wrapper);
155
156        let skip_http_trace = req.extensions().contains::<SkipHttpTrace>();
157
158        let fut = root_span.in_scope(|| {
159            if !skip_http_trace {
160                tracing::info!("Started HTTP request processing");
161            }
162            self.service.call(req)
163        });
164
165        TracingResponse {
166            fut,
167            span: root_span,
168            skip_http_trace,
169            _root_span_type: std::marker::PhantomData,
170        }
171    }
172}
173
174#[doc(hidden)]
175#[pin_project::pin_project]
176pub struct TracingResponse<F, RootSpanType> {
177    #[pin]
178    fut: F,
179    span: Span,
180    skip_http_trace: bool,
181    _root_span_type: std::marker::PhantomData<RootSpanType>,
182}
183
184#[doc(hidden)]
185#[pin_project::pin_project]
186pub struct StreamSpan<B> {
187    #[pin]
188    body: B,
189    span: Span,
190}
191
192impl<F, B, RootSpanType> Future for TracingResponse<F, RootSpanType>
193where
194    F: Future<Output = Result<ServiceResponse<B>, Error>>,
195    B: MessageBody + 'static,
196    RootSpanType: RootSpanBuilder,
197{
198    type Output = Result<ServiceResponse<StreamSpan<B>>, Error>;
199
200    fn poll(self: Pin<&mut Self>, cx: &mut Context<'_>) -> Poll<Self::Output> {
201        let this = self.project();
202
203        let fut = this.fut;
204        let span = this.span;
205        let skip_http_trace = *this.skip_http_trace;
206
207        span.in_scope(|| match fut.poll(cx) {
208            Poll::Pending => Poll::Pending,
209            Poll::Ready(outcome) => {
210                RootSpanType::on_request_end(Span::current(), &outcome);
211
212                if !skip_http_trace {
213                    tracing::info!("Finished HTTP request processing");
214                }
215
216                #[cfg(feature = "emit_event_on_error")]
217                {
218                    emit_event_on_error(&outcome);
219                }
220
221                Poll::Ready(outcome.map(|service_response| {
222                    service_response.map_body(|_, body| StreamSpan {
223                        body,
224                        span: span.clone(),
225                    })
226                }))
227            }
228        })
229    }
230}
231
232impl<B> MessageBody for StreamSpan<B>
233where
234    B: MessageBody,
235{
236    type Error = B::Error;
237
238    fn size(&self) -> BodySize {
239        self.body.size()
240    }
241
242    fn poll_next(
243        self: Pin<&mut Self>,
244        cx: &mut Context<'_>,
245    ) -> Poll<Option<Result<Bytes, Self::Error>>> {
246        let this = self.project();
247
248        let body = this.body;
249        let span = this.span;
250        span.in_scope(|| body.poll_next(cx))
251    }
252}
253
254fn emit_event_on_error<B: 'static>(outcome: &Result<ServiceResponse<B>, actix_web::Error>) {
255    match outcome {
256        Ok(response) => {
257            if let Some(err) = response.response().error() {
258                // use the status code already constructed for the outgoing HTTP response
259                emit_error_event(err.as_response_error(), response.status())
260            }
261        }
262        Err(error) => {
263            let response_error = error.as_response_error();
264            emit_error_event(response_error, response_error.status_code())
265        }
266    }
267}
268
269fn emit_error_event(response_error: &dyn ResponseError, status_code: StatusCode) {
270    let error_msg_prefix = "Error encountered while processing the incoming HTTP request";
271    if status_code.is_client_error() {
272        tracing::warn!("{}: {:?}", error_msg_prefix, response_error);
273    } else {
274        tracing::error!("{}: {:?}", error_msg_prefix, response_error);
275    }
276}