tracing_log/
lib.rs

1//! Adapters for connecting unstructured log records from the `log` crate into
2//! the `tracing` ecosystem.
3//!
4//! # Overview
5//!
6//! [`tracing`] is a framework for instrumenting Rust programs with context-aware,
7//! structured, event-based diagnostic information. This crate provides
8//! compatibility layers for using `tracing` alongside the logging facade provided
9//! by the [`log`] crate.
10//!
11//! This crate provides:
12//!
13//! - [`AsTrace`] and [`AsLog`] traits for converting between `tracing` and `log` types.
14//! - [`LogTracer`], a [`log::Log`] implementation that consumes [`log::Record`]s
15//!   and outputs them as [`tracing::Event`].
16//!
17//! *Compiler support: [requires `rustc` 1.65+][msrv]*
18//!
19//! [msrv]: #supported-rust-versions
20//!
21//! # Usage
22//!
23//! ## Convert log records to tracing `Event`s
24//!
25//! To convert [`log::Record`]s as [`tracing::Event`]s, set `LogTracer` as the default
26//! logger by calling its [`init`] or [`init_with_filter`] methods.
27//!
28//! ```rust
29//! # use std::error::Error;
30//! use tracing_log::LogTracer;
31//! use log;
32//!
33//! # fn main() -> Result<(), Box<Error>> {
34//! LogTracer::init()?;
35//!
36//! // will be available for Subscribers as a tracing Event
37//! log::trace!("an example trace log");
38//! # Ok(())
39//! # }
40//! ```
41//!
42//! This conversion does not convert unstructured data in log records (such as
43//! values passed as format arguments to the `log!` macro) to structured
44//! `tracing` fields. However, it *does* attach these new events to to the
45//! span that was currently executing when the record was logged. This is the
46//! primary use-case for this library: making it possible to locate the log
47//! records emitted by dependencies which use `log` within the context of a
48//! trace.
49//!
50//! ## Convert tracing `Event`s to logs
51//!
52//! Enabling the ["log" and "log-always" feature flags][flags] on the `tracing`
53//! crate will cause all `tracing` spans and events to emit `log::Record`s as
54//! they occur.
55//!
56//! ## Caution: Mixing both conversions
57//!
58//! Note that `log::Logger` implementations that convert log records to trace events
59//! should not be used with `Subscriber`s that convert trace events _back_ into
60//! `log` records, as doing so will result in the event recursing between the subscriber
61//! and the logger forever (or, in real life, probably overflowing the call stack).
62//!
63//! If the logging of trace events generated from log records produced by the
64//! `log` crate is desired, either the `log` crate should not be used to
65//! implement this logging, or an additional layer of filtering will be
66//! required to avoid infinitely converting between `Event` and `log::Record`.
67//!
68//! ## Feature Flags
69//!
70//! * `std`: enables features that require the Rust standard library (on by default)
71//! * `log-tracer`: enables the `LogTracer` type (on by default)
72//! * `interest-cache`: makes it possible to configure an interest cache for
73//!   logs emitted through the `log` crate (see [`Builder::with_interest_cache`]); requires `std`
74//!
75//! ## Supported Rust Versions
76//!
77//! Tracing is built against the latest stable release. The minimum supported
78//! version is 1.65. The current Tracing version is not guaranteed to build on
79//! Rust versions earlier than the minimum supported version.
80//!
81//! Tracing follows the same compiler support policies as the rest of the Tokio
82//! project. The current stable Rust compiler and the three most recent minor
83//! versions before it will always be supported. For example, if the current
84//! stable compiler version is 1.69, the minimum supported version will not be
85//! increased past 1.66, three minor versions prior. Increasing the minimum
86//! supported compiler version is not considered a semver breaking change as
87//! long as doing so complies with this policy.
88//!
89//! [`init`]: LogTracer::init
90//! [`init_with_filter`]: LogTracer::init_with_filter
91//! [`tracing`]: https://crates.io/crates/tracing
92//! [`tracing::Subscriber`]: https://docs.rs/tracing/latest/tracing/trait.Subscriber.html
93//! [`Subscriber`]: https://docs.rs/tracing/latest/tracing/trait.Subscriber.html
94//! [`tracing::Event`]: https://docs.rs/tracing/latest/tracing/struct.Event.html
95//! [flags]: https://docs.rs/tracing/latest/tracing/#crate-feature-flags
96//! [`Builder::with_interest_cache`]: log_tracer::Builder::with_interest_cache
97#![doc(
98    html_logo_url = "https://raw.githubusercontent.com/tokio-rs/tracing/main/assets/logo-type.png",
99    html_favicon_url = "https://raw.githubusercontent.com/tokio-rs/tracing/main/assets/favicon.ico",
100    issue_tracker_base_url = "https://github.com/tokio-rs/tracing/issues/"
101)]
102#![cfg_attr(docsrs, feature(doc_cfg), deny(rustdoc::broken_intra_doc_links))]
103#![warn(
104    missing_debug_implementations,
105    missing_docs,
106    rust_2018_idioms,
107    unreachable_pub,
108    bad_style,
109    dead_code,
110    improper_ctypes,
111    non_shorthand_field_patterns,
112    no_mangle_generic_items,
113    overflowing_literals,
114    path_statements,
115    patterns_in_fns_without_body,
116    private_interfaces,
117    private_bounds,
118    unconditional_recursion,
119    unused,
120    unused_allocation,
121    unused_comparisons,
122    unused_parens,
123    while_true
124)]
125use once_cell::sync::Lazy;
126
127use std::{fmt, io};
128
129use tracing_core::{
130    callsite::{self, Callsite},
131    dispatcher,
132    field::{self, Field, Visit},
133    identify_callsite,
134    metadata::{Kind, Level},
135    subscriber, Event, Metadata,
136};
137
138#[cfg(feature = "log-tracer")]
139#[cfg_attr(docsrs, doc(cfg(feature = "log-tracer")))]
140pub mod log_tracer;
141
142#[cfg(feature = "log-tracer")]
143#[cfg_attr(docsrs, doc(cfg(feature = "log-tracer")))]
144#[doc(inline)]
145pub use self::log_tracer::LogTracer;
146
147pub use log;
148
149#[cfg(all(feature = "interest-cache", feature = "log-tracer", feature = "std"))]
150mod interest_cache;
151
152#[cfg(all(feature = "interest-cache", feature = "log-tracer", feature = "std"))]
153#[cfg_attr(
154    docsrs,
155    doc(cfg(all(feature = "interest-cache", feature = "log-tracer", feature = "std")))
156)]
157pub use crate::interest_cache::InterestCacheConfig;
158
159/// Format a log record as a trace event in the current span.
160pub fn format_trace(record: &log::Record<'_>) -> io::Result<()> {
161    dispatch_record(record);
162    Ok(())
163}
164
165// XXX(eliza): this is factored out so that we don't have to deal with the pub
166// function `format_trace`'s `Result` return type...maybe we should get rid of
167// that in 0.2...
168pub(crate) fn dispatch_record(record: &log::Record<'_>) {
169    dispatcher::get_default(|dispatch| {
170        let filter_meta = record.as_trace();
171        if !dispatch.enabled(&filter_meta) {
172            return;
173        }
174
175        let (_, keys, meta) = loglevel_to_cs(record.level());
176
177        let log_module = record.module_path();
178        let log_file = record.file();
179        let log_line = record.line();
180
181        let module = log_module.as_ref().map(|s| s as &dyn field::Value);
182        let file = log_file.as_ref().map(|s| s as &dyn field::Value);
183        let line = log_line.as_ref().map(|s| s as &dyn field::Value);
184
185        dispatch.event(&Event::new(
186            meta,
187            &meta.fields().value_set(&[
188                (&keys.message, Some(record.args() as &dyn field::Value)),
189                (&keys.target, Some(&record.target())),
190                (&keys.module, module),
191                (&keys.file, file),
192                (&keys.line, line),
193            ]),
194        ));
195    });
196}
197
198/// Trait implemented for `tracing` types that can be converted to a `log`
199/// equivalent.
200pub trait AsLog: crate::sealed::Sealed {
201    /// The `log` type that this type can be converted into.
202    type Log;
203    /// Returns the `log` equivalent of `self`.
204    fn as_log(&self) -> Self::Log;
205}
206
207/// Trait implemented for `log` types that can be converted to a `tracing`
208/// equivalent.
209pub trait AsTrace: crate::sealed::Sealed {
210    /// The `tracing` type that this type can be converted into.
211    type Trace;
212    /// Returns the `tracing` equivalent of `self`.
213    fn as_trace(&self) -> Self::Trace;
214}
215
216impl crate::sealed::Sealed for Metadata<'_> {}
217
218impl<'a> AsLog for Metadata<'a> {
219    type Log = log::Metadata<'a>;
220    fn as_log(&self) -> Self::Log {
221        log::Metadata::builder()
222            .level(self.level().as_log())
223            .target(self.target())
224            .build()
225    }
226}
227impl crate::sealed::Sealed for log::Metadata<'_> {}
228
229impl<'a> AsTrace for log::Metadata<'a> {
230    type Trace = Metadata<'a>;
231    fn as_trace(&self) -> Self::Trace {
232        let cs_id = identify_callsite!(loglevel_to_cs(self.level()).0);
233        Metadata::new(
234            "log record",
235            self.target(),
236            self.level().as_trace(),
237            None,
238            None,
239            None,
240            field::FieldSet::new(FIELD_NAMES, cs_id),
241            Kind::EVENT,
242        )
243    }
244}
245
246struct Fields {
247    message: field::Field,
248    target: field::Field,
249    module: field::Field,
250    file: field::Field,
251    line: field::Field,
252}
253
254static FIELD_NAMES: &[&str] = &[
255    "message",
256    "log.target",
257    "log.module_path",
258    "log.file",
259    "log.line",
260];
261
262impl Fields {
263    fn new(cs: &'static dyn Callsite) -> Self {
264        let fieldset = cs.metadata().fields();
265        let message = fieldset.field("message").unwrap();
266        let target = fieldset.field("log.target").unwrap();
267        let module = fieldset.field("log.module_path").unwrap();
268        let file = fieldset.field("log.file").unwrap();
269        let line = fieldset.field("log.line").unwrap();
270        Fields {
271            message,
272            target,
273            module,
274            file,
275            line,
276        }
277    }
278}
279
280macro_rules! log_cs {
281    ($level:expr, $cs:ident, $meta:ident, $ty:ident) => {
282        struct $ty;
283        static $cs: $ty = $ty;
284        static $meta: Metadata<'static> = Metadata::new(
285            "log event",
286            "log",
287            $level,
288            ::core::option::Option::None,
289            ::core::option::Option::None,
290            ::core::option::Option::None,
291            field::FieldSet::new(FIELD_NAMES, identify_callsite!(&$cs)),
292            Kind::EVENT,
293        );
294
295        impl callsite::Callsite for $ty {
296            fn set_interest(&self, _: subscriber::Interest) {}
297            fn metadata(&self) -> &'static Metadata<'static> {
298                &$meta
299            }
300        }
301    };
302}
303
304log_cs!(
305    tracing_core::Level::TRACE,
306    TRACE_CS,
307    TRACE_META,
308    TraceCallsite
309);
310log_cs!(
311    tracing_core::Level::DEBUG,
312    DEBUG_CS,
313    DEBUG_META,
314    DebugCallsite
315);
316log_cs!(tracing_core::Level::INFO, INFO_CS, INFO_META, InfoCallsite);
317log_cs!(tracing_core::Level::WARN, WARN_CS, WARN_META, WarnCallsite);
318log_cs!(
319    tracing_core::Level::ERROR,
320    ERROR_CS,
321    ERROR_META,
322    ErrorCallsite
323);
324
325static TRACE_FIELDS: Lazy<Fields> = Lazy::new(|| Fields::new(&TRACE_CS));
326static DEBUG_FIELDS: Lazy<Fields> = Lazy::new(|| Fields::new(&DEBUG_CS));
327static INFO_FIELDS: Lazy<Fields> = Lazy::new(|| Fields::new(&INFO_CS));
328static WARN_FIELDS: Lazy<Fields> = Lazy::new(|| Fields::new(&WARN_CS));
329static ERROR_FIELDS: Lazy<Fields> = Lazy::new(|| Fields::new(&ERROR_CS));
330
331fn level_to_cs(level: Level) -> (&'static dyn Callsite, &'static Fields) {
332    match level {
333        Level::TRACE => (&TRACE_CS, &*TRACE_FIELDS),
334        Level::DEBUG => (&DEBUG_CS, &*DEBUG_FIELDS),
335        Level::INFO => (&INFO_CS, &*INFO_FIELDS),
336        Level::WARN => (&WARN_CS, &*WARN_FIELDS),
337        Level::ERROR => (&ERROR_CS, &*ERROR_FIELDS),
338    }
339}
340
341fn loglevel_to_cs(
342    level: log::Level,
343) -> (
344    &'static dyn Callsite,
345    &'static Fields,
346    &'static Metadata<'static>,
347) {
348    match level {
349        log::Level::Trace => (&TRACE_CS, &*TRACE_FIELDS, &TRACE_META),
350        log::Level::Debug => (&DEBUG_CS, &*DEBUG_FIELDS, &DEBUG_META),
351        log::Level::Info => (&INFO_CS, &*INFO_FIELDS, &INFO_META),
352        log::Level::Warn => (&WARN_CS, &*WARN_FIELDS, &WARN_META),
353        log::Level::Error => (&ERROR_CS, &*ERROR_FIELDS, &ERROR_META),
354    }
355}
356
357impl crate::sealed::Sealed for log::Record<'_> {}
358
359impl<'a> AsTrace for log::Record<'a> {
360    type Trace = Metadata<'a>;
361    fn as_trace(&self) -> Self::Trace {
362        let cs_id = identify_callsite!(loglevel_to_cs(self.level()).0);
363        Metadata::new(
364            "log record",
365            self.target(),
366            self.level().as_trace(),
367            self.file(),
368            self.line(),
369            self.module_path(),
370            field::FieldSet::new(FIELD_NAMES, cs_id),
371            Kind::EVENT,
372        )
373    }
374}
375
376impl crate::sealed::Sealed for tracing_core::Level {}
377
378impl AsLog for tracing_core::Level {
379    type Log = log::Level;
380    fn as_log(&self) -> log::Level {
381        match *self {
382            tracing_core::Level::ERROR => log::Level::Error,
383            tracing_core::Level::WARN => log::Level::Warn,
384            tracing_core::Level::INFO => log::Level::Info,
385            tracing_core::Level::DEBUG => log::Level::Debug,
386            tracing_core::Level::TRACE => log::Level::Trace,
387        }
388    }
389}
390
391impl crate::sealed::Sealed for log::Level {}
392
393impl AsTrace for log::Level {
394    type Trace = tracing_core::Level;
395    #[inline]
396    fn as_trace(&self) -> tracing_core::Level {
397        match self {
398            log::Level::Error => tracing_core::Level::ERROR,
399            log::Level::Warn => tracing_core::Level::WARN,
400            log::Level::Info => tracing_core::Level::INFO,
401            log::Level::Debug => tracing_core::Level::DEBUG,
402            log::Level::Trace => tracing_core::Level::TRACE,
403        }
404    }
405}
406
407impl crate::sealed::Sealed for log::LevelFilter {}
408
409impl AsTrace for log::LevelFilter {
410    type Trace = tracing_core::LevelFilter;
411    #[inline]
412    fn as_trace(&self) -> tracing_core::LevelFilter {
413        match self {
414            log::LevelFilter::Off => tracing_core::LevelFilter::OFF,
415            log::LevelFilter::Error => tracing_core::LevelFilter::ERROR,
416            log::LevelFilter::Warn => tracing_core::LevelFilter::WARN,
417            log::LevelFilter::Info => tracing_core::LevelFilter::INFO,
418            log::LevelFilter::Debug => tracing_core::LevelFilter::DEBUG,
419            log::LevelFilter::Trace => tracing_core::LevelFilter::TRACE,
420        }
421    }
422}
423
424impl crate::sealed::Sealed for tracing_core::LevelFilter {}
425
426impl AsLog for tracing_core::LevelFilter {
427    type Log = log::LevelFilter;
428    #[inline]
429    fn as_log(&self) -> Self::Log {
430        match *self {
431            tracing_core::LevelFilter::OFF => log::LevelFilter::Off,
432            tracing_core::LevelFilter::ERROR => log::LevelFilter::Error,
433            tracing_core::LevelFilter::WARN => log::LevelFilter::Warn,
434            tracing_core::LevelFilter::INFO => log::LevelFilter::Info,
435            tracing_core::LevelFilter::DEBUG => log::LevelFilter::Debug,
436            tracing_core::LevelFilter::TRACE => log::LevelFilter::Trace,
437        }
438    }
439}
440/// Extends log `Event`s to provide complete `Metadata`.
441///
442/// In `tracing-log`, an `Event` produced by a log (through [`AsTrace`]) has an hard coded
443/// "log" target and no `file`, `line`, or `module_path` attributes. This happens because `Event`
444/// requires its `Metadata` to be `'static`, while [`log::Record`]s provide them with a generic
445/// lifetime.
446///
447/// However, these values are stored in the `Event`'s fields and
448/// the [`normalized_metadata`] method allows to build a new `Metadata`
449/// that only lives as long as its source `Event`, but provides complete
450/// data.
451///
452/// It can typically be used by `Subscriber`s when processing an `Event`,
453/// to allow accessing its complete metadata in a consistent way,
454/// regardless of the source of its source.
455///
456/// [`normalized_metadata`]: NormalizeEvent#normalized_metadata
457pub trait NormalizeEvent<'a>: crate::sealed::Sealed {
458    /// If this `Event` comes from a `log`, this method provides a new
459    /// normalized `Metadata` which has all available attributes
460    /// from the original log, including `file`, `line`, `module_path`
461    /// and `target`.
462    /// Returns `None` is the `Event` is not issued from a `log`.
463    fn normalized_metadata(&'a self) -> Option<Metadata<'a>>;
464    /// Returns whether this `Event` represents a log (from the `log` crate)
465    fn is_log(&self) -> bool;
466}
467
468impl crate::sealed::Sealed for Event<'_> {}
469
470impl<'a> NormalizeEvent<'a> for Event<'a> {
471    fn normalized_metadata(&'a self) -> Option<Metadata<'a>> {
472        let original = self.metadata();
473        if self.is_log() {
474            let mut fields = LogVisitor::new_for(self, level_to_cs(*original.level()).1);
475            self.record(&mut fields);
476
477            Some(Metadata::new(
478                "log event",
479                fields.target.unwrap_or("log"),
480                *original.level(),
481                fields.file,
482                fields.line.map(|l| l as u32),
483                fields.module_path,
484                field::FieldSet::new(&["message"], original.callsite()),
485                Kind::EVENT,
486            ))
487        } else {
488            None
489        }
490    }
491
492    fn is_log(&self) -> bool {
493        self.metadata().callsite() == identify_callsite!(level_to_cs(*self.metadata().level()).0)
494    }
495}
496
497struct LogVisitor<'a> {
498    target: Option<&'a str>,
499    module_path: Option<&'a str>,
500    file: Option<&'a str>,
501    line: Option<u64>,
502    fields: &'static Fields,
503}
504
505impl<'a> LogVisitor<'a> {
506    // We don't actually _use_ the provided event argument; it is simply to
507    // ensure that the `LogVisitor` does not outlive the event whose fields it
508    // is visiting, so that the reference casts in `record_str` are safe.
509    fn new_for(_event: &'a Event<'a>, fields: &'static Fields) -> Self {
510        Self {
511            target: None,
512            module_path: None,
513            file: None,
514            line: None,
515            fields,
516        }
517    }
518}
519
520impl Visit for LogVisitor<'_> {
521    fn record_debug(&mut self, _field: &Field, _value: &dyn fmt::Debug) {}
522
523    fn record_u64(&mut self, field: &Field, value: u64) {
524        if field == &self.fields.line {
525            self.line = Some(value);
526        }
527    }
528
529    fn record_str(&mut self, field: &Field, value: &str) {
530        unsafe {
531            // The `Visit` API erases the string slice's lifetime. However, we
532            // know it is part of the `Event` struct with a lifetime of `'a`. If
533            // (and only if!) this `LogVisitor` was constructed with the same
534            // lifetime parameter `'a` as the event in question, it's safe to
535            // cast these string slices to the `'a` lifetime.
536            if field == &self.fields.file {
537                self.file = Some(&*(value as *const _));
538            } else if field == &self.fields.target {
539                self.target = Some(&*(value as *const _));
540            } else if field == &self.fields.module {
541                self.module_path = Some(&*(value as *const _));
542            }
543        }
544    }
545}
546
547mod sealed {
548    pub trait Sealed {}
549}
550
551#[cfg(test)]
552mod test {
553    use super::*;
554
555    fn test_callsite(level: log::Level) {
556        let record = log::Record::builder()
557            .args(format_args!("Error!"))
558            .level(level)
559            .target("myApp")
560            .file(Some("server.rs"))
561            .line(Some(144))
562            .module_path(Some("server"))
563            .build();
564
565        let meta = record.as_trace();
566        let (cs, _keys, _) = loglevel_to_cs(record.level());
567        let cs_meta = cs.metadata();
568        assert_eq!(
569            meta.callsite(),
570            cs_meta.callsite(),
571            "actual: {:#?}\nexpected: {:#?}",
572            meta,
573            cs_meta
574        );
575        assert_eq!(meta.level(), &level.as_trace());
576    }
577
578    #[test]
579    fn error_callsite_is_correct() {
580        test_callsite(log::Level::Error);
581    }
582
583    #[test]
584    fn warn_callsite_is_correct() {
585        test_callsite(log::Level::Warn);
586    }
587
588    #[test]
589    fn info_callsite_is_correct() {
590        test_callsite(log::Level::Info);
591    }
592
593    #[test]
594    fn debug_callsite_is_correct() {
595        test_callsite(log::Level::Debug);
596    }
597
598    #[test]
599    fn trace_callsite_is_correct() {
600        test_callsite(log::Level::Trace);
601    }
602}
tracing_log/lib.rs

tracing_log/
lib.rs
