Feature: Options to log line number and filename on tracing-subscriber #1773

renecouto · 2021-12-09T22:41:55Z

Motivation

Logging line numbers and file names can ease debugging. This feature was suggested by #1326

Solution

As per @hawkw 's suggestions, fields were added on Format, along with builder methods. filename and line number information was gathered from the meta variable.

…pretty formating

hawkw

overall, this looks like a good start. however, i noticed the tests here don't pass on Windows, as the Windows CI build is failing. we'll want to fix that.

hawkw · 2021-12-09T23:06:47Z

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

+            .with_ansi(false)
+            .with_timer(MockTime);
+
+        let expected = Regex::new("^fake time tracing_subscriber::fmt::format::test: tracing-subscriber/src/fmt/format/mod.rs: [0-9]+: hello\n$").unwrap();


it looks like these tests fail on Windows, because Windows formats paths using \ rather than /. see the CI failure: https://github.com/tokio-rs/tracing/runs/4477194846?check_suite_focus=true

perhaps what we should do instead is build the regex using the actual path to this file, rather than hard-coding it. that way, these tests would pass regardless of the operating system's path separator character. also, we wouldn't have to update it if we moved the test into a different file. we could write something like this:

Suggested change

let expected = Regex::new("^fake time tracing_subscriber::fmt::format::test: tracing-subscriber/src/fmt/format/mod.rs: [0-9]+: hello\n$").unwrap();

let expected = Regex::new(concat!(

"^fake time ",

module_path!(),

" :",

file!(),

": [0-9]+: hello\n$"

)).unwrap();

actually, hmm, this won't quite work, since we'd also need to escape any backslash characters in the path on windows, but we could do that by using format! rather than concat!, and using str::replace to replace any \s in the file path with \\

hawkw · 2021-12-09T23:08:55Z

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

@@ -679,6 +693,24 @@ impl<F, T> Format<F, T> {
        }
    }

+    /// Sets whether or not the [filename] of the tracing logs source code is displayed


this looks like it's supposed to be a link, but it doesn't link to anything?

hawkw · 2021-12-09T23:09:22Z

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

+        }
+    }
+
+    /// Sets whether or not the [line_number] of the tracing logs is source codedisplayed


similarly, this looks like it's supposed to be a link to something?

hawkw · 2021-12-09T23:19:00Z

...oh, I see that you also fixed the Windows path separator issue while i was writing the review, thanks!

hawkw · 2021-12-23T20:29:58Z

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

+        if let Some(line_number) = line_number {
+            write!(
+                writer,
+                "{}{} ",
+                dimmed.paint(line_number.to_string()),
+                dimmed.paint(":")
+            )?;
+        }


As I mentioned here, I'm still unconvinced that we should display line numbers if both targets and file names are disabled...a line number like ':156' doesn't make a lot of sense if we don't know what file or module it's in. But, trying to handle that case nicely will complicate the implementation significantly.

@davidbarsky what do you think? Is it worthwhile to make sure we do the "right thing" if a user calls with_line_number(true) but never enables file names? What if they've also called .with_target(false)?

@davidbarsky what do you think? Is it worthwhile to make sure we do the "right thing" if a user calls .with_line_number(true) but never enables file names?

Just saw this. While I think that it's worth doing the right thing, I'd like to consider redesigning the configuration interface of fmt holistically. To that end, I'd rather accept this PR-as-is designed, and fix it later.

At the very least, the lone line number will confusing, but it won't cause runtime panics like other misconfigurations can.

To be clear, I'm not entirely sure what the holistic redesign should look like, but naively, I might want to try bundling lines and file formatting information into a single struct where a missing target/file is very obvious to the end user.

hawkw · 2021-12-23T20:35:41Z

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

+            write!(
+                writer,
+                "{}{} ",
+                dimmed.paint(line_number.to_string()),
+                dimmed.paint(":")
+            )?;


