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

timvw_rust_runtime/
trace.rs
