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

[David Gibson <david@gibson.dropbear.id.au>]

[-- Attachment #1: Type: text/plain, Size: 2317 bytes --]

On Fri, Jul 26, 2024 at 11:32:57AM +0200, Stefano Brivio wrote:
> On Fri, 26 Jul 2024 09:15:59 +1000
> David Gibson <david@gibson.dropbear.id.au> 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 <david@gibson.dropbear.id.au>
> > > Signed-off-by: Stefano Brivio <sbrivio@redhat.com>  
> > 
> > Reviewed-by: David Gibson <david@gibson.dropbear.id.au>
> > 
> > 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

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]