-
Notifications
You must be signed in to change notification settings - Fork 565
logger: improve format of timestamp (quality of life improvement) #7355
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
logger: improve format of timestamp (quality of life improvement) #7355
Conversation
Streamline the output format of the timestamp of a message. The old format doesn't nicely align across multiple lines. # Example (old style) ``` cloud-hypervisor: 858.465660ms: <vcpu0> DEBUG:devices/src/ioapic.rs:154 -- IOAPIC_R @ offset 0x10 cloud-hypervisor: 858.507342ms: <vcpu0> DEBUG:devices/src/ioapic.rs:298 -- IOAPIC_R reg 0x1 cloud-hypervisor: 1.010001s: <vcpu0> DEBUG:devices/src/ioapic.rs:174 -- IOAPIC_W @ offset 0x0 cloud-hypervisor: 1.010067s: <vcpu0> DEBUG:devices/src/ioapic.rs:154 -- IOAPIC_R @ offset 0x10 ``` # Example (new style) ``` cloud-hypervisor: 0.731399s: <vcpu0> DEBUG:devices/src/ioapic.rs:174 -- IOAPIC_W @ offset 0x10 cloud-hypervisor: 0.731420s: <vcpu0> DEBUG:devices/src/ioapic.rs:252 -- IOAPIC_W reg 0x2a, val 0x10000 cloud-hypervisor: 17.026073s: <vmm> INFO:vmm/src/api/mod.rs:898 -- API request event: VmInfo cloud-hypervisor: 17.263210s: <vmm> INFO:vmm/src/api/mod.rs:898 -- API request event: VmInfo cloud-hypervisor: 17.547915s: <vmm> INFO:vmm/src/api/mod.rs:898 -- API request event: VmInfo ``` Signed-off-by: Philipp Schuster <[email protected]> On-behalf-of: SAP [email protected]
Signed-off-by: Philipp Schuster <[email protected]> On-behalf-of: SAP [email protected]
|
Shouldn't we keep the smaller numbers as milliseconds? |
Could you please elaborate a little about the value-add you see in this behavior? IMHO, having things aligned helps humans to parse the log much faster. And you have the milliseconds anyway, just in an aligned format. |
|
|
||
| let now = std::time::Instant::now(); | ||
| let duration = now.duration_since(self.start); | ||
| let duration_s = duration.as_secs_f32(); |
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.
This looks better:
let duration = self.start.elapsed().as_secs_f32();
|
Thanks @phip1611 - although this looks nice - I worry that this might break tooling that expects only a single space before the time - I see from the format string it right aligns it to 10 characters? How is that going to look when a VM is up for many months or even years? |
It would look somehow like this:
I see but do we make any promises for the log format? From the README:
So there are features for that we do not support "stability" across updates. Not sure is the log format is or should be one of them. I don't have a very strong opinion here, it is just a quality of live improvement IMHO. |
fae3241
This is a small improvement to the timestamp in the logging format.
Example (old style)
Example (new style)