I don't think we should be calling to_string here; that will allocate a new String, which could have a performance impact that it would be nice to avoid. Nothing else in the formatting code currently allocates strings, so I'd really like to avoid this.

I think the to_string() call here is necessary to use Style::paint, which takes a Cow<'a, str> rather than a fmt::Debug implementation? We can avoid this by using ansi_term's prefix and suffix methods, changing this code to something like this:

Suggested change

write!(

writer,

"{}{} ",

dimmed.paint(line_number.to_string()),

dimmed.paint(":")

)?;

write!(

writer,

"{}{}:{} ",

dimmed.prefix(),

line_number,

dimmed.suffix(),

)?;

If we do that, we'll also need to add prefix() and suffix() methods to the no-op version of Style that's used when ANSI support is disabled, here:

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

Lines 1190 to 1198 in 989e07f

#[cfg(not(feature = "ansi"))]

impl Style {

fn new() -> Self {

Style

}

fn paint(&self, d: impl fmt::Display) -> impl fmt::Display {

d

}

}

This would look something like the following:

#[cfg(not(feature = "ansi"))] impl Style { // ... fn prefix(&self) -> &'static str { "" } fn suffix(&self) -> &'static str { "" } }

hawkw · 2021-12-23T20:36:04Z

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

+                write!(
+                    writer,
+                    "{}{}",
+                    writer.bold().paint(line_number.to_string()),


as i mentioned above, i think the use of to_string should be avoided here.

hawkw · 2021-12-28T18:39:48Z

ping @renecouto, I'd really like to get this PR merged. I think https://github.com/tokio-rs/tracing/pull/1773/files#r774769644 is the last blocking issue we need to address before this is ready to merge.

Do you have the time to continue working on this? If not, I'd be happy to make those changes to your branch so that we can get this released.

hawkw · 2022-01-11T19:06:15Z

another quick ping on this — @renecouto, are you still planning to work on this? otherwise, i'm happy to wrap it up so we can merge it.

thanks again!

Signed-off-by: Eliza Weisman <eliza@buoyant.io>

hawkw · 2022-01-13T19:44:35Z

okay, i went ahead and made the remaining required changes for this, I'll go ahead and merge it pending CI

@hawkw

## Motivation Logging line numbers and file names can be useful for debugging. This feature was suggested by #1326 ## Solution As per @hawkw's suggestions, fields were added on `Format`, along with builder methods. Filename and line number information was gathered from the `meta` variable. The `Pretty` formatter already supports printing source locations, but this is configured separately on the `Pretty` formatter rather than on the `Format` type. This branch also changes `Pretty` to honor the `Format`-level configurations and deprecates the `Pretty`-specific method. Fixes #1326 Closes #1804 Co-authored-by: David Barsky <me@davidbarsky.com> Co-authored-by: Eliza Weisman <eliza@buoyant.io>

@hawkw

## Motivation Logging line numbers and file names can be useful for debugging. This feature was suggested by #1326 ## Solution As per @hawkw's suggestions, fields were added on `Format`, along with builder methods. Filename and line number information was gathered from the `meta` variable. The `Pretty` formatter already supports printing source locations, but this is configured separately on the `Pretty` formatter rather than on the `Format` type. This branch also changes `Pretty` to honor the `Format`-level configurations and deprecates the `Pretty`-specific method. Fixes #1326 Closes #1804 Co-authored-by: David Barsky <me@davidbarsky.com> Co-authored-by: Eliza Weisman <eliza@buoyant.io>

@renecouto

# 0.3.6 (Jan 14, 2022) This release adds configuration options to `tracing_subscriber::fmt` to log source code locations for events. ### Added - **fmt**: Added `with_file` and `with_line_number` configuration methods to `fmt::Format`, `fmt::SubscriberBuilder`, and `fmt::Layer` ([#1773]) ### Fixed - **fmt**: Removed incorrect leading comma from span fields with the `Pretty` formatter ([#1833]) ### Deprecated - **fmt**: Deprecated `Pretty::with_source_location`, as it can now be replaced by the more general `Format`, `SubscriberBuilder`, and `Layer` methods ([#1773]) Thanks to new contributor @renecouto for contributing to this release! [#1773]: #1773 [#1833]: #1833

@renecouto

# 0.3.6 (Jan 14, 2022) This release adds configuration options to `tracing_subscriber::fmt` to log source code locations for events. ### Added - **fmt**: Added `with_file` and `with_line_number` configuration methods to `fmt::Format`, `fmt::SubscriberBuilder`, and `fmt::Layer` ([#1773]) ### Fixed - **fmt**: Removed incorrect leading comma from span fields with the `Pretty` formatter ([#1833]) ### Deprecated - **fmt**: Deprecated `Pretty::with_source_location`, as it can now be replaced by the more general `Format`, `SubscriberBuilder`, and `Layer` methods ([#1773]) Thanks to new contributor @renecouto for contributing to this release! [#1773]: #1773 [#1833]: #1833

This was just added to tracing (tokio-rs/tracing#1773) and the wrapper can be updated to leverage the same.

@hawkw

…1773) ## Motivation Logging line numbers and file names can be useful for debugging. This feature was suggested by tokio-rs#1326 ## Solution As per @hawkw's suggestions, fields were added on `Format`, along with builder methods. Filename and line number information was gathered from the `meta` variable. The `Pretty` formatter already supports printing source locations, but this is configured separately on the `Pretty` formatter rather than on the `Format` type. This branch also changes `Pretty` to honor the `Format`-level configurations and deprecates the `Pretty`-specific method. Fixes tokio-rs#1326 Closes tokio-rs#1804 Co-authored-by: David Barsky <me@davidbarsky.com> Co-authored-by: Eliza Weisman <eliza@buoyant.io>

@renecouto

# 0.3.6 (Jan 14, 2022) This release adds configuration options to `tracing_subscriber::fmt` to log source code locations for events. ### Added - **fmt**: Added `with_file` and `with_line_number` configuration methods to `fmt::Format`, `fmt::SubscriberBuilder`, and `fmt::Layer` ([tokio-rs#1773]) ### Fixed - **fmt**: Removed incorrect leading comma from span fields with the `Pretty` formatter ([tokio-rs#1833]) ### Deprecated - **fmt**: Deprecated `Pretty::with_source_location`, as it can now be replaced by the more general `Format`, `SubscriberBuilder`, and `Layer` methods ([tokio-rs#1773]) Thanks to new contributor @renecouto for contributing to this release! [tokio-rs#1773]: tokio-rs#1773 [tokio-rs#1833]: tokio-rs#1833

renecouto added 4 commits December 6, 2021 23:19

debugging

91b860e

more debugging

ddf4f0c

Added tests for json, implemented filename and line_numbe logging on …

2c95286

…pretty formating

Fixed docs and added filename logging to compact logging

c3b8c72

renecouto requested review from davidbarsky, hawkw and a team as code owners December 9, 2021 22:41

made tests windows-compatible

7afbe52

hawkw reviewed Dec 9, 2021

View reviewed changes

Merge branch 'master' into feature/log-line-number-and-filename

989e07f

hawkw requested changes Dec 23, 2021

View reviewed changes

Merge branch 'master' into feature/log-line-number-and-filename

4a8f07a

hawkw mentioned this pull request Dec 28, 2021

Add feature to print line number #1804

Closed

Merge branch 'master' into feature/log-line-number-and-filename

317ee10

hawkw added 11 commits January 12, 2022 10:27

fixup tests

662bdee

Signed-off-by: Eliza Weisman <eliza@buoyant.io>

remove unneeded allocations

6a6ff49

Signed-off-by: Eliza Weisman <eliza@buoyant.io>

API polish

7e6a77c

Signed-off-by: Eliza Weisman <eliza@buoyant.io>

add an example

c2a2f04

Signed-off-by: Eliza Weisman <eliza@buoyant.io>

Merge branch 'master' into feature/log-line-number-and-filename

a2bb9f3

add doc to comment

f37d5e1

Signed-off-by: Eliza Weisman <eliza@buoyant.io>

make pretty formatter play nicely with configs

333991b

Signed-off-by: Eliza Weisman <eliza@buoyant.io>

fix docs

333e8ed

Signed-off-by: Eliza Weisman <eliza@buoyant.io>

fix tests on Windows

3791f7a

Signed-off-by: Eliza Weisman <eliza@buoyant.io>

oh, it's only SOMETIMES used in a regex, lol

6535633

Signed-off-by: Eliza Weisman <eliza@buoyant.io>

fix json test on windows

218afdd

Signed-off-by: Eliza Weisman <eliza@buoyant.io>

hawkw force-pushed the feature/log-line-number-and-filename branch from e663405 to 218afdd Compare January 13, 2022 19:12

Merge branch 'master' into feature/log-line-number-and-filename

bda7dad

hawkw self-requested a review January 14, 2022 17:29

hawkw merged commit 6f23c12 into tokio-rs:master Jan 14, 2022

hawkw mentioned this pull request Jan 14, 2022

subscriber: prepare to release 0.3.6 #1839

Merged

bsodmike added a commit to bsodmike/axum-rest-starter-example that referenced this pull request Jan 17, 2022

Clean up use of utility wrapper to log file/line numbers for tracing

6a97f16

This was just added to tracing (tokio-rs/tracing#1773) and the wrapper can be updated to leverage the same.

davidbarsky mentioned this pull request Sep 26, 2023

chore: backport roughly a year's worth of changes #2728

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Feature: Options to log line number and filename on tracing-subscriber #1773

Feature: Options to log line number and filename on tracing-subscriber #1773

renecouto commented Dec 9, 2021

hawkw left a comment

hawkw Dec 9, 2021

hawkw Dec 9, 2021

hawkw Dec 9, 2021

hawkw Dec 9, 2021

hawkw commented Dec 9, 2021

hawkw Dec 23, 2021

davidbarsky Dec 29, 2021

davidbarsky Dec 29, 2021 •

edited

Loading

hawkw Dec 23, 2021

hawkw Dec 23, 2021

hawkw commented Dec 28, 2021

hawkw commented Jan 11, 2022

hawkw commented Jan 13, 2022

-        let expected = Regex::new("^fake time tracing_subscriber::fmt::format::test: tracing-subscriber/src/fmt/format/mod.rs: [0-9]+: hello\n$").unwrap();
+        let expected = Regex::new(concat!(
+            "^fake time ",
+             module_path!(),
+             " :",
+             file!(),
+             ": [0-9]+: hello\n$"
+         )).unwrap();

-            write!(
-                writer,
-                "{}{} ",
-                dimmed.paint(line_number.to_string()),
-                dimmed.paint(":")
-            )?;
+            write!(
+                writer,
+                "{}{}:{} ",
+                dimmed.prefix(),
+                line_number,
+                dimmed.suffix(),
+            )?;

	#[cfg(not(feature = "ansi"))]
	impl Style {
	fn new() -> Self {
	Style
	}
	fn paint(&self, d: impl fmt::Display) -> impl fmt::Display {
	d
	}
	}

Feature: Options to log line number and filename on tracing-subscriber #1773

Feature: Options to log line number and filename on tracing-subscriber #1773

Conversation

renecouto commented Dec 9, 2021

Motivation

Solution

hawkw left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

hawkw commented Dec 9, 2021

Choose a reason for hiding this comment

Choose a reason for hiding this comment

davidbarsky Dec 29, 2021 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

hawkw commented Dec 28, 2021

hawkw commented Jan 11, 2022

hawkw commented Jan 13, 2022

davidbarsky Dec 29, 2021 •

edited

Loading