| //! A `tracing` [`Subscriber`] that uses the [`log`] crate as a backend for |
| //! formatting `tracing` spans and events. |
| //! |
| //! When a [`TraceLogger`] is set as the current subscriber, it will record |
| //! traces by emitting [`log::Record`]s that can be collected by a logger. |
| //! |
| //! **Note**: This API has been deprecated since version 0.1.1. In order to emit |
| //! `tracing` events as `log` records, the ["log" and "log-always" feature |
| //! flags][flags] on the `tracing` crate should be used instead. |
| //! |
| //! [`log`]: https://docs.rs/log/0.4.8/log/index.html |
| //! [`Subscriber`]: https://docs.rs/tracing/0.1.7/tracing/subscriber/trait.Subscriber.html |
| //! [`TraceLogger`]: struct.TraceLogger.html |
| //! [`log::Record`]: https://docs.rs/log/0.4.8/log/struct.Record.html |
| //! [flags]: https://docs.rs/tracing/0.1.10/tracing/#crate-feature-flags |
| #![deprecated(since = "0.1.1", note = "use the `tracing` crate's \"log\" feature flag instead")] |
| use crate::AsLog; |
| use std::{ |
| cell::RefCell, |
| collections::HashMap, |
| fmt::{self, Write}, |
| sync::{ |
| atomic::{AtomicUsize, Ordering}, |
| Mutex, |
| }, |
| }; |
| use tracing_core::{ |
| field, |
| span::{self, Id}, |
| Event, Metadata, Subscriber, |
| }; |
| |
| /// A `tracing` [`Subscriber`] implementation that logs all recorded |
| /// trace events. |
| /// |
| /// **Note**: This API has been deprecated since version 0.1.1. In order to emit |
| /// `tracing` events as `log` records, the ["log" and "log-always" feature |
| /// flags][flags] on the `tracing` crate should be used instead. |
| /// |
| /// [`Subscriber`]: https://docs.rs/tracing/0.1.7/tracing/subscriber/trait.Subscriber.html |
| pub struct TraceLogger { |
| settings: Builder, |
| spans: Mutex<HashMap<Id, SpanLineBuilder>>, |
| next_id: AtomicUsize, |
| } |
| |
| thread_local! { |
| static CURRENT: RefCell<Vec<Id>> = RefCell::new(Vec::new()); |
| } |
| /// Configures and constructs a [`TraceLogger`]. |
| /// |
| /// [`TraceLogger`]: struct.TraceLogger.html |
| #[derive(Debug)] |
| pub struct Builder { |
| log_span_closes: bool, |
| log_enters: bool, |
| log_exits: bool, |
| log_ids: bool, |
| parent_fields: bool, |
| log_parent: bool, |
| } |
| |
| // ===== impl TraceLogger ===== |
| |
| impl TraceLogger { |
| /// Returns a new `TraceLogger` with the default configuration. |
| pub fn new() -> Self { |
| Self::builder().finish() |
| } |
| |
| /// Returns a `Builder` for configuring a `TraceLogger`. |
| pub fn builder() -> Builder { |
| Default::default() |
| } |
| |
| fn from_builder(settings: Builder) -> Self { |
| Self { |
| settings, |
| ..Default::default() |
| } |
| } |
| |
| fn next_id(&self) -> Id { |
| Id::from_u64(self.next_id.fetch_add(1, Ordering::SeqCst) as u64) |
| } |
| } |
| |
| // ===== impl Builder ===== |
| |
| impl Builder { |
| /// Configures whether or not the [`TraceLogger`] being constructed will log |
| /// when a span closes. |
| /// |
| /// [`TraceLogger`]: struct.TraceLogger.html |
| pub fn with_span_closes(self, log_span_closes: bool) -> Self { |
| Self { |
| log_span_closes, |
| ..self |
| } |
| } |
| |
| /// Configures whether or not the [`TraceLogger`] being constructed will |
| /// include the fields of parent spans when formatting events. |
| /// |
| /// [`TraceLogger`]: struct.TraceLogger.html |
| pub fn with_parent_fields(self, parent_fields: bool) -> Self { |
| Self { |
| parent_fields, |
| ..self |
| } |
| } |
| |
| /// Configures whether or not the [`TraceLogger`] being constructed will log |
| /// when a span is entered. |
| /// |
| /// If this is set to false, fields from the current span will still be |
| /// recorded as context, but the actual entry will not create a log record. |
| /// |
| /// [`TraceLogger`]: struct.TraceLogger.html |
| pub fn with_span_entry(self, log_enters: bool) -> Self { |
| Self { log_enters, ..self } |
| } |
| |
| /// Configures whether or not the [`TraceLogger`] being constructed will log |
| /// when a span is exited. |
| /// |
| /// [`TraceLogger`]: struct.TraceLogger.html |
| pub fn with_span_exits(self, log_exits: bool) -> Self { |
| Self { log_exits, ..self } |
| } |
| |
| /// Configures whether or not the [`TraceLogger`] being constructed will |
| /// include span IDs when formatting log output. |
| /// |
| /// [`TraceLogger`]: struct.TraceLogger.html |
| pub fn with_ids(self, log_ids: bool) -> Self { |
| Self { log_ids, ..self } |
| } |
| |
| /// Configures whether or not the [`TraceLogger`] being constructed will |
| /// include the names of parent spans as context when formatting events. |
| /// |
| /// [`TraceLogger`]: struct.TraceLogger.html |
| pub fn with_parent_names(self, log_parent: bool) -> Self { |
| Self { log_parent, ..self } |
| } |
| |
| /// Complete the builder, returning a configured [`TraceLogger`]. |
| /// |
| /// [`TraceLogger`]: struct.TraceLogger.html |
| pub fn finish(self) -> TraceLogger { |
| TraceLogger::from_builder(self) |
| } |
| } |
| |
| impl Default for Builder { |
| fn default() -> Self { |
| Builder { |
| log_span_closes: false, |
| parent_fields: true, |
| log_exits: false, |
| log_ids: false, |
| log_parent: true, |
| log_enters: false, |
| } |
| } |
| } |
| |
| impl Default for TraceLogger { |
| fn default() -> Self { |
| TraceLogger { |
| settings: Default::default(), |
| spans: Default::default(), |
| next_id: AtomicUsize::new(1), |
| } |
| } |
| } |
| |
| #[derive(Debug)] |
| struct SpanLineBuilder { |
| parent: Option<Id>, |
| ref_count: usize, |
| fields: String, |
| file: Option<String>, |
| line: Option<u32>, |
| module_path: Option<String>, |
| target: String, |
| level: log::Level, |
| name: &'static str, |
| } |
| |
| impl SpanLineBuilder { |
| fn new(parent: Option<Id>, meta: &Metadata<'_>, fields: String) -> Self { |
| Self { |
| parent, |
| ref_count: 1, |
| fields, |
| file: meta.file().map(String::from), |
| line: meta.line(), |
| module_path: meta.module_path().map(String::from), |
| target: String::from(meta.target()), |
| level: meta.level().as_log(), |
| name: meta.name(), |
| } |
| } |
| |
| fn log_meta(&self) -> log::Metadata<'_> { |
| log::MetadataBuilder::new() |
| .level(self.level) |
| .target(self.target.as_ref()) |
| .build() |
| } |
| |
| fn finish(self) { |
| let log_meta = self.log_meta(); |
| let logger = log::logger(); |
| if logger.enabled(&log_meta) { |
| logger.log( |
| &log::Record::builder() |
| .metadata(log_meta) |
| .target(self.target.as_ref()) |
| .module_path(self.module_path.as_ref().map(String::as_ref)) |
| .file(self.file.as_ref().map(String::as_ref)) |
| .line(self.line) |
| .args(format_args!("close {}; {}", self.name, self.fields)) |
| .build(), |
| ); |
| } |
| } |
| } |
| |
| impl field::Visit for SpanLineBuilder { |
| fn record_debug(&mut self, field: &field::Field, value: &dyn fmt::Debug) { |
| write!(self.fields, " {}={:?};", field.name(), value) |
| .expect("write to string should never fail") |
| } |
| } |
| |
| impl Subscriber for TraceLogger { |
| fn enabled(&self, metadata: &Metadata<'_>) -> bool { |
| log::logger().enabled(&metadata.as_log()) |
| } |
| |
| fn new_span(&self, attrs: &span::Attributes<'_>) -> Id { |
| let id = self.next_id(); |
| let mut spans = self.spans.lock().unwrap(); |
| let mut fields = String::new(); |
| let parent = self.current_id(); |
| if self.settings.parent_fields { |
| let mut next_parent = parent.as_ref(); |
| while let Some(ref parent) = next_parent.and_then(|p| spans.get(&p)) { |
| write!(&mut fields, "{}", parent.fields).expect("write to string cannot fail"); |
| next_parent = parent.parent.as_ref(); |
| } |
| } |
| let mut span = SpanLineBuilder::new(parent, attrs.metadata(), fields); |
| attrs.record(&mut span); |
| spans.insert(id.clone(), span); |
| id |
| } |
| |
| fn record(&self, span: &Id, values: &span::Record<'_>) { |
| let mut spans = self.spans.lock().unwrap(); |
| if let Some(span) = spans.get_mut(span) { |
| values.record(span); |
| } |
| } |
| |
| fn record_follows_from(&self, span: &Id, follows: &Id) { |
| // TODO: this should eventually track the relationship? |
| log::logger().log( |
| &log::Record::builder() |
| .level(log::Level::Trace) |
| .args(format_args!("span {:?} follows_from={:?};", span, follows)) |
| .build(), |
| ); |
| } |
| |
| fn enter(&self, id: &Id) { |
| let _ = CURRENT.try_with(|current| { |
| let mut current = current.borrow_mut(); |
| if current.contains(id) { |
| // Ignore duplicate enters. |
| return; |
| } |
| current.push(id.clone()); |
| }); |
| let spans = self.spans.lock().unwrap(); |
| if self.settings.log_enters { |
| if let Some(span) = spans.get(id) { |
| let log_meta = span.log_meta(); |
| let logger = log::logger(); |
| if logger.enabled(&log_meta) { |
| let current_id = self.current_id(); |
| let current_fields = current_id |
| .as_ref() |
| .and_then(|id| spans.get(&id)) |
| .map(|span| span.fields.as_ref()) |
| .unwrap_or(""); |
| if self.settings.log_ids { |
| logger.log( |
| &log::Record::builder() |
| .metadata(log_meta) |
| .target(span.target.as_ref()) |
| .module_path(span.module_path.as_ref().map(String::as_ref)) |
| .file(span.file.as_ref().map(String::as_ref)) |
| .line(span.line) |
| .args(format_args!( |
| "enter {}; in={:?}; {}", |
| span.name, current_id, current_fields |
| )) |
| .build(), |
| ); |
| } else { |
| logger.log( |
| &log::Record::builder() |
| .metadata(log_meta) |
| .target(span.target.as_ref()) |
| .module_path(span.module_path.as_ref().map(String::as_ref)) |
| .file(span.file.as_ref().map(String::as_ref)) |
| .line(span.line) |
| .args(format_args!("enter {}; {}", span.name, current_fields)) |
| .build(), |
| ); |
| } |
| } |
| } |
| } |
| } |
| |
| fn exit(&self, id: &Id) { |
| let _ = CURRENT.try_with(|current| { |
| let mut current = current.borrow_mut(); |
| if current.last() == Some(id) { |
| current.pop() |
| } else { |
| None |
| } |
| }); |
| if self.settings.log_exits { |
| let spans = self.spans.lock().unwrap(); |
| if let Some(span) = spans.get(id) { |
| let log_meta = span.log_meta(); |
| let logger = log::logger(); |
| if logger.enabled(&log_meta) { |
| logger.log( |
| &log::Record::builder() |
| .metadata(log_meta) |
| .target(span.target.as_ref()) |
| .module_path(span.module_path.as_ref().map(String::as_ref)) |
| .file(span.file.as_ref().map(String::as_ref)) |
| .line(span.line) |
| .args(format_args!("exit {}", span.name)) |
| .build(), |
| ); |
| } |
| } |
| } |
| } |
| |
| fn event(&self, event: &Event<'_>) { |
| let meta = event.metadata(); |
| let log_meta = meta.as_log(); |
| let logger = log::logger(); |
| if logger.enabled(&log_meta) { |
| let spans = self.spans.lock().unwrap(); |
| let current = self.current_id().and_then(|id| spans.get(&id)); |
| let (current_fields, parent) = current |
| .map(|span| { |
| let fields = span.fields.as_ref(); |
| let parent = if self.settings.log_parent { |
| Some(span.name) |
| } else { |
| None |
| }; |
| (fields, parent) |
| }) |
| .unwrap_or(("", None)); |
| logger.log( |
| &log::Record::builder() |
| .metadata(log_meta) |
| .target(meta.target()) |
| .module_path(meta.module_path().as_ref().cloned()) |
| .file(meta.file().as_ref().cloned()) |
| .line(meta.line()) |
| .args(format_args!( |
| "{}{}{}{}", |
| parent.unwrap_or(""), |
| if parent.is_some() { ": " } else { "" }, |
| LogEvent(event), |
| current_fields, |
| )) |
| .build(), |
| ); |
| } |
| } |
| |
| fn clone_span(&self, id: &Id) -> Id { |
| let mut spans = self.spans.lock().unwrap(); |
| if let Some(span) = spans.get_mut(id) { |
| span.ref_count += 1; |
| } |
| id.clone() |
| } |
| |
| fn try_close(&self, id: Id) -> bool { |
| let mut spans = self.spans.lock().unwrap(); |
| if spans.contains_key(&id) { |
| if spans.get(&id).unwrap().ref_count == 1 { |
| let span = spans.remove(&id).unwrap(); |
| if self.settings.log_span_closes { |
| span.finish(); |
| } |
| return true; |
| } else { |
| spans.get_mut(&id).unwrap().ref_count -= 1; |
| } |
| } |
| false |
| } |
| } |
| |
| impl TraceLogger { |
| #[inline] |
| fn current_id(&self) -> Option<Id> { |
| CURRENT |
| .try_with(|current| current.borrow().last().map(|span| self.clone_span(span))) |
| .ok()? |
| } |
| } |
| |
| struct LogEvent<'a>(&'a Event<'a>); |
| |
| impl<'a> fmt::Display for LogEvent<'a> { |
| fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { |
| let mut has_logged = false; |
| let mut format_fields = |field: &field::Field, value: &dyn fmt::Debug| { |
| let name = field.name(); |
| let leading = if has_logged { " " } else { "" }; |
| // TODO: handle fmt error? |
| let _ = if name == "message" { |
| write!(f, "{}{:?};", leading, value) |
| } else { |
| write!(f, "{}{}={:?};", leading, name, value) |
| }; |
| has_logged = true; |
| }; |
| |
| self.0.record(&mut format_fields); |
| Ok(()) |
| } |
| } |
| |
| impl fmt::Debug for TraceLogger { |
| fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { |
| f.debug_struct("TraceLogger") |
| .field("settings", &self.settings) |
| .field("spans", &self.spans) |
| .field("current", &self.current_id()) |
| .field("next_id", &self.next_id) |
| .finish() |
| } |
| } |