Skip to main content

timvw_rust_runtime/
trace.rs

1//! Logs every request with [`tracing`](https://docs.rs/tracing) (feature `tracing`).
2//!
3//! [`TraceLayer`] opens a `http.request` span per request, with the method and the URL without its query (a query can
4//! hold an API key), and records the status and duration when the response arrives:
5//!
6//! - a response below `500`: an event at `DEBUG`;
7//! - a `5xx` response or a failure to send: an event at `WARN`.
8//!
9//! Events have the target `timvw_rust_runtime::trace`, so `RUST_LOG=timvw_rust_runtime=debug` shows every request.
10//! With the `retry` feature, [`RetryPolicy`](crate::retry::RetryPolicy) logs each retry at `DEBUG` too.
11//!
12//! ```no_run
13//! # #[cfg(feature = "reqwest")]
14//! # fn demo() {
15//! use timvw_rust_runtime::{trace::TraceLayer, Client};
16//!
17//! let client = Client::default().layer(TraceLayer::new());
18//! # }
19//! ```
20//!
21//! Headers and bodies are not logged. For more (headers, custom spans, OpenTelemetry), use `tower-http`'s
22//! `TraceLayer`; it works with [`Client::layer`](crate::Client::layer) too.
23
24use std::fmt;
25use std::future::Future;
26use std::pin::Pin;
27use std::task::{Context, Poll};
28use std::time::Instant;
29
30use tower::{Layer, Service};
31use tracing::Instrument;
32
33/// A tower layer that logs each request and its outcome. See the [module](self) documentation.
34#[derive(Clone, Copy, Debug, Default)]
35pub struct TraceLayer {
36    _private: (),
37}
38
39impl TraceLayer {
40    /// The layer.
41    pub fn new() -> Self {
42        Self::default()
43    }
44}
45
46impl<S> Layer<S> for TraceLayer {
47    type Service = TraceService<S>;
48
49    fn layer(&self, inner: S) -> Self::Service {
50        TraceService { inner }
51    }
52}
53
54/// The service of a [`TraceLayer`].
55#[derive(Clone, Debug)]
56pub struct TraceService<S> {
57    inner: S,
58}
59
60impl<S, ReqBody, ResBody> Service<http::Request<ReqBody>> for TraceService<S>
61where
62    S: Service<http::Request<ReqBody>, Response = http::Response<ResBody>>,
63    S::Error: fmt::Display,
64    S::Future: Send + 'static,
65{
66    type Response = S::Response;
67    type Error = S::Error;
68    type Future = Pin<Box<dyn Future<Output = Result<S::Response, S::Error>> + Send>>;
69
70    fn poll_ready(&mut self, cx: &mut Context<'_>) -> Poll<Result<(), Self::Error>> {
71        self.inner.poll_ready(cx)
72    }
73
74    fn call(&mut self, request: http::Request<ReqBody>) -> Self::Future {
75        let uri = request.uri();
76        let url = format!(
77            "{}://{}{}",
78            uri.scheme_str().unwrap_or("http"),
79            uri.authority().map(|a| a.as_str()).unwrap_or(""),
80            uri.path()
81        );
82        let span = tracing::debug_span!(
83            "http.request",
84            http.request.method = %request.method(),
85            url.full = %url,
86            http.response.status_code = tracing::field::Empty,
87        );
88        let start = Instant::now();
89        let future = {
90            let _entered = span.enter();
91            self.inner.call(request)
92        };
93        let instrumented = span.clone();
94        Box::pin(
95            async move {
96                let result = future.await;
97                let elapsed_ms = start.elapsed().as_millis() as u64;
98                match &result {
99                    Ok(response) => {
100                        let status = response.status();
101                        span.record("http.response.status_code", status.as_u16());
102                        if status.is_server_error() {
103                            tracing::warn!(status = status.as_u16(), elapsed_ms, "response");
104                        } else {
105                            tracing::debug!(status = status.as_u16(), elapsed_ms, "response");
106                        }
107                    }
108                    Err(error) => tracing::warn!(%error, elapsed_ms, "request failed"),
109                }
110                result
111            }
112            .instrument(instrumented),
113        )
114    }
115}