Print the span info on span exit and entry (#16)

Author: oli-obk

examples/basic.rs

@@ -8,6 +8,8 @@ fn main() {
         .with_indent_amount(2)
         .with_thread_names(true)
         .with_thread_ids(true)
+        .with_verbose_exit(true)
+        .with_verbose_entry(true)
         .with_targets(true);
 
     let subscriber = Registry::default().with(layer);

src/format.rs

@@ -8,9 +8,19 @@ use tracing::{
     Level,
 };
 
-const LINE_VERT: &str = "│";
+pub(crate) const LINE_VERT: &str = "│";
 const LINE_HORIZ: &str = "─";
-const LINE_BRANCH: &str = "├";
+pub(crate) const LINE_BRANCH: &str = "├";
+pub(crate) const LINE_CLOSE: &str = "┘";
+pub(crate) const LINE_OPEN: &str = "┐";
+
+pub(crate) enum SpanMode {
+    PreOpen,
+    Open,
+    Close,
+    PostClose,
+    Event,
+}
 
 #[derive(Debug)]
 pub struct Config {
@@ -28,6 +38,10 @@ pub struct Config {
     pub render_thread_names: bool,
     /// Specifies after how many indentation levels we will wrap back around to zero
     pub wraparound: usize,
+    /// Whether to print the current span before activating a new one
+    pub verbose_entry: bool,
+    /// Whether to print the current span before exiting it.
+    pub verbose_exit: bool,
 }
 
 impl Config {
@@ -64,6 +78,20 @@ impl Config {
         Self { wraparound, ..self }
     }
 
+    pub fn with_verbose_entry(self, verbose_entry: bool) -> Self {
+        Self {
+            verbose_entry,
+            ..self
+        }
+    }
+
+    pub fn with_verbose_exit(self, verbose_exit: bool) -> Self {
+        Self {
+            verbose_exit,
+            ..self
+        }
+    }
+
     pub(crate) fn prefix(&self) -> String {
         let mut buf = String::new();
         if self.render_thread_ids {
@@ -97,6 +125,8 @@ impl Default for Config {
             render_thread_ids: false,
             render_thread_names: false,
             wraparound: usize::max_value(),
+            verbose_entry: false,
+            verbose_exit: false,
         }
     }
 }
@@ -125,7 +155,7 @@ impl Buffers {
         self.indent_buf.clear();
     }
 
-    pub fn indent_current(&mut self, indent: usize, config: &Config) {
+    pub(crate) fn indent_current(&mut self, indent: usize, config: &Config, style: SpanMode) {
         self.current_buf.push('\n');
         indent_block(
             &mut self.current_buf,
@@ -134,6 +164,7 @@ impl Buffers {
             config.indent_amount,
             config.indent_lines,
             &config.prefix(),
+            style,
         );
         self.current_buf.clear();
         self.flush_indent_buf();
@@ -181,7 +212,15 @@ fn indent_block_with_lines(
     indent: usize,
     indent_amount: usize,
     prefix: &str,
+    style: SpanMode,
 ) {
+    let indent = match style {
+        SpanMode::PreOpen => indent - 1,
+        SpanMode::Open => indent - 1,
+        SpanMode::Close => indent,
+        SpanMode::PostClose => indent,
+        SpanMode::Event => indent,
+    };
     let indent_spaces = indent * indent_amount;
     if lines.is_empty() {
         return;
@@ -208,11 +247,68 @@ fn indent_block_with_lines(
 
     // draw branch
     buf.push_str(&s);
-    buf.push_str(LINE_BRANCH);
 
-    // add `indent_amount - 1` horizontal lines before the span/event
-    for _ in 0..(indent_amount - 1) {
-        buf.push_str(LINE_HORIZ);
+    match style {
+        SpanMode::PreOpen => {
+            buf.push_str(LINE_BRANCH);
+            for _ in 1..(indent_amount / 2) {
+                buf.push_str(LINE_HORIZ);
+            }
+            buf.push_str(LINE_OPEN);
+        }
+        SpanMode::Open => {
+            buf.push_str(LINE_VERT);
+            for _ in 1..(indent_amount / 2) {
+                buf.push(' ');
+            }
+            // We don't have the space for fancy rendering at single space indent.
+            if indent_amount > 1 {
+                buf.push('└');
+            }
+            for _ in (indent_amount / 2)..(indent_amount - 1) {
+                buf.push_str(LINE_HORIZ);
+            }
+            // We don't have the space for fancy rendering at single space indent.
+            if indent_amount > 1 {
+                buf.push_str(LINE_OPEN);
+            } else {
+                buf.push_str(LINE_VERT);
+            }
+        }
+        SpanMode::Close => {
+            buf.push_str(LINE_VERT);
+            for _ in 1..(indent_amount / 2) {
+                buf.push(' ');
+            }
+            // We don't have the space for fancy rendering at single space indent.
+            if indent_amount > 1 {
+                buf.push('┌');
+            }
+            for _ in (indent_amount / 2)..(indent_amount - 1) {
+                buf.push_str(LINE_HORIZ);
+            }
+            // We don't have the space for fancy rendering at single space indent.
+            if indent_amount > 1 {
+                buf.push_str(LINE_CLOSE);
+            } else {
+                buf.push_str(LINE_VERT);
+            }
+        }
+        SpanMode::PostClose => {
+            buf.push_str(LINE_BRANCH);
+            for _ in 1..(indent_amount / 2) {
+                buf.push_str(LINE_HORIZ);
+            }
+            buf.push_str(LINE_CLOSE);
+        }
+        SpanMode::Event => {
+            buf.push_str(LINE_BRANCH);
+
+            // add `indent_amount - 1` horizontal lines before the span/event
+            for _ in 0..(indent_amount - 1) {
+                buf.push_str(LINE_HORIZ);
+            }
+        }
     }
     buf.push_str(&lines[0]);
     buf.push('\n');
@@ -242,12 +338,13 @@ fn indent_block(
     indent_amount: usize,
     indent_lines: bool,
     prefix: &str,
+    style: SpanMode,
 ) {
     let lines: Vec<&str> = block.lines().collect();
     let indent_spaces = indent * indent_amount;
     buf.reserve(block.len() + (lines.len() * indent_spaces));
     if indent_lines {
-        indent_block_with_lines(&lines, buf, indent, indent_amount, prefix);
+        indent_block_with_lines(&lines, buf, indent, indent_amount, prefix, style);
     } else {
         let indent_str = String::from(" ").repeat(indent_spaces);
         for line in lines {

src/lib.rs

@@ -2,7 +2,7 @@ pub(crate) mod format;
 
 use ansi_term::{Color, Style};
 use chrono::{DateTime, Local};
-use format::{Buffers, ColorLevel, Config, FmtEvent};
+use format::{Buffers, ColorLevel, Config, FmtEvent, SpanMode};
 use std::{
     fmt::{self, Write as _},
     io,
@@ -149,6 +149,26 @@ where
         }
     }
 
+    /// Whether to print the currently active span's message again before entering a new span.
+    /// This helps if the entry to the current span was quite a while back (and with scrolling
+    /// upwards in logs).
+    pub fn with_verbose_entry(self, verbose_entry: bool) -> Self {
+        Self {
+            config: self.config.with_verbose_entry(verbose_entry),
+            ..self
+        }
+    }
+
+    /// Whether to print the currently active span's message again before dropping it.
+    /// This helps if the entry to the current span was quite a while back (and with scrolling
+    /// upwards in logs).
+    pub fn with_verbose_exit(self, verbose_exit: bool) -> Self {
+        Self {
+            config: self.config.with_verbose_exit(verbose_exit),
+            ..self
+        }
+    }
+
     fn styled(&self, style: Style, text: impl AsRef<str>) -> String {
         if self.config.ansi {
             style.paint(text.as_ref()).to_string()
@@ -177,29 +197,30 @@ where
         }
         Ok(())
     }
-}
 
-impl<S, W> Layer<S> for HierarchicalLayer<W>
-where
-    S: Subscriber + for<'span> LookupSpan<'span> + fmt::Debug,
-    W: MakeWriter + 'static,
-{
-    fn new_span(&self, attrs: &Attributes, id: &Id, ctx: Context<S>) {
-        let data = Data::new(attrs);
-        let span = ctx.span(id).expect("in new_span but span does not exist");
-        span.extensions_mut().insert(data);
-    }
-
-    fn on_enter(&self, id: &tracing::Id, ctx: Context<S>) {
-        let span = ctx.span(&id).expect("in on_enter but span does not exist");
+    fn write_span_info<S: Subscriber + for<'span> LookupSpan<'span> + fmt::Debug>(
+        &self,
+        id: &tracing::Id,
+        ctx: &Context<S>,
+        entering: bool,
+        style: SpanMode,
+    ) {
+        let span = ctx
+            .span(&id)
+            .expect("in on_enter/on_exit but span does not exist");
         let ext = span.extensions();
         let data = ext.get::<Data>().expect("span does not have data");
 
         let mut guard = self.bufs.lock().unwrap();
         let bufs = &mut *guard;
         let mut current_buf = &mut bufs.current_buf;
 
-        let indent = ctx.scope().count().saturating_sub(1);
+        let indent = ctx.scope().count();
+        let indent = if entering {
+            indent.saturating_sub(1)
+        } else {
+            indent
+        };
 
         if self.config.targets {
             let target = span.metadata().target();
@@ -232,10 +253,47 @@ where
         )
         .unwrap();
 
-        bufs.indent_current(indent, &self.config);
+        bufs.indent_current(indent, &self.config, style);
         let writer = self.make_writer.make_writer();
         bufs.flush_current_buf(writer)
     }
+}
+
+impl<S, W> Layer<S> for HierarchicalLayer<W>
+where
+    S: Subscriber + for<'span> LookupSpan<'span> + fmt::Debug,
+    W: MakeWriter + 'static,
+{
+    fn new_span(&self, attrs: &Attributes, id: &Id, ctx: Context<S>) {
+        let data = Data::new(attrs);
+        let span = ctx.span(id).expect("in new_span but span does not exist");
+        span.extensions_mut().insert(data);
+    }
+
+    fn on_enter(&self, id: &tracing::Id, ctx: Context<S>) {
+        let mut iter = ctx.scope();
+        let mut prev = iter.next();
+        let mut cur = iter.next();
+        loop {
+            match (prev, cur) {
+                (Some(span), Some(cur_elem)) => {
+                    if let Some(next) = iter.next() {
+                        prev = Some(cur_elem);
+                        cur = Some(next);
+                    } else {
+                        self.write_span_info(&span.id(), &ctx, false, SpanMode::PreOpen);
+                        break;
+                    }
+                }
+                // Iterator is not sealed, so we need to catch this case.
+                (None, Some(_)) => break,
+                // Just the new span on the stack
+                (Some(_), None) => break,
+                (None, None) => unreachable!("just entered span must exist"),
+            }
+        }
+        self.write_span_info(id, &ctx, false, SpanMode::Open);
+    }
 
     fn on_event(&self, event: &Event<'_>, ctx: Context<S>) {
         let mut guard = self.bufs.lock().unwrap();
@@ -303,10 +361,19 @@ where
             bufs: &mut bufs,
         };
         event.record(&mut visitor);
-        visitor.bufs.indent_current(indent, &self.config);
+        visitor
+            .bufs
+            .indent_current(indent, &self.config, SpanMode::Event);
         let writer = self.make_writer.make_writer();
         bufs.flush_current_buf(writer)
     }
 
-    fn on_exit(&self, _id: &Id, _ctx: Context<S>) {}
+    fn on_exit(&self, id: &Id, ctx: Context<S>) {
+        if self.config.verbose_exit {
+            self.write_span_info(id, &ctx, false, SpanMode::Close);
+            if let Some(span) = ctx.scope().last() {
+                self.write_span_info(&span.id(), &ctx, false, SpanMode::PostClose);
+            }
+        }
+    }
 }