- Sponsor
-
Notifications
You must be signed in to change notification settings - Fork 85
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: add support for customizable logger formatting #765
Conversation
Thank you for the PR. I am looking into it |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I do like the idea!
Such a mechanism is common practice in many other logging systems, so I don't know why we did not think about it before.
Left a few comments.
I made the requested changes and I added an extra |
812824d
to
0379d13
Compare
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I played around with the feature and really like it. It gives users all the flexibility they need.
I've noticed a few details which changed with your PR. Some of these changes might be okay, but I wanted to make sure none of them happen accidentally, and some plainly need to be fixed.
Please have a look at these probe-run invocations as context
$ # before PR without timestamp
$ DEFMT_LOG=trace cargo run -q --bin levels
(HOST) INFO flashing program (2 pages / 8.00 KiB)
(HOST) INFO success!
────────────────────────────────────────────────────────────────────────────────
INFO info
└─ levels::__cortex_m_rt_main @ src/bin/levels.rs:10
TRACE trace
└─ levels::__cortex_m_rt_main @ src/bin/levels.rs:11
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
println
└─ levels::__cortex_m_rt_main @ src/bin/levels.rs:15
────────────────────────────────────────────────────────────────────────────────
(HOST) INFO device halted without error
$ # before PR with timestamp
$ DEFMT_LOG=trace cargo run -q --bin levels
0 INFO info
└─ levels::__cortex_m_rt_main @ src/bin/levels.rs:10
1 TRACE trace
└─ levels::__cortex_m_rt_main @ src/bin/levels.rs:11
2 WARN warn
└─ levels::__cortex_m_rt_main @ src/bin/levels.rs:12
3 DEBUG debug
└─ levels::__cortex_m_rt_main @ src/bin/levels.rs:13
4 ERROR error
└─ levels::__cortex_m_rt_main @ src/bin/levels.rs:14
5 println
└─ levels::__cortex_m_rt_main @ src/bin/levels.rs:15
$ # after PR without timestamp
$ DEFMT_LOG=trace cargo run -q --bin levels
(HOST) INFO flashing program (2 pages / 8.00 KiB)
(HOST) INFO success!
────────────────────────────────────────────────────────────────────────────────
INFO info
└─ levels::__cortex_m_rt_main @ src/bin/levels.rs:10
TRACE trace
└─ levels::__cortex_m_rt_main @ src/bin/levels.rs:11
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
────────────────────────────────────────────────────────────────────────────────
(HOST) INFO device halted without error
$ # after PR with timestamp
$ DEFMT_LOG=trace cargo run -q --bin levels
0 INFO info
└─ levels::__cortex_m_rt_main @ src/bin/levels.rs:10
1 TRACE trace
└─ levels::__cortex_m_rt_main @ src/bin/levels.rs:11
2 WARN warn
└─ levels::__cortex_m_rt_main @ src/bin/levels.rs:12
3 DEBUG debug
└─ levels::__cortex_m_rt_main @ src/bin/levels.rs:13
4 ERROR error
└─ levels::__cortex_m_rt_main @ src/bin/levels.rs:14
5 <lvl> println
└─ levels::__cortex_m_rt_main @ src/bin/levels.rs:15
timestamp
With your PR and the default format, if there is no timestamp, the first character is a space. Before this was not the case1, but the log line just started with the log level. This should be fixed.
println
The idea of defmt::println
is that the log message is printed without the log level and timestamp. With your PR it emits a <lvl>
as log level. This should be fixed.
bold messages
With your PR all messages are bold. Before only log messages were bold, but println and host messages were normal. This is okay if it changes, but I would probably err for making all log messages normal (and the metadata dimmed).
space between timestamp and log message
Before, there were enough spaces between the log level and the log message so the beginning of the log message was aligned. With the PR there is always just one space. I think this is okay if it changes.
Footnotes
-
Actually there was a similar bug https://github.com/knurling-rs/defmt/issues/602 ↩
Unless I'm misunderstanding the circumstances under which the timestamp would not be available, I'd argue that the previous behavior is not the right behavior in the context of the new formatting system in this PR. I'm assuming that a timestamp is not available if the user does not provide a I also just don't see how I can implement the previous behavior nicely in the current system. If the user does not intend to provide a For example if I want the following format:
I think it'd be better to print
than
|
I've fixed this. I think I hadn't understood the purpose of that I see the value for a |
I've fixed this, with the exception of the dimmed metadata. I think further formatting options should be added in future PRs. |
I didn't understand this comment, but I think we should extend the formatting options with a field width specifier in a future PR. I think that would address this in a better way. Then you could have something like
without the need to special-case everything internally and allowing for better user-customization. |
Ah I see what you mean now, but I don't understand why this is not working. The width specifier is already there. Any ideas? |
Or we have a
I agree. I am unsure if we easily know if there is a timestamp implementation or not. |
It seems that adding a diff --git a/decoder/src/lib.rs b/decoder/src/lib.rs
index cf7fa12..7da00bf 100644
--- a/decoder/src/lib.rs
+++ b/decoder/src/lib.rs
@@ -271,6 +271,10 @@ impl Table {
pub fn encoding(&self) -> Encoding {
self.encoding
}
+
+ pub fn has_timestamp(&self) -> bool {
+ self.timestamp.is_some()
+ }
}
// NOTE follows `parser::Type` I tested it with a small project and adding and removing the timestamp implementation. |
So what would you like me to do about this? |
I propose the following:
Do you agree? |
I agree with the warning, but what do I print with the logs in that case? |
I added an info struct to the defmt logger API, and I added the warning in |
|
Done |
My understanding is that with this PR, the println format is hard-coded and it is not possible to add the timestamp as it used to be the case (IIRC). Is this by design or it would be possible to let the user customize the println format too? (like for the log and host log format) |
Hi @ia0, According to @Urhengulas this is by design:
I also argued that a discussion should be had about what we want
|
Thanks for the response! I'm working around by adding the timestamp directly in the |
Hei 👋🏾 I agree that we need to make the logging story more clear, I am gonna put some time into that soon™️ I would be interested why you cannot use the logging macros (e.g. |
Because that's something I want always printed, regardless of log level. |
A pain point for me when using
defmt
is that I can't easily customize the format in which the logs are printed.This PR replaces the current
PrettyLogger
with a newStdoutLogger
(seemed like a better name to me since the other logger is calledJsonLogger
), that supports an optional format string. If no format string is provided, a default format is used that looks pretty much the same as the current format, with the exception that the location is not "dimmed".The formatting options I added are completely arbitrary and not set in stone. I just chose what made sense to me. This is from what I wrote in the docs:
The new format is easily changeable and extendable. Some things that I think could be implemented but I chose not to waste time on before getting community feedback are:
{t:8}
or something like that to specify that the timestamp must be at least 8 characters wide)This PR is also an alternative to #762 (I think)