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::task::{Context, Poll};
26#[cfg(not(target_family = "wasm"))]
27use std::time::Instant;
28
29use tower::{Layer, Service};
30use tracing::Instrument;
31#[cfg(target_family = "wasm")]
32use web_time::Instant;
33
34use crate::maybe::BoxFuture;
35use crate::MaybeSend;
36
37/// A tower layer that logs each request and its outcome. See the [module](self) documentation.
38#[derive(Clone, Copy, Debug, Default)]
39pub struct TraceLayer {
40    _private: (),
41}
42
43impl TraceLayer {
44    /// The layer.
45    pub fn new() -> Self {
46        Self::default()
47    }
48}
49
50impl<S> Layer<S> for TraceLayer {
51    type Service = TraceService<S>;
52
53    fn layer(&self, inner: S) -> Self::Service {
54        TraceService { inner }
55    }
56}
57
58/// The service of a [`TraceLayer`].
59#[derive(Clone, Debug)]
60pub struct TraceService<S> {
61    inner: S,
62}
63
64impl<S, ReqBody, ResBody> Service<http::Request<ReqBody>> for TraceService<S>
65where
66    S: Service<http::Request<ReqBody>, Response = http::Response<ResBody>>,
67    S::Error: fmt::Display,
68    S::Future: MaybeSend + 'static,
69{
70    type Response = S::Response;
71    type Error = S::Error;
72    type Future = BoxFuture<'static, Result<S::Response, S::Error>>;
73
74    fn poll_ready(&mut self, cx: &mut Context<'_>) -> Poll<Result<(), Self::Error>> {
75        self.inner.poll_ready(cx)
76    }
77
78    fn call(&mut self, request: http::Request<ReqBody>) -> Self::Future {
79        let uri = request.uri();
80        let url = format!(
81            "{}://{}{}",
82            uri.scheme_str().unwrap_or("http"),
83            uri.authority().map(|a| a.as_str()).unwrap_or(""),
84            uri.path()
85        );
86        let span = tracing::debug_span!(
87            "http.request",
88            http.request.method = %request.method(),
89            url.full = %url,
90            http.response.status_code = tracing::field::Empty,
91        );
92        let start = Instant::now();
93        let future = {
94            let _entered = span.enter();
95            self.inner.call(request)
96        };
97        let instrumented = span.clone();
98        Box::pin(
99            async move {
100                let result = future.await;
101                let elapsed_ms = start.elapsed().as_millis() as u64;
102                match &result {
103                    Ok(response) => {
104                        let status = response.status();
105                        span.record("http.response.status_code", status.as_u16());
106                        if status.is_server_error() {
107                            tracing::warn!(status = status.as_u16(), elapsed_ms, "response");
108                        } else {
109                            tracing::debug!(status = status.as_u16(), elapsed_ms, "response");
110                        }
111                    }
112                    Err(error) => tracing::warn!(%error, elapsed_ms, "request failed"),
113                }
114                result
115            }
116            .instrument(instrumented),
117        )
118    }
119}