tracing_bunyan_formatter/
formatting_layer.rs

1use crate::storage_layer::JsonStorage;
2use ahash::{HashSet, HashSetExt};
3use serde::ser::{Serialize, SerializeMap, Serializer};
4use serde_json::Value;
5use std::collections::HashMap;
6use std::fmt;
7use std::io::Write;
8use time::format_description::well_known::Rfc3339;
9use tracing::{Event, Id, Metadata, Subscriber};
10use tracing_core::metadata::Level;
11use tracing_core::span::Attributes;
12use tracing_log::AsLog;
13use tracing_subscriber::fmt::MakeWriter;
14use tracing_subscriber::layer::Context;
15use tracing_subscriber::registry::SpanRef;
16use tracing_subscriber::Layer;
17
18/// Keys for core fields of the Bunyan format (https://github.com/trentm/node-bunyan#core-fields)
19const BUNYAN_VERSION: &str = "v";
20const LEVEL: &str = "level";
21const NAME: &str = "name";
22const HOSTNAME: &str = "hostname";
23const PID: &str = "pid";
24const TIME: &str = "time";
25const MESSAGE: &str = "msg";
26const _SOURCE: &str = "src";
27
28const BUNYAN_REQUIRED_FIELDS: [&str; 7] =
29    [BUNYAN_VERSION, LEVEL, NAME, HOSTNAME, PID, TIME, MESSAGE];
30
31/// Convert from log levels to Bunyan's levels.
32fn to_bunyan_level(level: &Level) -> u16 {
33    match level.as_log() {
34        log::Level::Error => 50,
35        log::Level::Warn => 40,
36        log::Level::Info => 30,
37        log::Level::Debug => 20,
38        log::Level::Trace => 10,
39    }
40}
41
42/// This layer is exclusively concerned with formatting information using the [Bunyan format](https://github.com/trentm/node-bunyan).
43/// It relies on the upstream `JsonStorageLayer` to get access to the fields attached to
44/// each span.
45#[derive(Default)]
46pub struct BunyanFormattingLayer<W: for<'a> MakeWriter<'a> + 'static> {
47    make_writer: W,
48    pid: u32,
49    hostname: String,
50    bunyan_version: u8,
51    name: String,
52    default_fields: HashMap<String, Value>,
53    skip_fields: HashSet<String>,
54}
55
56/// This error will be returned in [`BunyanFormattingLayer::skip_fields`] if trying to skip a core field.
57#[non_exhaustive]
58#[derive(Debug)]
59pub struct SkipFieldError(String);
60
61impl fmt::Display for SkipFieldError {
62    fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
63        write!(
64            f,
65            "{} is a core field in the bunyan log format, it can't be skipped",
66            &self.0
67        )
68    }
69}
70
71impl std::error::Error for SkipFieldError {}
72
73impl<W: for<'a> MakeWriter<'a> + 'static> BunyanFormattingLayer<W> {
74    /// Create a new `BunyanFormattingLayer`.
75    ///
76    /// You have to specify:
77    /// - a `name`, which will be attached to all formatted records according to the [Bunyan format](https://github.com/trentm/node-bunyan#log-record-fields);
78    /// - a `make_writer`, which will be used to get a `Write` instance to write formatted records to.
79    ///
80    /// ## Using stdout
81    ///
82    /// ```rust
83    /// use tracing_bunyan_formatter::BunyanFormattingLayer;
84    ///
85    /// let formatting_layer = BunyanFormattingLayer::new("tracing_example".into(), std::io::stdout);
86    /// ```
87    ///
88    /// If you prefer, you can use closure syntax:
89    ///
90    /// ```rust
91    /// use tracing_bunyan_formatter::BunyanFormattingLayer;
92    ///
93    /// let formatting_layer = BunyanFormattingLayer::new("tracing_example".into(), || std::io::stdout());
94    /// ```
95    pub fn new(name: String, make_writer: W) -> Self {
96        Self::with_default_fields(name, make_writer, HashMap::new())
97    }
98
99    /// Add default fields to all formatted records.
100    ///
101    /// ```rust
102    /// use std::collections::HashMap;
103    /// use serde_json::json;
104    /// use tracing_bunyan_formatter::BunyanFormattingLayer;
105    ///
106    /// let mut default_fields = HashMap::new();
107    /// default_fields.insert("custom_field".to_string(), json!("custom_value"));
108    /// let formatting_layer = BunyanFormattingLayer::with_default_fields(
109    ///     "test".into(),
110    ///     std::io::stdout,
111    ///     default_fields,
112    /// );
113    /// ```
114    pub fn with_default_fields(
115        name: String,
116        make_writer: W,
117        default_fields: HashMap<String, Value>,
118    ) -> Self {
119        Self {
120            make_writer,
121            name,
122            pid: std::process::id(),
123            #[cfg(feature = "hostname")]
124            hostname: gethostname::gethostname().to_string_lossy().into_owned(),
125            #[cfg(not(feature = "hostname"))]
126            hostname: Default::default(),
127            bunyan_version: 0,
128            default_fields,
129            skip_fields: HashSet::new(),
130        }
131    }
132
133    /// Add fields to skip when formatting with this layer.
134    ///
135    /// It returns an error if you try to skip a required core Bunyan field (e.g. `name`).
136    /// You can skip optional core Bunyan fields (e.g. `line`, `file`, `target`).
137    ///
138    /// ```rust
139    /// use tracing_bunyan_formatter::BunyanFormattingLayer;
140    ///
141    /// let skipped_fields = vec!["skipped"];
142    /// let formatting_layer = BunyanFormattingLayer::new("test".into(), std::io::stdout)
143    ///     .skip_fields(skipped_fields.into_iter())
144    ///     .expect("One of the specified fields cannot be skipped");
145    /// ```
146    pub fn skip_fields<Fields, Field>(mut self, fields: Fields) -> Result<Self, SkipFieldError>
147    where
148        Fields: Iterator<Item = Field>,
149        Field: Into<String>,
150    {
151        for field in fields {
152            let field = field.into();
153            if BUNYAN_REQUIRED_FIELDS.contains(&field.as_str()) {
154                return Err(SkipFieldError(field));
155            }
156            self.skip_fields.insert(field);
157        }
158
159        Ok(self)
160    }
161
162    fn serialize_bunyan_core_fields(
163        &self,
164        map_serializer: &mut impl SerializeMap<Error = serde_json::Error>,
165        message: &str,
166        level: &Level,
167    ) -> Result<(), std::io::Error> {
168        map_serializer.serialize_entry(BUNYAN_VERSION, &self.bunyan_version)?;
169        map_serializer.serialize_entry(NAME, &self.name)?;
170        map_serializer.serialize_entry(MESSAGE, &message)?;
171        map_serializer.serialize_entry(LEVEL, &to_bunyan_level(level))?;
172        map_serializer.serialize_entry(HOSTNAME, &self.hostname)?;
173        map_serializer.serialize_entry(PID, &self.pid)?;
174        if let Ok(time) = &time::OffsetDateTime::now_utc().format(&Rfc3339) {
175            map_serializer.serialize_entry(TIME, time)?;
176        }
177        Ok(())
178    }
179
180    fn serialize_field<V>(
181        &self,
182        map_serializer: &mut impl SerializeMap<Error = serde_json::Error>,
183        key: &str,
184        value: &V,
185    ) -> Result<(), std::io::Error>
186    where
187        V: Serialize + ?Sized,
188    {
189        if !self.skip_fields.contains(key) {
190            map_serializer.serialize_entry(key, value)?;
191        }
192
193        Ok(())
194    }
195
196    /// Given a span, it serialised it to a in-memory buffer (vector of bytes).
197    fn serialize_span<S: Subscriber + for<'a> tracing_subscriber::registry::LookupSpan<'a>>(
198        &self,
199        span: &SpanRef<S>,
200        ty: Type,
201    ) -> Result<Vec<u8>, std::io::Error> {
202        let mut buffer = Vec::new();
203        let mut serializer = serde_json::Serializer::new(&mut buffer);
204        let mut map_serializer = serializer.serialize_map(None)?;
205        let message = format_span_context(span, ty);
206        self.serialize_bunyan_core_fields(&mut map_serializer, &message, span.metadata().level())?;
207        // Additional metadata useful for debugging
208        // They should be nested under `src` (see https://github.com/trentm/node-bunyan#src )
209        // but `tracing` does not support nested values yet
210        self.serialize_field(&mut map_serializer, "target", span.metadata().target())?;
211        self.serialize_field(&mut map_serializer, "line", &span.metadata().line())?;
212        self.serialize_field(&mut map_serializer, "file", &span.metadata().file())?;
213
214        // Add all default fields
215        for (key, value) in self.default_fields.iter() {
216            // Make sure this key isn't reserved. If it is reserved,
217            // silently ignore
218            if !BUNYAN_REQUIRED_FIELDS.contains(&key.as_str()) {
219                self.serialize_field(&mut map_serializer, key, value)?;
220            }
221        }
222
223        let extensions = span.extensions();
224        if let Some(visitor) = extensions.get::<JsonStorage>() {
225            for (key, value) in visitor.values() {
226                // Make sure this key isn't reserved. If it is reserved,
227                // silently ignore
228                if !BUNYAN_REQUIRED_FIELDS.contains(key) {
229                    self.serialize_field(&mut map_serializer, key, value)?;
230                }
231            }
232        }
233        map_serializer.end()?;
234        // We add a trailing new line.
235        buffer.write_all(b"\n")?;
236        Ok(buffer)
237    }
238
239    /// Given an in-memory buffer holding a complete serialised record, flush it to the writer
240    /// returned by self.make_writer.
241    ///
242    /// If we write directly to the writer returned by self.make_writer in more than one go
243    /// we can end up with broken/incoherent bits and pieces of those records when
244    /// running multi-threaded/concurrent programs.
245    fn emit(&self, buffer: &[u8], meta: &Metadata<'_>) -> Result<(), std::io::Error> {
246        self.make_writer.make_writer_for(meta).write_all(buffer)
247    }
248}
249
250/// The type of record we are dealing with: entering a span, exiting a span, an event.
251#[derive(Clone, Debug)]
252pub enum Type {
253    EnterSpan,
254    ExitSpan,
255    Event,
256}
257
258impl fmt::Display for Type {
259    fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
260        let repr = match self {
261            Type::EnterSpan => "START",
262            Type::ExitSpan => "END",
263            Type::Event => "EVENT",
264        };
265        write!(f, "{}", repr)
266    }
267}
268
269/// Ensure consistent formatting of the span context.
270///
271/// Example: "[AN_INTERESTING_SPAN - START]"
272fn format_span_context<S: Subscriber + for<'a> tracing_subscriber::registry::LookupSpan<'a>>(
273    span: &SpanRef<S>,
274    ty: Type,
275) -> String {
276    format!("[{} - {}]", span.metadata().name().to_uppercase(), ty)
277}
278
279/// Ensure consistent formatting of event message.
280///
281/// Examples:
282/// - "[AN_INTERESTING_SPAN - EVENT] My event message" (for an event with a parent span)
283/// - "My event message" (for an event without a parent span)
284fn format_event_message<S: Subscriber + for<'a> tracing_subscriber::registry::LookupSpan<'a>>(
285    current_span: &Option<SpanRef<S>>,
286    event: &Event,
287    event_visitor: &JsonStorage<'_>,
288) -> String {
289    // Extract the "message" field, if provided. Fallback to the target, if missing.
290    let mut message = event_visitor
291        .values()
292        .get("message")
293        .and_then(|v| match v {
294            Value::String(s) => Some(s.as_str()),
295            _ => None,
296        })
297        .unwrap_or_else(|| event.metadata().target())
298        .to_owned();
299
300    // If the event is in the context of a span, prepend the span name to the message.
301    if let Some(span) = &current_span {
302        message = format!("{} {}", format_span_context(span, Type::Event), message);
303    }
304
305    message
306}
307
308impl<S, W> Layer<S> for BunyanFormattingLayer<W>
309where
310    S: Subscriber + for<'a> tracing_subscriber::registry::LookupSpan<'a>,
311    W: for<'a> MakeWriter<'a> + 'static,
312{
313    fn on_event(&self, event: &Event<'_>, ctx: Context<'_, S>) {
314        // Events do not necessarily happen in the context of a span, hence lookup_current
315        // returns an `Option<SpanRef<_>>` instead of a `SpanRef<_>`.
316        let current_span = ctx.lookup_current();
317
318        let mut event_visitor = JsonStorage::default();
319        event.record(&mut event_visitor);
320
321        // Opting for a closure to use the ? operator and get more linear code.
322        let format = || {
323            let mut buffer = Vec::new();
324
325            let mut serializer = serde_json::Serializer::new(&mut buffer);
326            let mut map_serializer = serializer.serialize_map(None)?;
327
328            let message = format_event_message(&current_span, event, &event_visitor);
329            self.serialize_bunyan_core_fields(
330                &mut map_serializer,
331                &message,
332                event.metadata().level(),
333            )?;
334            // Additional metadata useful for debugging
335            // They should be nested under `src` (see https://github.com/trentm/node-bunyan#src )
336            // but `tracing` does not support nested values yet
337            self.serialize_field(&mut map_serializer, "target", event.metadata().target())?;
338            self.serialize_field(&mut map_serializer, "line", &event.metadata().line())?;
339            self.serialize_field(&mut map_serializer, "file", &event.metadata().file())?;
340
341            // Add all default fields
342            for (key, value) in self.default_fields.iter().filter(|(key, _)| {
343                key.as_str() != "message" && !BUNYAN_REQUIRED_FIELDS.contains(&key.as_str())
344            }) {
345                self.serialize_field(&mut map_serializer, key, value)?;
346            }
347
348            // Add all the other fields associated with the event, expect the message we already used.
349            for (key, value) in event_visitor
350                .values()
351                .iter()
352                .filter(|(&key, _)| key != "message" && !BUNYAN_REQUIRED_FIELDS.contains(&key))
353            {
354                self.serialize_field(&mut map_serializer, key, value)?;
355            }
356
357            // Add all the fields from the current span, if we have one.
358            if let Some(span) = &current_span {
359                let extensions = span.extensions();
360                if let Some(visitor) = extensions.get::<JsonStorage>() {
361                    for (key, value) in visitor.values() {
362                        // Make sure this key isn't reserved. If it is reserved,
363                        // silently ignore
364                        if !BUNYAN_REQUIRED_FIELDS.contains(key) {
365                            self.serialize_field(&mut map_serializer, key, value)?;
366                        }
367                    }
368                }
369            }
370            map_serializer.end()?;
371            // We add a trailing new line.
372            buffer.write_all(b"\n")?;
373
374            Ok(buffer)
375        };
376
377        let result: std::io::Result<Vec<u8>> = format();
378        if let Ok(formatted) = result {
379            let _ = self.emit(&formatted, event.metadata());
380        }
381    }
382
383    fn on_new_span(&self, _attrs: &Attributes, id: &Id, ctx: Context<'_, S>) {
384        let span = ctx.span(id).expect("Span not found, this is a bug");
385        if let Ok(serialized) = self.serialize_span(&span, Type::EnterSpan) {
386            let _ = self.emit(&serialized, span.metadata());
387        }
388    }
389
390    fn on_close(&self, id: Id, ctx: Context<'_, S>) {
391        let span = ctx.span(&id).expect("Span not found, this is a bug");
392        if let Ok(serialized) = self.serialize_span(&span, Type::ExitSpan) {
393            let _ = self.emit(&serialized, span.metadata());
394        }
395    }
396}
tracing_bunyan_formatter/formatting_layer.rs

tracing_bunyan_formatter/
formatting_layer.rs
