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.56+][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.56. 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/master/assets/logo-type.png",
99 issue_tracker_base_url = "https://github.com/tokio-rs/tracing/issues/"
100)]
101#![cfg_attr(docsrs, feature(doc_cfg), deny(rustdoc::broken_intra_doc_links))]
102#![warn(
103 missing_debug_implementations,
104 missing_docs,
105 rust_2018_idioms,
106 unreachable_pub,
107 bad_style,
108 dead_code,
109 improper_ctypes,
110 non_shorthand_field_patterns,
111 no_mangle_generic_items,
112 overflowing_literals,
113 path_statements,
114 patterns_in_fns_without_body,
115 private_in_public,
116 unconditional_recursion,
117 unused,
118 unused_allocation,
119 unused_comparisons,
120 unused_parens,
121 while_true
122)]
123use once_cell::sync::Lazy;
124
125use std::{fmt, io};
126
127use tracing_core::{
128 callsite::{self, Callsite},
129 dispatcher,
130 field::{self, Field, Visit},
131 identify_callsite,
132 metadata::{Kind, Level},
133 subscriber, Event, Metadata,
134};
135
136#[cfg(feature = "log-tracer")]
137#[cfg_attr(docsrs, doc(cfg(feature = "log-tracer")))]
138pub mod log_tracer;
139
140#[cfg(feature = "log-tracer")]
141#[cfg_attr(docsrs, doc(cfg(feature = "log-tracer")))]
142#[doc(inline)]
143pub use self::log_tracer::LogTracer;
144
145pub use log;
146
147#[cfg(all(feature = "interest-cache", feature = "log-tracer", feature = "std"))]
148mod interest_cache;
149
150#[cfg(all(feature = "interest-cache", feature = "log-tracer", feature = "std"))]
151#[cfg_attr(
152 docsrs,
153 doc(cfg(all(feature = "interest-cache", feature = "log-tracer", feature = "std")))
154)]
155pub use crate::interest_cache::InterestCacheConfig;
156
157/// Format a log record as a trace event in the current span.
158pub fn format_trace(record: &log::Record<'_>) -> io::Result<()> {
159 dispatch_record(record);
160 Ok(())
161}
162
163// XXX(eliza): this is factored out so that we don't have to deal with the pub
164// function `format_trace`'s `Result` return type...maybe we should get rid of
165// that in 0.2...
166pub(crate) fn dispatch_record(record: &log::Record<'_>) {
167 dispatcher::get_default(|dispatch| {
168 let filter_meta = record.as_trace();
169 if !dispatch.enabled(&filter_meta) {
170 return;
171 }
172
173 let (_, keys, meta) = loglevel_to_cs(record.level());
174
175 let log_module = record.module_path();
176 let log_file = record.file();
177 let log_line = record.line();
178
179 let module = log_module.as_ref().map(|s| s as &dyn field::Value);
180 let file = log_file.as_ref().map(|s| s as &dyn field::Value);
181 let line = log_line.as_ref().map(|s| s as &dyn field::Value);
182
183 dispatch.event(&Event::new(
184 meta,
185 &meta.fields().value_set(&[
186 (&keys.message, Some(record.args() as &dyn field::Value)),
187 (&keys.target, Some(&record.target())),
188 (&keys.module, module),
189 (&keys.file, file),
190 (&keys.line, line),
191 ]),
192 ));
193 });
194}
195
196/// Trait implemented for `tracing` types that can be converted to a `log`
197/// equivalent.
198pub trait AsLog: crate::sealed::Sealed {
199 /// The `log` type that this type can be converted into.
200 type Log;
201 /// Returns the `log` equivalent of `self`.
202 fn as_log(&self) -> Self::Log;
203}
204
205/// Trait implemented for `log` types that can be converted to a `tracing`
206/// equivalent.
207pub trait AsTrace: crate::sealed::Sealed {
208 /// The `tracing` type that this type can be converted into.
209 type Trace;
210 /// Returns the `tracing` equivalent of `self`.
211 fn as_trace(&self) -> Self::Trace;
212}
213
214impl<'a> crate::sealed::Sealed for Metadata<'a> {}
215
216impl<'a> AsLog for Metadata<'a> {
217 type Log = log::Metadata<'a>;
218 fn as_log(&self) -> Self::Log {
219 log&mut MetadataBuilder<'_>::Metadata::builder()
220 .level(self.level().as_log())
221 .target(self.target())
222 .build()
223 }
224}
225impl<'a> crate::sealed::Sealed for log::Metadata<'a> {}
226
227impl<'a> AsTrace for log::Metadata<'a> {
228 type Trace = Metadata<'a>;
229 fn as_trace(&self) -> Self::Trace {
230 let cs_id: Identifier = identify_callsite!(loglevel_to_cs(self.level()).0);
231 Metadata::new(
232 name:"log record",
233 self.target(),
234 self.level().as_trace(),
235 file:None,
236 line:None,
237 module_path:None,
238 fields:field::FieldSet::new(FIELD_NAMES, cs_id),
239 kind:Kind::EVENT,
240 )
241 }
242}
243
244struct Fields {
245 message: field::Field,
246 target: field::Field,
247 module: field::Field,
248 file: field::Field,
249 line: field::Field,
250}
251
252static FIELD_NAMES: &[&str] = &[
253 "message",
254 "log.target",
255 "log.module_path",
256 "log.file",
257 "log.line",
258];
259
260impl Fields {
261 fn new(cs: &'static dyn Callsite) -> Self {
262 let fieldset: &FieldSet = cs.metadata().fields();
263 let message: Field = fieldset.field(name:"message").unwrap();
264 let target: Field = fieldset.field(name:"log.target").unwrap();
265 let module: Field = fieldset.field(name:"log.module_path").unwrap();
266 let file: Field = fieldset.field(name:"log.file").unwrap();
267 let line: Field = fieldset.field(name:"log.line").unwrap();
268 Fields {
269 message,
270 target,
271 module,
272 file,
273 line,
274 }
275 }
276}
277
278macro_rules! log_cs {
279 ($level:expr, $cs:ident, $meta:ident, $ty:ident) => {
280 struct $ty;
281 static $cs: $ty = $ty;
282 static $meta: Metadata<'static> = Metadata::new(
283 "log event",
284 "log",
285 $level,
286 ::core::option::Option::None,
287 ::core::option::Option::None,
288 ::core::option::Option::None,
289 field::FieldSet::new(FIELD_NAMES, identify_callsite!(&$cs)),
290 Kind::EVENT,
291 );
292
293 impl callsite::Callsite for $ty {
294 fn set_interest(&self, _: subscriber::Interest) {}
295 fn metadata(&self) -> &'static Metadata<'static> {
296 &$meta
297 }
298 }
299 };
300}
301
302log_cs!(
303 tracing_core::Level::TRACE,
304 TRACE_CS,
305 TRACE_META,
306 TraceCallsite
307);
308log_cs!(
309 tracing_core::Level::DEBUG,
310 DEBUG_CS,
311 DEBUG_META,
312 DebugCallsite
313);
314log_cs!(tracing_core::Level::INFO, INFO_CS, INFO_META, InfoCallsite);
315log_cs!(tracing_core::Level::WARN, WARN_CS, WARN_META, WarnCallsite);
316log_cs!(
317 tracing_core::Level::ERROR,
318 ERROR_CS,
319 ERROR_META,
320 ErrorCallsite
321);
322
323static TRACE_FIELDS: Lazy<Fields> = Lazy::new(|| Fields::new(&TRACE_CS));
324static DEBUG_FIELDS: Lazy<Fields> = Lazy::new(|| Fields::new(&DEBUG_CS));
325static INFO_FIELDS: Lazy<Fields> = Lazy::new(|| Fields::new(&INFO_CS));
326static WARN_FIELDS: Lazy<Fields> = Lazy::new(|| Fields::new(&WARN_CS));
327static ERROR_FIELDS: Lazy<Fields> = Lazy::new(|| Fields::new(&ERROR_CS));
328
329fn level_to_cs(level: Level) -> (&'static dyn Callsite, &'static Fields) {
330 match level {
331 Level::TRACE => (&TRACE_CS, &*TRACE_FIELDS),
332 Level::DEBUG => (&DEBUG_CS, &*DEBUG_FIELDS),
333 Level::INFO => (&INFO_CS, &*INFO_FIELDS),
334 Level::WARN => (&WARN_CS, &*WARN_FIELDS),
335 Level::ERROR => (&ERROR_CS, &*ERROR_FIELDS),
336 }
337}
338
339fn loglevel_to_cs(
340 level: log::Level,
341) -> (
342 &'static dyn Callsite,
343 &'static Fields,
344 &'static Metadata<'static>,
345) {
346 match level {
347 log::Level::Trace => (&TRACE_CS, &*TRACE_FIELDS, &TRACE_META),
348 log::Level::Debug => (&DEBUG_CS, &*DEBUG_FIELDS, &DEBUG_META),
349 log::Level::Info => (&INFO_CS, &*INFO_FIELDS, &INFO_META),
350 log::Level::Warn => (&WARN_CS, &*WARN_FIELDS, &WARN_META),
351 log::Level::Error => (&ERROR_CS, &*ERROR_FIELDS, &ERROR_META),
352 }
353}
354
355impl<'a> crate::sealed::Sealed for log::Record<'a> {}
356
357impl<'a> AsTrace for log::Record<'a> {
358 type Trace = Metadata<'a>;
359 fn as_trace(&self) -> Self::Trace {
360 let cs_id: Identifier = identify_callsite!(loglevel_to_cs(self.level()).0);
361 Metadata::new(
362 name:"log record",
363 self.target(),
364 self.level().as_trace(),
365 self.file(),
366 self.line(),
367 self.module_path(),
368 fields:field::FieldSet::new(FIELD_NAMES, cs_id),
369 kind:Kind::EVENT,
370 )
371 }
372}
373
374impl crate::sealed::Sealed for tracing_core::Level {}
375
376impl AsLog for tracing_core::Level {
377 type Log = log::Level;
378 fn as_log(&self) -> log::Level {
379 match *self {
380 tracing_core::Level::ERROR => log::Level::Error,
381 tracing_core::Level::WARN => log::Level::Warn,
382 tracing_core::Level::INFO => log::Level::Info,
383 tracing_core::Level::DEBUG => log::Level::Debug,
384 tracing_core::Level::TRACE => log::Level::Trace,
385 }
386 }
387}
388
389impl crate::sealed::Sealed for log::Level {}
390
391impl AsTrace for log::Level {
392 type Trace = tracing_core::Level;
393 #[inline]
394 fn as_trace(&self) -> tracing_core::Level {
395 match self {
396 log::Level::Error => tracing_core::Level::ERROR,
397 log::Level::Warn => tracing_core::Level::WARN,
398 log::Level::Info => tracing_core::Level::INFO,
399 log::Level::Debug => tracing_core::Level::DEBUG,
400 log::Level::Trace => tracing_core::Level::TRACE,
401 }
402 }
403}
404
405impl crate::sealed::Sealed for log::LevelFilter {}
406
407impl AsTrace for log::LevelFilter {
408 type Trace = tracing_core::LevelFilter;
409 #[inline]
410 fn as_trace(&self) -> tracing_core::LevelFilter {
411 match self {
412 log::LevelFilter::Off => tracing_core::LevelFilter::OFF,
413 log::LevelFilter::Error => tracing_core::LevelFilter::ERROR,
414 log::LevelFilter::Warn => tracing_core::LevelFilter::WARN,
415 log::LevelFilter::Info => tracing_core::LevelFilter::INFO,
416 log::LevelFilter::Debug => tracing_core::LevelFilter::DEBUG,
417 log::LevelFilter::Trace => tracing_core::LevelFilter::TRACE,
418 }
419 }
420}
421
422impl crate::sealed::Sealed for tracing_core::LevelFilter {}
423
424impl AsLog for tracing_core::LevelFilter {
425 type Log = log::LevelFilter;
426 #[inline]
427 fn as_log(&self) -> Self::Log {
428 match *self {
429 tracing_core::LevelFilter::OFF => log::LevelFilter::Off,
430 tracing_core::LevelFilter::ERROR => log::LevelFilter::Error,
431 tracing_core::LevelFilter::WARN => log::LevelFilter::Warn,
432 tracing_core::LevelFilter::INFO => log::LevelFilter::Info,
433 tracing_core::LevelFilter::DEBUG => log::LevelFilter::Debug,
434 tracing_core::LevelFilter::TRACE => log::LevelFilter::Trace,
435 }
436 }
437}
438/// Extends log `Event`s to provide complete `Metadata`.
439///
440/// In `tracing-log`, an `Event` produced by a log (through [`AsTrace`]) has an hard coded
441/// "log" target and no `file`, `line`, or `module_path` attributes. This happens because `Event`
442/// requires its `Metadata` to be `'static`, while [`log::Record`]s provide them with a generic
443/// lifetime.
444///
445/// However, these values are stored in the `Event`'s fields and
446/// the [`normalized_metadata`] method allows to build a new `Metadata`
447/// that only lives as long as its source `Event`, but provides complete
448/// data.
449///
450/// It can typically be used by `Subscriber`s when processing an `Event`,
451/// to allow accessing its complete metadata in a consistent way,
452/// regardless of the source of its source.
453///
454/// [`normalized_metadata`]: NormalizeEvent#normalized_metadata
455pub trait NormalizeEvent<'a>: crate::sealed::Sealed {
456 /// If this `Event` comes from a `log`, this method provides a new
457 /// normalized `Metadata` which has all available attributes
458 /// from the original log, including `file`, `line`, `module_path`
459 /// and `target`.
460 /// Returns `None` is the `Event` is not issued from a `log`.
461 fn normalized_metadata(&'a self) -> Option<Metadata<'a>>;
462 /// Returns whether this `Event` represents a log (from the `log` crate)
463 fn is_log(&self) -> bool;
464}
465
466impl<'a> crate::sealed::Sealed for Event<'a> {}
467
468impl<'a> NormalizeEvent<'a> for Event<'a> {
469 fn normalized_metadata(&'a self) -> Option<Metadata<'a>> {
470 let original = self.metadata();
471 if self.is_log() {
472 let mut fields = LogVisitor::new_for(self, level_to_cs(*original.level()).1);
473 self.record(&mut fields);
474
475 Some(Metadata::new(
476 "log event",
477 fields.target.unwrap_or("log"),
478 *original.level(),
479 fields.file,
480 fields.line.map(|l| l as u32),
481 fields.module_path,
482 field::FieldSet::new(&["message"], original.callsite()),
483 Kind::EVENT,
484 ))
485 } else {
486 None
487 }
488 }
489
490 fn is_log(&self) -> bool {
491 self.metadata().callsite() == identify_callsite!(level_to_cs(*self.metadata().level()).0)
492 }
493}
494
495struct LogVisitor<'a> {
496 target: Option<&'a str>,
497 module_path: Option<&'a str>,
498 file: Option<&'a str>,
499 line: Option<u64>,
500 fields: &'static Fields,
501}
502
503impl<'a> LogVisitor<'a> {
504 // We don't actually _use_ the provided event argument; it is simply to
505 // ensure that the `LogVisitor` does not outlive the event whose fields it
506 // is visiting, so that the reference casts in `record_str` are safe.
507 fn new_for(_event: &'a Event<'a>, fields: &'static Fields) -> Self {
508 Self {
509 target: None,
510 module_path: None,
511 file: None,
512 line: None,
513 fields,
514 }
515 }
516}
517
518impl<'a> Visit for LogVisitor<'a> {
519 fn record_debug(&mut self, _field: &Field, _value: &dyn fmt::Debug) {}
520
521 fn record_u64(&mut self, field: &Field, value: u64) {
522 if field == &self.fields.line {
523 self.line = Some(value);
524 }
525 }
526
527 fn record_str(&mut self, field: &Field, value: &str) {
528 unsafe {
529 // The `Visit` API erases the string slice's lifetime. However, we
530 // know it is part of the `Event` struct with a lifetime of `'a`. If
531 // (and only if!) this `LogVisitor` was constructed with the same
532 // lifetime parameter `'a` as the event in question, it's safe to
533 // cast these string slices to the `'a` lifetime.
534 if field == &self.fields.file {
535 self.file = Some(&*(value as *const _));
536 } else if field == &self.fields.target {
537 self.target = Some(&*(value as *const _));
538 } else if field == &self.fields.module {
539 self.module_path = Some(&*(value as *const _));
540 }
541 }
542 }
543}
544
545mod sealed {
546 pub trait Sealed {}
547}
548
549#[cfg(test)]
550mod test {
551 use super::*;
552
553 fn test_callsite(level: log::Level) {
554 let record = log::Record::builder()
555 .args(format_args!("Error!"))
556 .level(level)
557 .target("myApp")
558 .file(Some("server.rs"))
559 .line(Some(144))
560 .module_path(Some("server"))
561 .build();
562
563 let meta = record.as_trace();
564 let (cs, _keys, _) = loglevel_to_cs(record.level());
565 let cs_meta = cs.metadata();
566 assert_eq!(
567 meta.callsite(),
568 cs_meta.callsite(),
569 "actual: {:#?}\nexpected: {:#?}",
570 meta,
571 cs_meta
572 );
573 assert_eq!(meta.level(), &level.as_trace());
574 }
575
576 #[test]
577 fn error_callsite_is_correct() {
578 test_callsite(log::Level::Error);
579 }
580
581 #[test]
582 fn warn_callsite_is_correct() {
583 test_callsite(log::Level::Warn);
584 }
585
586 #[test]
587 fn info_callsite_is_correct() {
588 test_callsite(log::Level::Info);
589 }
590
591 #[test]
592 fn debug_callsite_is_correct() {
593 test_callsite(log::Level::Debug);
594 }
595
596 #[test]
597 fn trace_callsite_is_correct() {
598 test_callsite(log::Level::Trace);
599 }
600}
601