-
-
Notifications
You must be signed in to change notification settings - Fork 75
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
decoder: improve default format #848
decoder: improve default format #848
Conversation
Can we add in an option to put the logs back like they were? So anyone who doesn't want or like the new format can just add the option and go back to how they were? |
Sure, I can do that later today or tomorrow. |
a7deb93
to
f494673
Compare
Added |
I tried with probe-rs, which just uses the default format. Before: $ DEFMT_LOG=debug cargo run --target=thumbv7em-none-eabi --bin levels -- --allow-erase-all
Compiling defmt-macros v0.3.9
Compiling defmt v0.3.8
Compiling panic-probe v0.3.2
Compiling defmt-rtt v0.4.1
Compiling project v0.1.0 (/Users/jonathan/Documents/knurling/app-template)
Finished dev [optimized + debuginfo] target(s) in 0.91s
Running `probe-rs run --chip nRF52840_xxAA target/thumbv7em-none-eabi/debug/levels --allow-erase-all`
Erasing ✔ [00:00:00] [#######################################################] 8.00 KiB/8.00 KiB @ 25.22 KiB/s (eta 0s )
Programming ✔ [00:00:00] [#######################################################] 8.00 KiB/8.00 KiB @ 20.87 KiB/s (eta 0s ) Finished in 0.733s
INFO info
└─ levels::__cortex_m_rt_main @ src/bin/levels.rs:10
WARN warn
└─ levels::__cortex_m_rt_main @ src/bin/levels.rs:12
DEBUG debug
└─ levels::__cortex_m_rt_main @ src/bin/levels.rs:13
ERROR error
└─ levels::__cortex_m_rt_main @ src/bin/levels.rs:14
<lvl> println
└─ levels::__cortex_m_rt_main @ src/bin/levels.rs:15 After: $ ../probe-rs/target/debug/probe-rs run --chip nRF52840_xxAA target/thumbv7em-none-eabi/debug/levels
Erasing sectors ✔ [00:00:00] [################################################] 8.00 KiB/8.00 KiB @ 16.26 KiB/s (eta 0s )
Programming pages ✔ [00:00:00] [################################################] 8.00 KiB/8.00 KiB @ 11.97 KiB/s (eta 0s ) Finished in 1.221s
[INFO ] levels/bin/levels.rs:15 info
[WARN ] levels/bin/levels.rs:17 warn
[DEBUG] levels/bin/levels.rs:18 debug
[ERROR] levels/bin/levels.rs:19 error
println
➜ app-template git:(main) ✗ This looks like an improvement to me, but I'll go and ask the probe-rs people whether they consider this a breaking change or if they want to automatically pick it up. |
They seem happy for it to go into 0.3.12, as they are pinned to
|
OK, I was testing the wrong version of probe-rs. I edited to correct the output. The problem with removing the newline is that the location field is of variable length, and because it's now padded to the maximum location length, you get a lot of weird padding in the output for lines from locations that are shorter in length. |
I do like the current two line format, but I am honestly fine with any default. @jonathanpallant what is your call? |
After a lot of discussion on the probe.rs matrix chat, we iterated to: const FORMAT: &str = "{[{L}]%bold} {s}";
const FORMAT_WITH_LOCATION: &str = "{[{L}]%bold} {s} {({c:bold}:{ff}:{l:1})%dimmed}";
const FORMAT_WITH_TIMESTAMP: &str = "{t} {[{L}]%bold} {s}";
const FORMAT_WITH_TIMESTAMP_AND_LOCATION: &str = "{t} {[{L}]%bold} {s} {({c:bold}:{ff}:{l:1})%dimmed}"; |
I pushed the new format :) |
Ah, there's an issue. |
Perhaps: const FORMAT: &str = "{[{L}]%bold} {s}";
const FORMAT_WITH_LOC: &str = "{[{L}]%bold} {s} {({c:bold} {fff}:{l:1})%dimmed}";
const FORMAT_WITH_TS: &str = "{t} {[{L}]%bold} {s}";
const FORMAT_WITH_TS_AND_LOC: &str = "{t} {[{L}]%bold} {s} {({c:bold} {fff}:{l:1})%dimmed}";
|
I think trying to make the paths clickable is going to be very painful if we don't have the full path there. Sometimes it will work and sometimes it won't. Especially with dependencies from crates.io where the path would be something like:
vscode won't be able to figure out anything just with |
In the end it's just about striking a good balance, but I think having stuff work only sometimes is probably bad UX |
I see your point, but I don't think I want the full path, because they are so long. For me |
Unless you have the panic-probe-0.3.1 folder open, or any file in that folder open. Then it works it out. |
I definitely don't want the full path either. I'm fine with anything really, I think the new default would be a pretty good improvement, and it doesn't have to be set in stone forever, we can always adjust in the future if necessary. |
It'd be cool if we somehow could show the full path for files under the binary crate, and only |
Make it clickable was one main reason to always show the full path by default, iirc. Also Maybe we can see if we can port that code to |
Basically that was what |
It sounds like that'd need to be implemented in probe-rs |
Here are the PRs that implemented shorten paths. It includes examples. |
We decided to go back to probe-rs and ask if in fact the new log format should be in their repo, instead of being added to the library. We weren't sure if we wanted defmt-decoder to maintain a big list of possible log formats, or if that should be a tool-by-tool decision. |
Now we have "Default" (the two-line version) and "OneLiner" (the new version). The tool using this library can then choose, and there is no breaking change if they keep the default. Also refactored out some common code, as I imagine we'll get additional formats in the future. And added some missing comments, now this library is using used by third-parties.
aa7dff4
to
9c8c97d
Compare
I added a bunch of comments, and pulled out some common code and put it behind a trait. This now switches the default back as it was, so it requires probe-rs to implement some command line flags to a) pick a defmt formatting style, and b) show the user the list of possible defmt formatting styles. Oh, I also rebased. |
Thanks for the help :) I just wanted to mention that the original intention of this PR was to improve the default format, not to just add another formatting option (for that I could have just used the custom log format option for my own projects - which I already do and will probably continue to do). |
Yeah, and I do appreciate that. It's just that we discussed this internally and we realised that as we have a bunch of users of this library that we don't know much about - people writing custom tools and not using probe-rs - and we weren't comfortable surprising them with a change to the default log format. I think probe-rs is in a better position to change the defaults, because it's reasonable for binaries to have stronger opinions than libraries about console formatting. With these changes, hopefully that is really easy for them to do. Edit to add: It is possible we could do a switch of the default in some future semver-breaking-change release. |
@andresovela @jonathanpallant Is this good to go? |
I think this was "blocked" on opening a PR on probe-rs to support this, but I've unfortunately changed projects and haven't been working on Rust stuff so I haven't gotten around this. That said, I'm not sure what's defmt's policy on rolling out this sort of changes. |
The view was expressed that it should be the binary that configures the library, rather than the library changing its default output. |
Yeah I remember. I think this PR is now mostly just code clean up. |
reads Oh yeah! OK, this is fine then. The default is unchanged - this just cleans it up and adds a second option for anyone who wants it. |
This PR contains a breaking change, because |
I guess as long as probe-rs still builds, it's probably OK. |
This is the only place they use it and that should be fine since they only construct it: https://github.com/probe-rs/probe-rs/blob/f8bff658f16196c12e888f626ba3618982d4220e/probe-rs-tools/src/bin/probe-rs/util/rtt.rs#L349-L355 |
I have updated the default log format to something I consider more sensible. Whether this proposal is the best default or not is of course a very subjective matter.
The main and biggest problem with the current format is the two-line log on the "with location" variant. It introduces a lot of visual noise and it makes it pretty hard to read the logs IMO. It also introduces issues when the user wants to print a multi-line log for whatever reason. In the screenshots below I added an extra line just to emphasize an error, for example. The current version without location is not too bad actually.
The proposed format in this PR introduces the following improvements to the logging experience:
mod.rs
in a single cratemy_app::____embassy_main_task::{async_fn#0}
Logs with location before this PR
Logs with location after this PR
Logs without location before this PR
Logs without location after this PR
I hope the proposed format is reasonable. I have no idea why nobody has made an attempt to improve the current one yet, maybe it's not as annoying to others as it is for me. This not only an issue for my own codebases, but generally the default ends up being used as reference material, on blog posts, etc, for example this post on URLO.
Note that the log format continues to be customizable, so if anyone wants to change anything, the option is still there.
Another idea I had was to introduce a new location option that prints just the crate name instead of crate + file name + line number:
I think an option like that would probably be useful for some people as well.