subscriber: allow thread name and ID to be displayed in traces (#818)

## Motivation

Fixes #809 

## Solution

This PR adds two new methods i.e `with_thread_ids` and
`with_thread_names` to the fmt Layer which passed till
the pre-configured Format type, where the check is performed
and these the above values are formatted based on the flags.

The formatting is done by creating to new Types that impl Display
for Id and Name. For Thread Name, we keep track of the max length
of the thread name that occured till now using a thread safe static
type and pad accordingly. For Thread Id, we pad directly with 2
as in most cases we would see a double digit number of threads.

Signed-off-by: Tarun Pothulapati <[email protected]>

Author: Pothulapati

examples/examples/thread-info.rs

@@ -0,0 +1,55 @@
+#![deny(rust_2018_idioms)]
+/// This is a example showing how thread info can be displayed when
+/// formatting events with `tracing_subscriber::fmt`. This is useful
+/// as `tracing` spans can be entered by multicple threads concurrently,
+/// or move across threads freely.
+///
+/// You can run this example by running the following command in a terminal
+///
+/// ```
+/// cargo run --example thread-info
+/// ```
+///
+/// Example output:
+///
+/// ```not_rust
+/// Jul 17 00:38:07.177  INFO ThreadId(02) thread_info: i=9
+/// Jul 17 00:38:07.177  INFO            thread 1 ThreadId(03) thread_info: i=9
+/// Jul 17 00:38:07.177  INFO large name thread 2 ThreadId(04) thread_info: i=9
+/// ```
+use std::thread;
+use std::time::Duration;
+use tracing::info;
+
+fn main() {
+    tracing_subscriber::fmt()
+        .with_max_level(tracing::Level::DEBUG)
+        // enable thread id to be emitted
+        .with_thread_ids(true)
+        // enabled thread name to be emitted
+        .with_thread_names(true)
+        .init();
+
+    let do_work = || {
+        for i in 1..10 {
+            info!(i);
+            thread::sleep(Duration::from_millis(1));
+        }
+    };
+
+    let thread_with_no_name = thread::spawn(do_work);
+    let thread_one = thread::Builder::new()
+        .name("thread 1".to_string())
+        .spawn(do_work)
+        .expect("could not spawn a new thread");
+    let thread_two = thread::Builder::new()
+        .name("large name thread 2".to_string())
+        .spawn(do_work)
+        .expect("could not spawn a new thread");
+
+    thread_with_no_name
+        .join()
+        .expect("could not wait for a thread");
+    thread_one.join().expect("could not wait for a thread");
+    thread_two.join().expect("could not wait for a thread");
+}

tracing-subscriber/src/fmt/fmt_layer.rs

@@ -290,6 +290,37 @@ where
         }
     }
 
+    /// Sets whether or not the [thread ID] of the current thread is displayed
+    /// when formatting events
+    ///
+    /// [thread ID]: https://doc.rust-lang.org/stable/std/thread/struct.ThreadId.html
+    pub fn with_thread_ids(self, display_thread_ids: bool) -> Layer<S, N, format::Format<L, T>, W> {
+        Layer {
+            fmt_event: self.fmt_event.with_thread_ids(display_thread_ids),
+            fmt_fields: self.fmt_fields,
+            fmt_span: self.fmt_span,
+            make_writer: self.make_writer,
+            _inner: self._inner,
+        }
+    }
+
+    /// Sets whether or not the [name] of the current thread is displayed
+    /// when formatting events
+    ///
+    /// [name]: https://doc.rust-lang.org/stable/std/thread/index.html#naming-threads
+    pub fn with_thread_names(
+        self,
+        display_thread_names: bool,
+    ) -> Layer<S, N, format::Format<L, T>, W> {
+        Layer {
+            fmt_event: self.fmt_event.with_thread_names(display_thread_names),
+            fmt_fields: self.fmt_fields,
+            fmt_span: self.fmt_span,
+            make_writer: self.make_writer,
+            _inner: self._inner,
+        }
+    }
+
     /// Sets the layer being built to use a [less verbose formatter](../fmt/format/struct.Compact.html).
     pub fn compact(self) -> Layer<S, N, format::Format<format::Compact, T>, W>
     where

