Skip to content

Commit

Permalink
subscriber: fix double space before thread ID with pretty formatter (#…
Browse files Browse the repository at this point in the history
…1778)

Before this PR there was one two many spaces between "on" and "ThreadId"
when thread id formatting is enabled but thread name formatting is
disabled. There was no issue when both thread name and thread id were
enabled.

Previous output:
```
  2021-12-15T00:44:05.596510Z ERROR shotover_proxy::transforms::redis::cache: failed to fetch from cache: system.local not a caching table
    at shotover-proxy/src/transforms/redis/cache.rs:366 on  ThreadId(5)
    in shotover_proxy::server::request with id=5 source="CassandraSource"
```

new output:
```
  2021-12-15T00:44:05.596510Z ERROR shotover_proxy::transforms::redis::cache: failed to fetch from cache: system.local not a caching table
    at shotover-proxy/src/transforms/redis/cache.rs:366 on ThreadId(5)
    in shotover_proxy::server::request with id=5 source="CassandraSource"
```

I spent a lot of time working on unittests, I managed to add tests for a
lot of related cases but couldnt test the actual case here :/ When I
write a test like:
```rust
    #[test]
    fn pretty_threads_ids() {
        let make_writer = MockMakeWriter::default();
        let subscriber = crate::fmt::Collector::builder()
            .pretty()
            .with_thread_ids(true)
            .with_writer(make_writer.clone())
            .with_ansi(false)
            .with_timer(MockTime);
        assert_info_hello_ignore_numeric(
            subscriber,
            make_writer,
            r#"  fake time  INFO tracing_subscriber::fmt::format::test: hello
    at tracing-subscriber/src/fmt/format/mod.rs:

"#,
        )
    }
```
Inexplicably the thread id is not displayed.

Hopefully you can accept the tests I did write as a compromise, the
actual fix here is really simple.
  • Loading branch information
rukai authored and hawkw committed Dec 23, 2021
1 parent 19b7b1b commit 8294572
Show file tree
Hide file tree
Showing 2 changed files with 67 additions and 6 deletions.
64 changes: 63 additions & 1 deletion tracing-subscriber/src/fmt/format/mod.rs
Original file line number Diff line number Diff line change
Expand Up @@ -1542,6 +1542,8 @@ pub(super) mod test {
use super::*;
use std::fmt;

use regex::Regex;

pub(crate) struct MockTime;
impl FormatTime for MockTime {
fn format_time(&self, w: &mut Writer<'_>) -> fmt::Result {
Expand All @@ -1562,7 +1564,7 @@ pub(super) mod test {
.with_thread_names(false);
#[cfg(feature = "ansi")]
let subscriber = subscriber.with_ansi(false);
run_test(subscriber, make_writer, "hello\n")
assert_info_hello(subscriber, make_writer, "hello\n")
}

fn test_ansi<T>(
Expand Down Expand Up @@ -1610,6 +1612,31 @@ pub(super) mod test {
run_test(subscriber, make_writer, expected);
}

fn assert_info_hello(subscriber: impl Into<Dispatch>, buf: MockMakeWriter, expected: &str) {
let _default = set_default(&subscriber.into());
tracing::info!("hello");
let result = buf.get_string();

assert_eq!(expected, result)
}

// When numeric characters are used they often form a non-deterministic value as they usually represent things like a thread id or line number.
// This assert method should be used when non-deterministic numeric characters are present.
fn assert_info_hello_ignore_numeric(
subscriber: impl Into<Dispatch>,
buf: MockMakeWriter,
expected: &str,
) {
let _default = set_default(&subscriber.into());
tracing::info!("hello");

let regex = Regex::new("[0-9]+").unwrap();
let result = buf.get_string();
let result_cleaned = regex.replace_all(&result, "NUMERIC");

assert_eq!(expected, result_cleaned)
}

fn test_overridden_parents<T>(
expected: &str,
builder: crate::fmt::SubscriberBuilder<DefaultFields, Format<T>>,
Expand Down Expand Up @@ -1671,6 +1698,21 @@ pub(super) mod test {

mod default {
use super::*;

#[test]
fn with_thread_ids() {
let make_writer = MockMakeWriter::default();
let subscriber = crate::fmt::Subscriber::builder()
.with_writer(make_writer.clone())
.with_thread_ids(true)
.with_ansi(false)
.with_timer(MockTime);
let expected =
"fake time INFO ThreadId(NUMERIC) tracing_subscriber::fmt::format::test: hello\n";

assert_info_hello_ignore_numeric(subscriber, make_writer, expected);
}

#[cfg(feature = "ansi")]
#[test]
fn with_ansi_true() {
Expand Down Expand Up @@ -1760,6 +1802,26 @@ pub(super) mod test {
}
}

mod pretty {
use super::*;

#[test]
fn pretty_default() {
let make_writer = MockMakeWriter::default();
let subscriber = crate::fmt::Subscriber::builder()
.pretty()
.with_writer(make_writer.clone())
.with_ansi(false)
.with_timer(MockTime);
let expected = format!(
" fake time INFO tracing_subscriber::fmt::format::test: hello\n at {}:NUMERIC\n\n",
file!()
);

assert_info_hello_ignore_numeric(subscriber, make_writer, &expected)
}
}

#[test]
fn format_nanos() {
fn fmt(t: u64) -> String {
Expand Down
9 changes: 4 additions & 5 deletions tracing-subscriber/src/fmt/format/pretty.rs
Original file line number Diff line number Diff line change
Expand Up @@ -186,13 +186,12 @@ where
if let Some(name) = thread.name() {
write!(writer, "{}", name)?;
if self.display_thread_id {
write!(writer, " ({:?})", thread.id())?;
writer.write_char(' ')?;
}
} else if !self.display_thread_id {
write!(writer, " {:?}", thread.id())?;
}
} else if self.display_thread_id {
write!(writer, " {:?}", thread.id())?;
}
if self.display_thread_id {
write!(writer, "{:?}", thread.id())?;
}
writer.write_char('\n')?;
}
Expand Down

0 comments on commit 8294572

Please sign in to comment.