1//! A `tracing` [`Subscriber`] that uses the [`log`] crate as a backend for
2//! formatting `tracing` spans and events.
3//!
4//! When a [`TraceLogger`] is set as the current subscriber, it will record
5//! traces by emitting [`log::Record`]s that can be collected by a logger.
6//!
7//! **Note**: This API has been deprecated since version 0.1.1. In order to emit
8//! `tracing` events as `log` records, the ["log" and "log-always" feature
9//! flags][flags] on the `tracing` crate should be used instead.
10//!
11//! [`log`]: log
12//! [`Subscriber`]: https://docs.rs/tracing/0.1.7/tracing/subscriber/trait.Subscriber.html
13//! [`log::Record`]:log::Record
14//! [flags]: https://docs.rs/tracing/latest/tracing/#crate-feature-flags
15#![deprecated(
16 since = "0.1.1",
17 note = "use the `tracing` crate's \"log\" feature flag instead"
18)]
19use crate::AsLog;
20use std::{
21 cell::RefCell,
22 collections::HashMap,
23 fmt::{self, Write},
24 sync::{
25 atomic::{AtomicUsize, Ordering},
26 Mutex,
27 },
28};
29use tracing_core::{
30 field,
31 span::{self, Id},
32 Event, Metadata, Subscriber,
33};
34
35/// A `tracing` [`Subscriber`] implementation that logs all recorded
36/// trace events.
37///
38/// **Note**: This API has been deprecated since version 0.1.1. In order to emit
39/// `tracing` events as `log` records, the ["log" and "log-always" feature
40/// flags][flags] on the `tracing` crate should be used instead.
41///
42/// [`Subscriber`]: https://docs.rs/tracing/0.1.7/tracing/subscriber/trait.Subscriber.html
43/// [flags]: https://docs.rs/tracing/latest/tracing/#crate-feature-flags
44pub struct TraceLogger {
45 settings: Builder,
46 spans: Mutex<HashMap<Id, SpanLineBuilder>>,
47 next_id: AtomicUsize,
48}
49
50thread_local! {
51 static CURRENT: RefCell<Vec<Id>> = RefCell::new(Vec::new());
52}
53/// Configures and constructs a [`TraceLogger`].
54///
55#[derive(Debug)]
56pub struct Builder {
57 log_span_closes: bool,
58 log_enters: bool,
59 log_exits: bool,
60 log_ids: bool,
61 parent_fields: bool,
62 log_parent: bool,
63}
64
65// ===== impl TraceLogger =====
66
67impl TraceLogger {
68 /// Returns a new `TraceLogger` with the default configuration.
69 pub fn new() -> Self {
70 Self::builder().finish()
71 }
72
73 /// Returns a `Builder` for configuring a `TraceLogger`.
74 pub fn builder() -> Builder {
75 Default::default()
76 }
77
78 fn from_builder(settings: Builder) -> Self {
79 Self {
80 settings,
81 ..Default::default()
82 }
83 }
84
85 fn next_id(&self) -> Id {
86 Id::from_u64(self.next_id.fetch_add(val:1, order:Ordering::SeqCst) as u64)
87 }
88}
89
90// ===== impl Builder =====
91
92impl Builder {
93 /// Configures whether or not the [`TraceLogger`] being constructed will log
94 /// when a span closes.
95 ///
96 pub fn with_span_closes(self, log_span_closes: bool) -> Self {
97 Self {
98 log_span_closes,
99 ..self
100 }
101 }
102
103 /// Configures whether or not the [`TraceLogger`] being constructed will
104 /// include the fields of parent spans when formatting events.
105 ///
106 pub fn with_parent_fields(self, parent_fields: bool) -> Self {
107 Self {
108 parent_fields,
109 ..self
110 }
111 }
112
113 /// Configures whether or not the [`TraceLogger`] being constructed will log
114 /// when a span is entered.
115 ///
116 /// If this is set to false, fields from the current span will still be
117 /// recorded as context, but the actual entry will not create a log record.
118 ///
119 pub fn with_span_entry(self, log_enters: bool) -> Self {
120 Self { log_enters, ..self }
121 }
122
123 /// Configures whether or not the [`TraceLogger`] being constructed will log
124 /// when a span is exited.
125 ///
126 pub fn with_span_exits(self, log_exits: bool) -> Self {
127 Self { log_exits, ..self }
128 }
129
130 /// Configures whether or not the [`TraceLogger`] being constructed will
131 /// include span IDs when formatting log output.
132 ///
133 pub fn with_ids(self, log_ids: bool) -> Self {
134 Self { log_ids, ..self }
135 }
136
137 /// Configures whether or not the [`TraceLogger`] being constructed will
138 /// include the names of parent spans as context when formatting events.
139 ///
140 pub fn with_parent_names(self, log_parent: bool) -> Self {
141 Self { log_parent, ..self }
142 }
143
144 /// Complete the builder, returning a configured [`TraceLogger`].
145 ///
146 pub fn finish(self) -> TraceLogger {
147 TraceLogger::from_builder(self)
148 }
149}
150
151impl Default for Builder {
152 fn default() -> Self {
153 Builder {
154 log_span_closes: false,
155 parent_fields: true,
156 log_exits: false,
157 log_ids: false,
158 log_parent: true,
159 log_enters: false,
160 }
161 }
162}
163
164impl Default for TraceLogger {
165 fn default() -> Self {
166 TraceLogger {
167 settings: Default::default(),
168 spans: Default::default(),
169 next_id: AtomicUsize::new(1),
170 }
171 }
172}
173
174#[derive(Debug)]
175struct SpanLineBuilder {
176 parent: Option<Id>,
177 ref_count: usize,
178 fields: String,
179 file: Option<String>,
180 line: Option<u32>,
181 module_path: Option<String>,
182 target: String,
183 level: log::Level,
184 name: &'static str,
185}
186
187impl SpanLineBuilder {
188 fn new(parent: Option<Id>, meta: &Metadata<'_>, fields: String) -> Self {
189 Self {
190 parent,
191 ref_count: 1,
192 fields,
193 file: meta.file().map(String::from),
194 line: meta.line(),
195 module_path: meta.module_path().map(String::from),
196 target: String::from(meta.target()),
197 level: meta.level().as_log(),
198 name: meta.name(),
199 }
200 }
201
202 fn log_meta(&self) -> log::Metadata<'_> {
203 log::MetadataBuilder::new()
204 .level(self.level)
205 .target(self.target.as_ref())
206 .build()
207 }
208
209 fn finish(self) {
210 let log_meta = self.log_meta();
211 let logger = log::logger();
212 if logger.enabled(&log_meta) {
213 logger.log(
214 &log::Record::builder()
215 .metadata(log_meta)
216 .target(self.target.as_ref())
217 .module_path(self.module_path.as_ref().map(String::as_ref))
218 .file(self.file.as_ref().map(String::as_ref))
219 .line(self.line)
220 .args(format_args!("close {}; {}", self.name, self.fields))
221 .build(),
222 );
223 }
224 }
225}
226
227impl field::Visit for SpanLineBuilder {
228 fn record_debug(&mut self, field: &field::Field, value: &dyn fmt::Debug) {
229 write!(self.fields, " {}={:?};", field.name(), value)
230 .expect(msg:"write to string should never fail")
231 }
232}
233
234impl Subscriber for TraceLogger {
235 fn enabled(&self, metadata: &Metadata<'_>) -> bool {
236 log::logger().enabled(&metadata.as_log())
237 }
238
239 fn new_span(&self, attrs: &span::Attributes<'_>) -> Id {
240 let id = self.next_id();
241 let mut spans = self.spans.lock().unwrap();
242 let mut fields = String::new();
243 let parent = self.current_id();
244 if self.settings.parent_fields {
245 let mut next_parent = parent.as_ref();
246 while let Some(parent) = next_parent.and_then(|p| spans.get(p)) {
247 write!(&mut fields, "{}", parent.fields).expect("write to string cannot fail");
248 next_parent = parent.parent.as_ref();
249 }
250 }
251 let mut span = SpanLineBuilder::new(parent, attrs.metadata(), fields);
252 attrs.record(&mut span);
253 spans.insert(id.clone(), span);
254 id
255 }
256
257 fn record(&self, span: &Id, values: &span::Record<'_>) {
258 let mut spans = self.spans.lock().unwrap();
259 if let Some(span) = spans.get_mut(span) {
260 values.record(span);
261 }
262 }
263
264 fn record_follows_from(&self, span: &Id, follows: &Id) {
265 // TODO: this should eventually track the relationship?
266 log::logger().log(
267 &log::Record::builder()
268 .level(log::Level::Trace)
269 .args(format_args!("span {:?} follows_from={:?};", span, follows))
270 .build(),
271 );
272 }
273
274 fn enter(&self, id: &Id) {
275 let _ = CURRENT.try_with(|current| {
276 let mut current = current.borrow_mut();
277 if current.contains(id) {
278 // Ignore duplicate enters.
279 return;
280 }
281 current.push(id.clone());
282 });
283 let spans = self.spans.lock().unwrap();
284 if self.settings.log_enters {
285 if let Some(span) = spans.get(id) {
286 let log_meta = span.log_meta();
287 let logger = log::logger();
288 if logger.enabled(&log_meta) {
289 let current_id = self.current_id();
290 let current_fields = current_id
291 .as_ref()
292 .and_then(|id| spans.get(id))
293 .map(|span| span.fields.as_ref())
294 .unwrap_or("");
295 if self.settings.log_ids {
296 logger.log(
297 &log::Record::builder()
298 .metadata(log_meta)
299 .target(span.target.as_ref())
300 .module_path(span.module_path.as_ref().map(String::as_ref))
301 .file(span.file.as_ref().map(String::as_ref))
302 .line(span.line)
303 .args(format_args!(
304 "enter {}; in={:?}; {}",
305 span.name, current_id, current_fields
306 ))
307 .build(),
308 );
309 } else {
310 logger.log(
311 &log::Record::builder()
312 .metadata(log_meta)
313 .target(span.target.as_ref())
314 .module_path(span.module_path.as_ref().map(String::as_ref))
315 .file(span.file.as_ref().map(String::as_ref))
316 .line(span.line)
317 .args(format_args!("enter {}; {}", span.name, current_fields))
318 .build(),
319 );
320 }
321 }
322 }
323 }
324 }
325
326 fn exit(&self, id: &Id) {
327 let _ = CURRENT.try_with(|current| {
328 let mut current = current.borrow_mut();
329 if current.last() == Some(id) {
330 current.pop()
331 } else {
332 None
333 }
334 });
335 if self.settings.log_exits {
336 let spans = self.spans.lock().unwrap();
337 if let Some(span) = spans.get(id) {
338 let log_meta = span.log_meta();
339 let logger = log::logger();
340 if logger.enabled(&log_meta) {
341 logger.log(
342 &log::Record::builder()
343 .metadata(log_meta)
344 .target(span.target.as_ref())
345 .module_path(span.module_path.as_ref().map(String::as_ref))
346 .file(span.file.as_ref().map(String::as_ref))
347 .line(span.line)
348 .args(format_args!("exit {}", span.name))
349 .build(),
350 );
351 }
352 }
353 }
354 }
355
356 fn event(&self, event: &Event<'_>) {
357 let meta = event.metadata();
358 let log_meta = meta.as_log();
359 let logger = log::logger();
360 if logger.enabled(&log_meta) {
361 let spans = self.spans.lock().unwrap();
362 let current = self.current_id().and_then(|id| spans.get(&id));
363 let (current_fields, parent) = current
364 .map(|span| {
365 let fields = span.fields.as_ref();
366 let parent = if self.settings.log_parent {
367 Some(span.name)
368 } else {
369 None
370 };
371 (fields, parent)
372 })
373 .unwrap_or(("", None));
374 logger.log(
375 &log::Record::builder()
376 .metadata(log_meta)
377 .target(meta.target())
378 .module_path(meta.module_path().as_ref().cloned())
379 .file(meta.file().as_ref().cloned())
380 .line(meta.line())
381 .args(format_args!(
382 "{}{}{}{}",
383 parent.unwrap_or(""),
384 if parent.is_some() { ": " } else { "" },
385 LogEvent(event),
386 current_fields,
387 ))
388 .build(),
389 );
390 }
391 }
392
393 fn clone_span(&self, id: &Id) -> Id {
394 let mut spans = self.spans.lock().unwrap();
395 if let Some(span) = spans.get_mut(id) {
396 span.ref_count += 1;
397 }
398 id.clone()
399 }
400
401 fn try_close(&self, id: Id) -> bool {
402 let mut spans = self.spans.lock().unwrap();
403 if spans.contains_key(&id) {
404 if spans.get(&id).unwrap().ref_count == 1 {
405 let span = spans.remove(&id).unwrap();
406 if self.settings.log_span_closes {
407 span.finish();
408 }
409 return true;
410 } else {
411 spans.get_mut(&id).unwrap().ref_count -= 1;
412 }
413 }
414 false
415 }
416}
417
418impl TraceLogger {
419 #[inline]
420 fn current_id(&self) -> Option<Id> {
421 CURRENT
422 .try_with(|current: &RefCell>| current.borrow().last().map(|span: &Id| self.clone_span(id:span)))
423 .ok()?
424 }
425}
426
427struct LogEvent<'a>(&'a Event<'a>);
428
429impl<'a> fmt::Display for LogEvent<'a> {
430 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
431 let mut has_logged: bool = false;
432 let mut format_fields: impl FnMut(&Field, &dyn Debug) = |field: &field::Field, value: &dyn fmt::Debug| {
433 let name: &str = field.name();
434 let leading: &str = if has_logged { " " } else { "" };
435 // TODO: handle fmt error?
436 let _ = if name == "message" {
437 write!(f, "{}{:?};", leading, value)
438 } else {
439 write!(f, "{}{}={:?};", leading, name, value)
440 };
441 has_logged = true;
442 };
443
444 self.0.record(&mut format_fields);
445 Ok(())
446 }
447}
448
449impl fmt::Debug for TraceLogger {
450 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
451 f&mut DebugStruct<'_, '_>.debug_struct("TraceLogger")
452 .field("settings", &self.settings)
453 .field("spans", &self.spans)
454 .field("current", &self.current_id())
455 .field(name:"next_id", &self.next_id)
456 .finish()
457 }
458}
459