tracing-subscriber/src/fmt/format/json.rs

@@ -236,6 +236,26 @@ where
                 serializer.serialize_entry("target", meta.target())?;
             }
 
+            if self.display_thread_name {
+                let current_thread = std::thread::current();
+                match current_thread.name() {
+                    Some(name) => {
+                        serializer.serialize_entry("threadName", name)?;
+                    }
+                    // fall-back to thread id when name is absent and ids are not enabled
+                    None if !self.display_thread_id => {
+                        serializer
+                            .serialize_entry("threadName", &format!("{:?}", current_thread.id()))?;
+                    }
+                    _ => {}
+                }
+            }
+
+            if self.display_thread_id {
+                serializer
+                    .serialize_entry("threadId", &format!("{:?}", std::thread::current().id()))?;
+            }
+
             if !self.format.flatten_event {
                 use tracing_serde::fields::AsMap;
                 serializer.serialize_entry("fields", &event.field_map())?;

tracing-subscriber/src/fmt/format/mod.rs

@@ -179,6 +179,8 @@ pub struct Format<F = Full, T = SystemTime> {
     pub(crate) ansi: bool,
     pub(crate) display_target: bool,
     pub(crate) display_level: bool,
+    pub(crate) display_thread_id: bool,
+    pub(crate) display_thread_name: bool,
 }
 
 impl Default for Format<Full, SystemTime> {
@@ -189,6 +191,8 @@ impl Default for Format<Full, SystemTime> {
             ansi: true,
             display_target: true,
             display_level: true,
+            display_thread_id: false,
+            display_thread_name: false,
         }
     }
 }
@@ -204,6 +208,8 @@ impl<F, T> Format<F, T> {
             ansi: self.ansi,
             display_target: self.display_target,
             display_level: self.display_level,
+            display_thread_id: self.display_thread_id,
+            display_thread_name: self.display_thread_name,
         }
     }
 
@@ -232,6 +238,8 @@ impl<F, T> Format<F, T> {
             ansi: self.ansi,
             display_target: self.display_target,
             display_level: self.display_level,
+            display_thread_id: self.display_thread_id,
+            display_thread_name: self.display_thread_name,
         }
     }
 
@@ -253,6 +261,8 @@ impl<F, T> Format<F, T> {
             ansi: self.ansi,
             display_target: self.display_target,
             display_level: self.display_level,
+            display_thread_id: self.display_thread_id,
+            display_thread_name: self.display_thread_name,
         }
     }
 
@@ -264,6 +274,8 @@ impl<F, T> Format<F, T> {
             ansi: self.ansi,
             display_target: self.display_target,
             display_level: self.display_level,
+            display_thread_id: self.display_thread_id,
+            display_thread_name: self.display_thread_name,
         }
     }
 
@@ -287,6 +299,28 @@ impl<F, T> Format<F, T> {
             ..self
         }
     }
+
+    /// Sets whether or not the [thread ID] of the current thread is displayed
+    /// when formatting events
+    ///
+    /// [thread ID]: https://doc.rust-lang.org/stable/std/thread/struct.ThreadId.html
+    pub fn with_thread_ids(self, display_thread_id: bool) -> Format<F, T> {
+        Format {
+            display_thread_id,
+            ..self
+        }
+    }
+
+    /// Sets whether or not the [name] of the current thread is displayed
+    /// when formatting events
+    ///
+    /// [name]: https://doc.rust-lang.org/stable/std/thread/index.html#naming-threads
+    pub fn with_thread_names(self, display_thread_name: bool) -> Format<F, T> {
+        Format {
+            display_thread_name,
+            ..self
+        }
+    }
 }
 
 #[cfg(feature = "json")]
@@ -367,6 +401,24 @@ where
             write!(writer, "{} ", fmt_level)?;
         }
 
