Re: [PATCH 3/3] log: Fetch log times with CLOCK_MONOTONIC, not CLOCK_REALTIME

On Fri, Jul 26, 2024 at 11:32:57AM +0200, Stefano Brivio wrote:

On Fri, 26 Jul 2024 09:15:59 +1000 David Gibson wrote:

...

On Thu, Jul 25, 2024 at 06:26:34PM +0200, Stefano Brivio wrote:

...

We report relative timestamps in logs, so we want to avoid jumps in the system time.

Suggested-by: David Gibson Signed-off-by: Stefano Brivio

Reviewed-by: David Gibson

I noticed another pre-existing nit, though..

...

--- log.c | 4 ++-- passt.c | 2 +- 2 files changed, 3 insertions(+), 3 deletions(-)

diff --git a/log.c b/log.c index 9474bad..0fb25b7 100644 --- a/log.c +++ b/log.c @@ -68,7 +68,7 @@ void vlogmsg(bool newline, int pri, const char *format, va_list ap) struct timespec tp;

if (debug_print) { - clock_gettime(CLOCK_REALTIME, &tp); + clock_gettime(CLOCK_MONOTONIC, &tp); fprintf(stderr, logtime_fmt_and_arg(&tp)); fprintf(stderr, ": "); } @@ -382,7 +382,7 @@ void logfile_write(bool newline, int pri, const char *format, va_list ap) char buf[BUFSIZ]; int n;

- if (clock_gettime(CLOCK_REALTIME, &now)) + if (clock_gettime(CLOCK_MONOTONIC, &now))

We have two separate calls to get the time for "this" message. I think this means under the right circumstances we could have essentially the same message logged to different places with (slightly) different times.

This never happens because, in vlogmsg():

bool debug_print = (log_mask & LOG_MASK(LOG_DEBUG)) && log_file == -1;

Ah, good point.

...

That seems needlessly confusing. It would be nice to have a single point at which we capture the time for a single message.

...but yes, it might be confusing. A single clock_gettime() call would need a bit of refactoring in vlogmsg().

I have a draft patch, I'll send soon. -- David Gibson (he or they) | I'll have my music baroque, and my code david AT gibson.dropbear.id.au | minimalist, thank you, not the other way | around. http://www.ozlabs.org/~dgibson