Skip to main content

leyline/
trace.rs

1use std::fmt;
2use std::future::Future;
3use std::sync::Arc;
4use std::sync::atomic::{AtomicU64, Ordering};
5use std::time::{Duration, Instant};
6
7use crate::{Error, HttpVersion};
8
9mod headers;
10
11pub(crate) use headers::masked;
12
13#[derive(Debug)]
14#[non_exhaustive]
15pub struct Dns<'a> {
16    pub id: u64,
17    pub host: &'a str,
18    pub port: u16,
19    pub addrs: usize,
20    pub elapsed: Duration,
21}
22
23#[derive(Debug)]
24#[non_exhaustive]
25pub struct Connect<'a> {
26    pub id: u64,
27    pub host: &'a str,
28    pub port: u16,
29    pub reused: bool,
30    pub elapsed: Duration,
31}
32
33#[derive(Debug)]
34#[non_exhaustive]
35pub struct Tls<'a> {
36    pub id: u64,
37    pub host: &'a str,
38    pub version: Option<&'a str>,
39    pub cipher: Option<&'a str>,
40    pub alpn: Option<&'a str>,
41    pub elapsed: Duration,
42}
43
44#[non_exhaustive]
45pub struct Sent<'a> {
46    pub id: u64,
47    pub host: &'a str,
48    pub method: &'a str,
49    pub path: &'a str,
50    pub protocol: HttpVersion,
51    pub elapsed: Duration,
52}
53
54impl std::fmt::Debug for Sent<'_> {
55    fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
56        f.debug_struct("Sent")
57            .field("id", &self.id)
58            .field("host", &self.host)
59            .field("method", &self.method)
60            .field("path", &crate::util::redact_target(self.path))
61            .field("protocol", &self.protocol)
62            .field("elapsed", &self.elapsed)
63            .finish()
64    }
65}
66
67#[non_exhaustive]
68pub struct Head<'a> {
69    pub id: u64,
70    pub host: &'a str,
71    pub status: u16,
72    pub protocol: HttpVersion,
73    pub elapsed: Duration,
74    pub headers: &'a http::HeaderMap,
75}
76
77impl fmt::Debug for Head<'_> {
78    fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
79        f.debug_struct("Head")
80            .field("id", &self.id)
81            .field("host", &self.host)
82            .field("status", &self.status)
83            .field("protocol", &self.protocol)
84            .field("elapsed", &self.elapsed)
85            .field(
86                "headers",
87                &masked(self.headers.iter().map(|(k, v)| (k.as_str(), v.as_bytes()))),
88            )
89            .finish()
90    }
91}
92
93#[derive(Debug)]
94#[non_exhaustive]
95pub struct Done<'a> {
96    pub id: u64,
97    pub elapsed: Duration,
98    pub outcome: Result<(), &'a Error>,
99}
100
101#[expect(
102    unused_variables,
103    reason = "no-op defaults keep the event name visible in the rendered signature"
104)]
105pub trait Trace: Send + Sync + 'static {
106    fn dns(&self, ev: &Dns<'_>) {}
107    fn connect(&self, ev: &Connect<'_>) {}
108    fn tls(&self, ev: &Tls<'_>) {}
109    fn sent(&self, ev: &Sent<'_>) {}
110    fn head(&self, ev: &Head<'_>) {}
111    fn done(&self, ev: &Done<'_>) {}
112}
113
114#[derive(Clone)]
115pub(crate) struct Ctx {
116    hook: Arc<dyn Trace>,
117    id: u64,
118    start: Instant,
119}
120
121tokio::task_local! {
122    static CURRENT: Ctx;
123}
124
125static NEXT: AtomicU64 = AtomicU64::new(1);
126
127pub(crate) async fn scope<F>(hook: Option<&Arc<dyn Trace>>, fut: F) -> F::Output
128where
129    F: Future,
130{
131    match hook {
132        Some(hook) => {
133            let ctx = Ctx {
134                hook: Arc::clone(hook),
135                id: NEXT.fetch_add(1, Ordering::Relaxed),
136                start: Instant::now(),
137            };
138            CURRENT.scope(ctx, fut).await
139        }
140        None => fut.await,
141    }
142}
143
144pub(crate) fn carry<F>(fut: F) -> impl Future<Output = F::Output> + Send
145where
146    F: Future + Send,
147{
148    let ctx = CURRENT.try_with(Clone::clone).ok();
149    async move {
150        match ctx {
151            Some(ctx) => CURRENT.scope(ctx, fut).await,
152            None => fut.await,
153        }
154    }
155}
156
157pub(crate) fn on() -> bool {
158    CURRENT.try_with(|_| ()).is_ok()
159}
160
161fn with(emit: impl FnOnce(&Ctx)) {
162    CURRENT.try_with(emit).unwrap_or(())
163}
164
165pub(crate) fn dns(host: &str, port: u16, addrs: usize, elapsed: Duration) {
166    with(|ctx| {
167        ctx.hook.dns(&Dns {
168            id: ctx.id,
169            host,
170            port,
171            addrs,
172            elapsed,
173        });
174    });
175}
176
177pub(crate) fn connect(host: &str, port: u16, reused: bool, elapsed: Duration) {
178    with(|ctx| {
179        ctx.hook.connect(&Connect {
180            id: ctx.id,
181            host,
182            port,
183            reused,
184            elapsed,
185        });
186    });
187}
188
189pub(crate) fn tls(
190    host: &str,
191    version: Option<&str>,
192    cipher: Option<&str>,
193    alpn: Option<&str>,
194    elapsed: Duration,
195) {
196    with(|ctx| {
197        ctx.hook.tls(&Tls {
198            id: ctx.id,
199            host,
200            version,
201            cipher,
202            alpn,
203            elapsed,
204        });
205    });
206}
207
208pub(crate) fn sent(host: &str, method: &str, path: &str, protocol: HttpVersion, elapsed: Duration) {
209    with(|ctx| {
210        ctx.hook.sent(&Sent {
211            id: ctx.id,
212            host,
213            method,
214            path,
215            protocol,
216            elapsed,
217        });
218    });
219}
220
221pub(crate) fn head<I, N, V>(
222    host: &str,
223    status: u16,
224    protocol: HttpVersion,
225    elapsed: Duration,
226    headers: I,
227) where
228    I: IntoIterator<Item = (N, V)>,
229    N: AsRef<[u8]>,
230    V: Into<bytes::Bytes>,
231{
232    with(|ctx| {
233        let headers = crate::core::header_map(headers);
234        ctx.hook.head(&Head {
235            id: ctx.id,
236            host,
237            status,
238            protocol,
239            elapsed,
240            headers: &headers,
241        });
242    });
243}
244
245pub(crate) fn done(outcome: Result<(), &Error>) {
246    with(|ctx| {
247        ctx.hook.done(&Done {
248            id: ctx.id,
249            elapsed: ctx.start.elapsed(),
250            outcome,
251        });
252    });
253}
254
255#[derive(Debug, Default, Clone, Copy)]
256pub struct TracingTrace;
257
258impl Trace for TracingTrace {
259    fn dns(&self, ev: &Dns<'_>) {
260        tracing::debug!(target: "leyline::trace", id = ev.id, host = ev.host, port = ev.port, addrs = ev.addrs, elapsed_ms = ms(ev.elapsed), "dns");
261    }
262
263    fn connect(&self, ev: &Connect<'_>) {
264        tracing::debug!(target: "leyline::trace", id = ev.id, host = ev.host, port = ev.port, reused = ev.reused, elapsed_ms = ms(ev.elapsed), "connect");
265    }
266
267    fn tls(&self, ev: &Tls<'_>) {
268        tracing::debug!(target: "leyline::trace", id = ev.id, host = ev.host, version = ev.version, cipher = ev.cipher, alpn = ev.alpn, elapsed_ms = ms(ev.elapsed), "tls");
269    }
270
271    fn sent(&self, ev: &Sent<'_>) {
272        tracing::debug!(target: "leyline::trace", id = ev.id, host = ev.host, method = ev.method, path = %crate::util::redact_target(ev.path), protocol = ?ev.protocol, elapsed_ms = ms(ev.elapsed), "sent");
273    }
274
275    fn head(&self, ev: &Head<'_>) {
276        tracing::debug!(target: "leyline::trace", id = ev.id, host = ev.host, status = ev.status, protocol = ?ev.protocol, elapsed_ms = ms(ev.elapsed), "head");
277    }
278
279    fn done(&self, ev: &Done<'_>) {
280        match ev.outcome {
281            Ok(()) => {
282                tracing::debug!(target: "leyline::trace", id = ev.id, elapsed_ms = ms(ev.elapsed), "done")
283            }
284            Err(e) => {
285                tracing::debug!(target: "leyline::trace", id = ev.id, elapsed_ms = ms(ev.elapsed), kind = ?e.kind(), error = %e, "done")
286            }
287        }
288    }
289}
290
291fn ms(d: Duration) -> u32 {
292    u32::try_from(d.as_millis()).unwrap_or(u32::MAX)
293}
294
295impl<T: Trace> Trace for Arc<T> {
296    fn dns(&self, ev: &Dns<'_>) {
297        T::dns(self, ev);
298    }
299
300    fn connect(&self, ev: &Connect<'_>) {
301        T::connect(self, ev);
302    }
303
304    fn tls(&self, ev: &Tls<'_>) {
305        T::tls(self, ev);
306    }
307
308    fn sent(&self, ev: &Sent<'_>) {
309        T::sent(self, ev);
310    }
311
312    fn head(&self, ev: &Head<'_>) {
313        T::head(self, ev);
314    }
315
316    fn done(&self, ev: &Done<'_>) {
317        T::done(self, ev);
318    }
319}
320
321#[cfg(test)]
322mod tests;