+        if self.display_thread_name {
+            let current_thread = std::thread::current();
+            match current_thread.name() {
+                Some(name) => {
+                    write!(writer, "{} ", FmtThreadName::new(name))?;
+                }
+                // fall-back to thread id when name is absent and ids are not enabled
+                None if !self.display_thread_id => {
+                    write!(writer, "{:0>2?} ", current_thread.id())?;
+                }
+                _ => {}
+            }
+        }
+
+        if self.display_thread_id {
+            write!(writer, "{:0>2?} ", std::thread::current().id())?;
+        }
+
         let full_ctx = {
             #[cfg(feature = "ansi")]
             {
@@ -424,6 +476,24 @@ where
             write!(writer, "{} ", fmt_level)?;
         }
 
+        if self.display_thread_name {
+            let current_thread = std::thread::current();
+            match current_thread.name() {
+                Some(name) => {
+                    write!(writer, "{} ", FmtThreadName::new(name))?;
+                }
+                // fall-back to thread id when name is absent and ids are not enabled
+                None if !self.display_thread_id => {
+                    write!(writer, "{:0>2?} ", current_thread.id())?;
+                }
+                _ => {}
+            }
+        }
+
+        if self.display_thread_id {
+            write!(writer, "{:0>2?} ", std::thread::current().id())?;
+        }
+
         let fmt_ctx = {
             #[cfg(feature = "ansi")]
             {
@@ -761,6 +831,49 @@ impl Style {
     }
 }
 
+struct FmtThreadName<'a> {
+    name: &'a str,
+}
+
+impl<'a> FmtThreadName<'a> {
+    pub(crate) fn new(name: &'a str) -> Self {
+        Self { name }
+    }
+}
+
+impl<'a> fmt::Display for FmtThreadName<'a> {
+    fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
+        use std::sync::atomic::{
+            AtomicUsize,
+            Ordering::{AcqRel, Acquire, Relaxed},
+        };
+
+        // Track the longest thread name length we've seen so far in an atomic,
+        // so that it can be updated by any thread.
+        static MAX_LEN: AtomicUsize = AtomicUsize::new(0);
+        let len = self.name.len();
+        // Snapshot the current max thread name length.
+        let mut max_len = MAX_LEN.load(Relaxed);
+
+        while len > max_len {
+            // Try to set a new max length, if it is still the value we took a
+            // snapshot of.
+            match MAX_LEN.compare_exchange(max_len, len, AcqRel, Acquire) {
+                // We successfully set the new max value
+                Ok(_) => break,
+                // Another thread set a new max value since we last observed
+                // it! It's possible that the new length is actually longer than
+                // ours, so we'll loop again and check whether our length is
+                // still the longest. If not, we'll just use the newer value.
+                Err(actual) => max_len = actual,
+            }
+        }
+
+        // pad thread name using `max_len`
+        write!(f, "{:>width$}", self.name, width = max_len)
+    }
+}
+
 struct FmtLevel<'a> {
     level: &'a Level,
     #[cfg(feature = "ansi")]

tracing-subscriber/src/fmt/mod.rs

@@ -542,6 +542,34 @@ where
         }
     }
 
+    /// Sets whether or not the [name] of the current thread is displayed
+    /// when formatting events
+    ///
+    /// [name]: https://doc.rust-lang.org/stable/std/thread/index.html#naming-threads
+    pub fn with_thread_names(
+        self,
+        display_thread_names: bool,
+    ) -> SubscriberBuilder<N, format::Format<L, T>, F, W> {
+        SubscriberBuilder {
+            filter: self.filter,
+            inner: self.inner.with_thread_names(display_thread_names),
+        }
+    }
+
+    /// Sets whether or not the [thread ID] of the current thread is displayed
+    /// when formatting events
+    ///
+    /// [thread ID]: https://doc.rust-lang.org/stable/std/thread/struct.ThreadId.html
+    pub fn with_thread_ids(
+        self,
+        display_thread_ids: bool,
+    ) -> SubscriberBuilder<N, format::Format<L, T>, F, W> {
+        SubscriberBuilder {
+            filter: self.filter,
+            inner: self.inner.with_thread_ids(display_thread_ids),
+        }
+    }
+
     /// Sets the subscriber being built to use a less verbose formatter.
     ///
     /// See [`format::Compact`](../fmt/format/struct.Compact.html).