Re: [PATCH v5 09/24] util: introduce some API docs for logging APIs

["Daniel P. Berrangé" <berrange@redhat.com>]

On Tue, Jan 13, 2026 at 10:59:49AM +0100, Markus Armbruster wrote:
> Daniel P. Berrangé <berrange@redhat.com> writes:
> 
> > There is a gotcha with qemu_log() usage in a threaded process.
> > If fragments of a log message are output via qemu_log() it is
> > possible for messages from two threads to get mixed up. To
> > prevent this qemu_log_trylock() should be used, along with
> > fprintf(f) calls.
> >
> > This is a subtle problem that needs to be explained in the
> > API docs to ensure correct usage.
> >
> > Reported-by: Markus Armbruster <armbru@redhat.com>
> > Signed-off-by: Daniel P. Berrangé <berrange@redhat.com>
> > ---
> >  include/qemu/log-for-trace.h | 17 ++++++++++++++++-
> >  include/qemu/log.h           | 31 +++++++++++++++++++++++++++++++
> >  rust/util/src/log.rs         |  6 ++++++
> >  3 files changed, 53 insertions(+), 1 deletion(-)
> >
> > diff --git a/include/qemu/log-for-trace.h b/include/qemu/log-for-trace.h
> > index f3a8791f1d..6861a1a4b7 100644
> > --- a/include/qemu/log-for-trace.h
> > +++ b/include/qemu/log-for-trace.h
> > @@ -29,7 +29,22 @@ static inline bool qemu_loglevel_mask(int mask)
> >      return (qemu_loglevel & mask) != 0;
> >  }
> >  
> > -/* main logging function */
> > +/**
> > + * qemu_log: report a log message
> > + * @fmt: the format string for the message
> > + * @...: the format string arguments
> > + *
> > + * This will emit a log message to the current output stream.
> > + *
> > + * The @fmt string should normally represent a complete line
> > + * of text, and thus end with a newline character.
> 
> Note for later: "should normally".
> 
> > + *
> > + * While it is possible to incrementally output fragments of
> > + * a complete line using qemu_log, this is inefficient and
> > + * races with other threads. For outputting fragments it is
> > + * strongly preferred to use the qemu_log_trylock() method
> > + * combined with fprintf().
> > + */
> >  void G_GNUC_PRINTF(1, 2) qemu_log(const char *fmt, ...);
> >  
> >  #endif
> > diff --git a/include/qemu/log.h b/include/qemu/log.h
> > index 7effba4da4..e9d3c6806b 100644
> > --- a/include/qemu/log.h
> > +++ b/include/qemu/log.h
> > @@ -41,7 +41,38 @@ bool qemu_log_separate(void);
> >  
> >  /* Lock/unlock output. */
> >  
> > +/**
> > + * Acquires a lock on the current log output stream.
> > + * The returned FILE object should be used with the
> > + * fprintf() function to output the log message, and
> > + * then qemu_log_unlock() called to release the lock.
> > + *
> > + * The primary use case is to be able to incrementally
> > + * output fragments of a complete log message in an
> > + * efficient and race free manner.
> > + *
> > + * The simpler qemu_log() method must only be used
> > + * to output complete log messages.
> 
> "must".
> 
> > + *
> > + * A typical usage pattern would be
> > + *
> > + *    FILE *f = qemu_log_trylock()
> > + *
> > + *    fprintf(f, "Something ");
> > + *    fprintf(f, "Something ");
> > + *    fprintf(f, "Something ");
> > + *    fprintf(f, "The end\n");
> > + *
> > + *    qemu_log_unlock(f);
> > + *
> > + * Returns: the current FILE if available, NULL on error
> > + */
> >  FILE *qemu_log_trylock(void) G_GNUC_WARN_UNUSED_RESULT;
> > +
> > +/**
> > + * Releases the lock on the log output, previously
> > + * acquired by qemu_log_trylock().
> > + */
> >  void qemu_log_unlock(FILE *fd);
> >  
> >  /* Logging functions: */
> > diff --git a/rust/util/src/log.rs b/rust/util/src/log.rs
> > index 0a4bc4249a..6a3a30d8d8 100644
> > --- a/rust/util/src/log.rs
> > +++ b/rust/util/src/log.rs
> > @@ -134,6 +134,12 @@ fn drop(&mut self) {
> >  ///     "Address 0x{:x} out of range",
> >  ///     error_address,
> >  /// );
> > +///
> > +/// The `log_mask_ln` macro should only be used for emitting complete
> 
> "should only".
> 
> > +/// log messages. Where it is required to incrementally output string
> > +/// fragments to construct a complete message, `LogGuard::new()` should
> > +/// be directly used in combination with `writeln()` to avoid output
> > +/// races with other QEMU threads.
> >  /// ```
> >  #[macro_export]
> >  macro_rules! log_mask_ln {
> 
> "Should normally" suggests there are exceptions.
> 
> "Should only" does not.
> 
> "Must" is a bit stronger still.
> 
> Which of the three do we want?

The "Should" usage was reflecting the reality that we have quite alot
of code using qemu_log_trylock + qemu_log, instead of qemu_log_trylock
+ fprintf.

I didn't feel it appropriate to use 'must' unless we explicitly make
qemu_log() fail when used inside the scope of a qemu_log_trylock().

So "Should normally" is the best fit

With regards,
Daniel
-- 
|: https://berrange.com      -o-    https://www.flickr.com/photos/dberrange :|
|: https://libvirt.org         -o-            https://fstop138.berrange.com :|
|: https://entangle-photo.org    -o-    https://www.instagram.com/dberrange :|