Created attachment 44863 [details] Patch for src/util.c:format_timespan() The output from format_timespan is unusual and nonstandard. For example, here's a message from /var/log/messages: Startup finished in 1s 810ms 434us (kernel) + 1s 673ms 918us (initrd) + 3min 10s 373ms 956us (userspace) = 3min 13s 858ms 308us. Startup finished in 1s 751ms 494us (kernel) With the attached patch, the message becomes Startup finished in 1.751494s (kernel) + 1.673918s (initrd) + 3min 10.373956s (userspace) = 3min 13.858308s. I have built new systemd stuff from the source rpm and booted with it, and the resulting line after the boot is now: systemd[1]: Startup finished in 1.541491s (kernel) + 1.507862s (initrd) + 3min 8.000672s (userspace) = 3min 11.050025s.
Sounds like a good idea. I have a few requests though before I merge this: 1) parse_usec() is supposed to be able to parse everything format_timestamp() spits out. With your change this won't work anymore. Can you update parse_usec() too, please? 2) If people enter values like "1s" somewhere and this gets parsed and formatted again with your patch this would be shown as "1.000000s". I am not sure I like this. I think it would be much nicer if we'd show either 0, 3 or 6 numerics after the dot, depending whether the formatting would have only trailing zeros. That way 1s would be output as "1s", and 1.5s would be shown as "1.500s", and 1234ms as "1.234s", and so on. By showing only 0, 3, or 6 numerics after the dot the user can easily deduce ms and us from the value shown, but isn't overwhelmed by too many needless zeros behind the dot. BTW, you get extra points because you didn't use %f or %g to format this. This way things are locale-independent and we use no FP conversions. If you make these changes I'll merge your patch right-away! Thanks a lot!
Created attachment 45012 [details] [review] Same patch but gifwise this time and updated to latest util.c Fixes format_timespan() to produce e.g. 1.234567s rather than 1s 234ms 567 us
Oops, ships passing the night, hadn't seen your comment before I sent my new patch. I agree that parse_usec() needs fixing to accept the new output I've gotten format_timespan() to produce, and I'm working on that project right now. I'll send a patch within a day for that. I disagree that a time multiple of exactly one second should be represented as 1s rather than 1.000000s, for these reasons: columnarity, precision, odds, uniformity, code simplicity. 1. columnarity. Suppose someone does grep 'finished in' /var/log/messages*. When there's always six digits to the right of the decimal point, the results appear (almost) columnar. With 6 digits: Startup finished in 1.000000s (kernel) + 1.531926s (initrd) + 3min 7.863342s (userspace) = Startup finished in 1.585518s (kernel) + 1.494824s (initrd) + 3min 13.000000s (userspace) = Startup finished in 1.620459s (kernel) + 1.000000s (initrd) + 3min 7.084532s (userspace) = Startup finished in 1.677396s (kernel) + 1.455887s (initrd) + 3min 7.000000s (userspace) = With no digits nor decimal point: Startup finished in 1s (kernel) + 1.531926s (initrd) + 3min 7.863342s (userspace) = Startup finished in 1.585518s (kernel) + 1.494824s (initrd) + 3min 13s (userspace) = Startup finished in 1.620459s (kernel) + 1s (initrd) + 3min 7.084532s (userspace) = Startup finished in 1.677396s (kernel) + 1.455887s (initrd) + 3min 7s (userspace) = 2. precision. Even when a time interval's µs part is 0 it still is microsecond-precise, not second-precise, and it should be shown as such. Races are won in times these days measured in I suppose milliseconds, and the reported times are e.g. 3:42.923s or 3:45.000s, to express the precision. 3. odds. The odds are of course one in a million that a time will have zero microseconds, and so to format differently in that case is almost a bug. 3a. more odds. Should we also drop trailing zero digits, for the case of 1.345000s to be shown as 1.345s? It would be consistent with the use of 1s, but ewwwww. 4. uniformity. Maybe this amounts to columnarity, I dunno. It's nice to have a time interval delivered in a standardish string ddd.dddddds rather than two different strings ddds and ddd.dddddds. Well, I think it's nice :-). 5. code simplicity and maintainability. Code that produces a standard string with a single snprintf() is better practice than code which can produce, let's say, 5s or 5.1s or 5.12s or ... or 5.012367s. The latter would probably require multiple snprintf()s, and a maintainer could change one of them and forget to change the others. Okay, whew, long-winded rationalizations. If, after all that, you still believe that format_timespan() should produce either of these two seconds formats: "1s", "1.000573s", say the word and I will bite the bullet and produce those results. Let me know, and meanwhile I'll work on parse_usec() and plan for either of your choices. Thanks for all you've done, don't let me ever forget to thank you for that. Richard
Created attachment 45019 [details] [review] Patch modifies format_timespan() and parse_usec() format_timespan() is modified to produce seconds as 1.234567s: six decimal places even if exactly 1 second (1.000000s). parse_usec() is modified to additionally accept 1.dddddds (from 1 to 6 decimal digits).
Created attachment 45034 [details] [review] src/util.c and src/util.h: format_timespan() and parse_usec() Patch reworks format_timespan() per Lennart and reworks parse_usec() to symbolize constants.
Okay, here's the best patch of all. Lennart, format_timespan() does almost exactly what you asked for. For zero µs it gives e.g. 1.0s; for only 3 digits of µs it gives 1.234s; for 4 to 6 digits it gives 1.234567s. I tried for 1s but I couldn't get the single snprintf() to omit the zero, sigh. I've reworked patch_usec() too. I've changed the new fract[] table to symbolize all the constants, ala USEC_PER_FOO, and I've added deci, centi, decimilli, and centimilli constants to util.h The previous patch had a very slight bug that, for exactly one day it would print "1d 0.0s", which is stupid. This one prints "1d". Hope you like it. I think it's solid. Richard
Hm, that attachment of Comment #5 does go with my comment of Comment #6. I must say that despite the fun I had coding up the fractional seconds more or less to your specs, Lennart, I think I put forth good arguments in Comment #3 on why it's really a good thing to always produce "1.234567s" even if it turns out to be "53.000000s". If I convinced you too, holler and I'll make a patch that does it. If I didn't convince you, well, then, use the latest attachment, from Comment #5, described in Comment #6.
I'll merge this as one of the first things after the F15 release. As long as F15 is in beta I will fix only bugs and really trivial stuff. I hope that's OK with you.
Yes, of course it's okay, Lennart. I appreciate the note.
OK, this took waaaay to long. But this is finally in git. I made sure the formatting is always parseable. Also, accuracy is configurable by the caller. I pretty much implemented your suggestions, i.e. "1.234567s" is now used as syntax for values <= 1s. However, for values > 1s and <= 1ms e use "47.352ms" as syntax instead. And for values > 1ms we use just use us. This should make it nicer to read smaller values. Sorry for the delay!
Use of freedesktop.org services, including Bugzilla, is subject to our Code of Conduct. How we collect and use information is described in our Privacy Policy.