//! Adapters for connecting unstructured log records from the `log` crate into //! the `tracing` ecosystem. //! //! # Overview //! //! [`tracing`] is a framework for instrumenting Rust programs with context-aware, //! structured, event-based diagnostic information. This crate provides //! compatibility layers for using `tracing` alongside the logging facade provided //! by the [`log`] crate. //! //! This crate provides: //! //! - [`AsTrace`] and [`AsLog`] traits for converting between `tracing` and `log` types. //! - [`LogTracer`], a [`log::Log`] implementation that consumes [`log::Record`]s //! and outputs them as [`tracing::Event`]. //! - An [`env_logger`] module, with helpers for using the [`env_logger` crate] //! with `tracing` (optional, enabled by the `env-logger` feature). //! //! *Compiler support: [requires `rustc` 1.49+][msrv]* //! //! [msrv]: #supported-rust-versions //! //! # Usage //! //! ## Convert log records to tracing `Event`s //! //! To convert [`log::Record`]s as [`tracing::Event`]s, set `LogTracer` as the default //! logger by calling its [`init`] or [`init_with_filter`] methods. //! //! ```rust //! # use std::error::Error; //! use tracing_log::LogTracer; //! use log; //! //! # fn main() -> Result<(), Box> { //! LogTracer::init()?; //! //! // will be available for Subscribers as a tracing Event //! log::trace!("an example trace log"); //! # Ok(()) //! # } //! ``` //! //! This conversion does not convert unstructured data in log records (such as //! values passed as format arguments to the `log!` macro) to structured //! `tracing` fields. However, it *does* attach these new events to to the //! span that was currently executing when the record was logged. This is the //! primary use-case for this library: making it possible to locate the log //! records emitted by dependencies which use `log` within the context of a //! trace. //! //! ## Convert tracing `Event`s to logs //! //! Enabling the ["log" and "log-always" feature flags][flags] on the `tracing` //! crate will cause all `tracing` spans and events to emit `log::Record`s as //! they occur. //! //! ## Caution: Mixing both conversions //! //! Note that logger implementations that convert log records to trace events //! should not be used with `Subscriber`s that convert trace events _back_ into //! log records (such as the `TraceLogger`), as doing so will result in the //! event recursing between the subscriber and the logger forever (or, in real //! life, probably overflowing the call stack). //! //! If the logging of trace events generated from log records produced by the //! `log` crate is desired, either the `log` crate should not be used to //! implement this logging, or an additional layer of filtering will be //! required to avoid infinitely converting between `Event` and `log::Record`. //! //! # Feature Flags //! * `trace-logger`: enables an experimental `log` subscriber, deprecated since //! version 0.1.1. //! * `log-tracer`: enables the `LogTracer` type (on by default) //! * `env_logger`: enables the `env_logger` module, with helpers for working //! with the [`env_logger` crate]. //! * `interest-cache`: makes it possible to configure an interest cache for //! logs emitted through the `log` crate (see [`Builder::with_interest_cache`]); requires `std` //! //! ## Supported Rust Versions //! //! Tracing is built against the latest stable release. The minimum supported //! version is 1.49. The current Tracing version is not guaranteed to build on //! Rust versions earlier than the minimum supported version. //! //! Tracing follows the same compiler support policies as the rest of the Tokio //! project. The current stable Rust compiler and the three most recent minor //! versions before it will always be supported. For example, if the current //! stable compiler version is 1.45, the minimum supported version will not be //! increased past 1.42, three minor versions prior. Increasing the minimum //! supported compiler version is not considered a semver breaking change as //! long as doing so complies with this policy. //! //! [`init`]: LogTracer::init //! [`init_with_filter`]: LogTracer::init_with_filter //! [`tracing`]: https://crates.io/crates/tracing //! [`env_logger` crate]: https://crates.io/crates/env-logger //! [`tracing::Subscriber`]: https://docs.rs/tracing/latest/tracing/trait.Subscriber.html //! [`Subscriber`]: https://docs.rs/tracing/latest/tracing/trait.Subscriber.html //! [`tracing::Event`]: https://docs.rs/tracing/latest/tracing/struct.Event.html //! [flags]: https://docs.rs/tracing/latest/tracing/#crate-feature-flags //! [`Builder::with_interest_cache`]: log_tracer::Builder::with_interest_cache #![doc(html_root_url = "https://docs.rs/tracing-log/0.1.3")] #![doc( html_logo_url = "https://raw.githubusercontent.com/tokio-rs/tracing/master/assets/logo-type.png", issue_tracker_base_url = "https://github.com/tokio-rs/tracing/issues/" )] #![cfg_attr(docsrs, feature(doc_cfg), deny(rustdoc::broken_intra_doc_links))] #![warn( missing_debug_implementations, missing_docs, rust_2018_idioms, unreachable_pub, bad_style, const_err, dead_code, improper_ctypes, non_shorthand_field_patterns, no_mangle_generic_items, overflowing_literals, path_statements, patterns_in_fns_without_body, private_in_public, unconditional_recursion, unused, unused_allocation, unused_comparisons, unused_parens, while_true )] use lazy_static::lazy_static; use std::{fmt, io}; use tracing_core::{ callsite::{self, Callsite}, dispatcher, field::{self, Field, Visit}, identify_callsite, metadata::{Kind, Level}, subscriber, Event, Metadata, }; #[cfg(feature = "log-tracer")] #[cfg_attr(docsrs, doc(cfg(feature = "log-tracer")))] pub mod log_tracer; #[cfg(feature = "trace-logger")] #[cfg_attr(docsrs, doc(cfg(feature = "trace-logger")))] pub mod trace_logger; #[cfg(feature = "log-tracer")] #[cfg_attr(docsrs, doc(cfg(feature = "log-tracer")))] #[doc(inline)] pub use self::log_tracer::LogTracer; #[cfg(feature = "trace-logger")] #[cfg_attr(docsrs, doc(cfg(feature = "trace-logger")))] #[deprecated( since = "0.1.1", note = "use the `tracing` crate's \"log\" feature flag instead" )] #[allow(deprecated)] #[doc(inline)] pub use self::trace_logger::TraceLogger; #[cfg(feature = "env_logger")] #[cfg_attr(docsrs, doc(cfg(feature = "env_logger")))] pub mod env_logger; pub use log; #[cfg(all(feature = "interest-cache", feature = "log-tracer", feature = "std"))] mod interest_cache; #[cfg(all(feature = "interest-cache", feature = "log-tracer", feature = "std"))] #[cfg_attr( docsrs, doc(cfg(all(feature = "interest-cache", feature = "log-tracer", feature = "std"))) )] pub use crate::interest_cache::InterestCacheConfig; /// Format a log record as a trace event in the current span. pub fn format_trace(record: &log::Record<'_>) -> io::Result<()> { dispatch_record(record); Ok(()) } // XXX(eliza): this is factored out so that we don't have to deal with the pub // function `format_trace`'s `Result` return type...maybe we should get rid of // that in 0.2... pub(crate) fn dispatch_record(record: &log::Record<'_>) { dispatcher::get_default(|dispatch| { let filter_meta = record.as_trace(); if !dispatch.enabled(&filter_meta) { return; } let (_, keys, meta) = loglevel_to_cs(record.level()); let log_module = record.module_path(); let log_file = record.file(); let log_line = record.line(); let module = log_module.as_ref().map(|s| s as &dyn field::Value); let file = log_file.as_ref().map(|s| s as &dyn field::Value); let line = log_line.as_ref().map(|s| s as &dyn field::Value); dispatch.event(&Event::new( meta, &meta.fields().value_set(&[ (&keys.message, Some(record.args() as &dyn field::Value)), (&keys.target, Some(&record.target())), (&keys.module, module), (&keys.file, file), (&keys.line, line), ]), )); }); } /// Trait implemented for `tracing` types that can be converted to a `log` /// equivalent. pub trait AsLog: crate::sealed::Sealed { /// The `log` type that this type can be converted into. type Log; /// Returns the `log` equivalent of `self`. fn as_log(&self) -> Self::Log; } /// Trait implemented for `log` types that can be converted to a `tracing` /// equivalent. pub trait AsTrace: crate::sealed::Sealed { /// The `tracing` type that this type can be converted into. type Trace; /// Returns the `tracing` equivalent of `self`. fn as_trace(&self) -> Self::Trace; } impl<'a> crate::sealed::Sealed for Metadata<'a> {} impl<'a> AsLog for Metadata<'a> { type Log = log::Metadata<'a>; fn as_log(&self) -> Self::Log { log::Metadata::builder() .level(self.level().as_log()) .target(self.target()) .build() } } impl<'a> crate::sealed::Sealed for log::Metadata<'a> {} impl<'a> AsTrace for log::Metadata<'a> { type Trace = Metadata<'a>; fn as_trace(&self) -> Self::Trace { let cs_id = identify_callsite!(loglevel_to_cs(self.level()).0); Metadata::new( "log record", self.target(), self.level().as_trace(), None, None, None, field::FieldSet::new(FIELD_NAMES, cs_id), Kind::EVENT, ) } } struct Fields { message: field::Field, target: field::Field, module: field::Field, file: field::Field, line: field::Field, } static FIELD_NAMES: &[&str] = &[ "message", "log.target", "log.module_path", "log.file", "log.line", ]; impl Fields { fn new(cs: &'static dyn Callsite) -> Self { let fieldset = cs.metadata().fields(); let message = fieldset.field("message").unwrap(); let target = fieldset.field("log.target").unwrap(); let module = fieldset.field("log.module_path").unwrap(); let file = fieldset.field("log.file").unwrap(); let line = fieldset.field("log.line").unwrap(); Fields { message, target, module, file, line, } } } macro_rules! log_cs { ($level:expr, $cs:ident, $meta:ident, $ty:ident) => { struct $ty; static $cs: $ty = $ty; static $meta: Metadata<'static> = Metadata::new( "log event", "log", $level, None, None, None, field::FieldSet::new(FIELD_NAMES, identify_callsite!(&$cs)), Kind::EVENT, ); impl callsite::Callsite for $ty { fn set_interest(&self, _: subscriber::Interest) {} fn metadata(&self) -> &'static Metadata<'static> { &$meta } } }; } log_cs!( tracing_core::Level::TRACE, TRACE_CS, TRACE_META, TraceCallsite ); log_cs!( tracing_core::Level::DEBUG, DEBUG_CS, DEBUG_META, DebugCallsite ); log_cs!(tracing_core::Level::INFO, INFO_CS, INFO_META, InfoCallsite); log_cs!(tracing_core::Level::WARN, WARN_CS, WARN_META, WarnCallsite); log_cs!( tracing_core::Level::ERROR, ERROR_CS, ERROR_META, ErrorCallsite ); lazy_static! { static ref TRACE_FIELDS: Fields = Fields::new(&TRACE_CS); static ref DEBUG_FIELDS: Fields = Fields::new(&DEBUG_CS); static ref INFO_FIELDS: Fields = Fields::new(&INFO_CS); static ref WARN_FIELDS: Fields = Fields::new(&WARN_CS); static ref ERROR_FIELDS: Fields = Fields::new(&ERROR_CS); } fn level_to_cs(level: Level) -> (&'static dyn Callsite, &'static Fields) { match level { Level::TRACE => (&TRACE_CS, &*TRACE_FIELDS), Level::DEBUG => (&DEBUG_CS, &*DEBUG_FIELDS), Level::INFO => (&INFO_CS, &*INFO_FIELDS), Level::WARN => (&WARN_CS, &*WARN_FIELDS), Level::ERROR => (&ERROR_CS, &*ERROR_FIELDS), } } fn loglevel_to_cs( level: log::Level, ) -> ( &'static dyn Callsite, &'static Fields, &'static Metadata<'static>, ) { match level { log::Level::Trace => (&TRACE_CS, &*TRACE_FIELDS, &TRACE_META), log::Level::Debug => (&DEBUG_CS, &*DEBUG_FIELDS, &DEBUG_META), log::Level::Info => (&INFO_CS, &*INFO_FIELDS, &INFO_META), log::Level::Warn => (&WARN_CS, &*WARN_FIELDS, &WARN_META), log::Level::Error => (&ERROR_CS, &*ERROR_FIELDS, &ERROR_META), } } impl<'a> crate::sealed::Sealed for log::Record<'a> {} impl<'a> AsTrace for log::Record<'a> { type Trace = Metadata<'a>; fn as_trace(&self) -> Self::Trace { let cs_id = identify_callsite!(loglevel_to_cs(self.level()).0); Metadata::new( "log record", self.target(), self.level().as_trace(), self.file(), self.line(), self.module_path(), field::FieldSet::new(FIELD_NAMES, cs_id), Kind::EVENT, ) } } impl crate::sealed::Sealed for tracing_core::Level {} impl AsLog for tracing_core::Level { type Log = log::Level; fn as_log(&self) -> log::Level { match *self { tracing_core::Level::ERROR => log::Level::Error, tracing_core::Level::WARN => log::Level::Warn, tracing_core::Level::INFO => log::Level::Info, tracing_core::Level::DEBUG => log::Level::Debug, tracing_core::Level::TRACE => log::Level::Trace, } } } impl crate::sealed::Sealed for log::Level {} impl AsTrace for log::Level { type Trace = tracing_core::Level; #[inline] fn as_trace(&self) -> tracing_core::Level { match self { log::Level::Error => tracing_core::Level::ERROR, log::Level::Warn => tracing_core::Level::WARN, log::Level::Info => tracing_core::Level::INFO, log::Level::Debug => tracing_core::Level::DEBUG, log::Level::Trace => tracing_core::Level::TRACE, } } } impl crate::sealed::Sealed for log::LevelFilter {} impl AsTrace for log::LevelFilter { type Trace = tracing_core::LevelFilter; #[inline] fn as_trace(&self) -> tracing_core::LevelFilter { match self { log::LevelFilter::Off => tracing_core::LevelFilter::OFF, log::LevelFilter::Error => tracing_core::LevelFilter::ERROR, log::LevelFilter::Warn => tracing_core::LevelFilter::WARN, log::LevelFilter::Info => tracing_core::LevelFilter::INFO, log::LevelFilter::Debug => tracing_core::LevelFilter::DEBUG, log::LevelFilter::Trace => tracing_core::LevelFilter::TRACE, } } } impl crate::sealed::Sealed for tracing_core::LevelFilter {} impl AsLog for tracing_core::LevelFilter { type Log = log::LevelFilter; #[inline] fn as_log(&self) -> Self::Log { match *self { tracing_core::LevelFilter::OFF => log::LevelFilter::Off, tracing_core::LevelFilter::ERROR => log::LevelFilter::Error, tracing_core::LevelFilter::WARN => log::LevelFilter::Warn, tracing_core::LevelFilter::INFO => log::LevelFilter::Info, tracing_core::LevelFilter::DEBUG => log::LevelFilter::Debug, tracing_core::LevelFilter::TRACE => log::LevelFilter::Trace, } } } /// Extends log `Event`s to provide complete `Metadata`. /// /// In `tracing-log`, an `Event` produced by a log (through [`AsTrace`]) has an hard coded /// "log" target and no `file`, `line`, or `module_path` attributes. This happens because `Event` /// requires its `Metadata` to be `'static`, while [`log::Record`]s provide them with a generic /// lifetime. /// /// However, these values are stored in the `Event`'s fields and /// the [`normalized_metadata`] method allows to build a new `Metadata` /// that only lives as long as its source `Event`, but provides complete /// data. /// /// It can typically be used by `Subscriber`s when processing an `Event`, /// to allow accessing its complete metadata in a consistent way, /// regardless of the source of its source. /// /// [`normalized_metadata`]: NormalizeEvent#normalized_metadata pub trait NormalizeEvent<'a>: crate::sealed::Sealed { /// If this `Event` comes from a `log`, this method provides a new /// normalized `Metadata` which has all available attributes /// from the original log, including `file`, `line`, `module_path` /// and `target`. /// Returns `None` is the `Event` is not issued from a `log`. fn normalized_metadata(&'a self) -> Option>; /// Returns whether this `Event` represents a log (from the `log` crate) fn is_log(&self) -> bool; } impl<'a> crate::sealed::Sealed for Event<'a> {} impl<'a> NormalizeEvent<'a> for Event<'a> { fn normalized_metadata(&'a self) -> Option> { let original = self.metadata(); if self.is_log() { let mut fields = LogVisitor::new_for(self, level_to_cs(*original.level()).1); self.record(&mut fields); Some(Metadata::new( "log event", fields.target.unwrap_or("log"), *original.level(), fields.file, fields.line.map(|l| l as u32), fields.module_path, field::FieldSet::new(&["message"], original.callsite()), Kind::EVENT, )) } else { None } } fn is_log(&self) -> bool { self.metadata().callsite() == identify_callsite!(level_to_cs(*self.metadata().level()).0) } } struct LogVisitor<'a> { target: Option<&'a str>, module_path: Option<&'a str>, file: Option<&'a str>, line: Option, fields: &'static Fields, } impl<'a> LogVisitor<'a> { // We don't actually _use_ the provided event argument; it is simply to // ensure that the `LogVisitor` does not outlive the event whose fields it // is visiting, so that the reference casts in `record_str` are safe. fn new_for(_event: &'a Event<'a>, fields: &'static Fields) -> Self { Self { target: None, module_path: None, file: None, line: None, fields, } } } impl<'a> Visit for LogVisitor<'a> { fn record_debug(&mut self, _field: &Field, _value: &dyn fmt::Debug) {} fn record_u64(&mut self, field: &Field, value: u64) { if field == &self.fields.line { self.line = Some(value); } } fn record_str(&mut self, field: &Field, value: &str) { unsafe { // The `Visit` API erases the string slice's lifetime. However, we // know it is part of the `Event` struct with a lifetime of `'a`. If // (and only if!) this `LogVisitor` was constructed with the same // lifetime parameter `'a` as the event in question, it's safe to // cast these string slices to the `'a` lifetime. if field == &self.fields.file { self.file = Some(&*(value as *const _)); } else if field == &self.fields.target { self.target = Some(&*(value as *const _)); } else if field == &self.fields.module { self.module_path = Some(&*(value as *const _)); } } } } mod sealed { pub trait Sealed {} } #[cfg(test)] mod test { use super::*; fn test_callsite(level: log::Level) { let record = log::Record::builder() .args(format_args!("Error!")) .level(level) .target("myApp") .file(Some("server.rs")) .line(Some(144)) .module_path(Some("server")) .build(); let meta = record.as_trace(); let (cs, _keys, _) = loglevel_to_cs(record.level()); let cs_meta = cs.metadata(); assert_eq!( meta.callsite(), cs_meta.callsite(), "actual: {:#?}\nexpected: {:#?}", meta, cs_meta ); assert_eq!(meta.level(), &level.as_trace()); } #[test] fn error_callsite_is_correct() { test_callsite(log::Level::Error); } #[test] fn warn_callsite_is_correct() { test_callsite(log::Level::Warn); } #[test] fn info_callsite_is_correct() { test_callsite(log::Level::Info); } #[test] fn debug_callsite_is_correct() { test_callsite(log::Level::Debug); } #[test] fn trace_callsite_is_correct() { test_callsite(log::Level::Trace); } }