This addresses two key gotchas with the logging APIs: * Safely outputting a single line of text using multiple qemu_log() calls requires use of the qemu_log_trylock/unlock functions to avoid interleaving between threads * Directly outputting to the FILE object returned by qemu_log_trylock() must be discouraged because it prevents the inclusion of configured log message prefixes. Reported-by: Markus Armbruster <armbru@redhat.com> Signed-off-by: Daniel P. Berrangé <berrange@redhat.com> --- include/qemu/log-for-trace.h | 35 ++++++++++++++++++++++++++++++++++- include/qemu/log.h | 26 ++++++++++++++++++++++++++ rust/util/src/log.rs | 7 +++++++ 3 files changed, 67 insertions(+), 1 deletion(-) diff --git a/include/qemu/log-for-trace.h b/include/qemu/log-for-trace.h index d47c9cd446..4e05b2e26f 100644 --- a/include/qemu/log-for-trace.h +++ b/include/qemu/log-for-trace.h @@ -29,7 +29,40 @@ 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, ending with a newline character. + * + * If intending to call this function multiple times to + * incrementally construct a line of text, locking must + * be used to ensure that output from different threads + * is not interleaved. + * + * This is achieved by calling qemu_log_trylock() before + * starting the log line; calling qemu_log() multiple + * times with the last call having a newline at the end + * of @fmt; finishing with a call to qemu_log_unlock(). + * + * The FILE object returned by qemu_log_trylock() does + * not need to be used for outputting text directly, + * it is merely used to associate the lock. + * + * FILE *f = qemu_log_trylock() + * + * qemu_log("Something"); + * qemu_log("Something"); + * qemu_log("Something"); + * qemu_log("The end\n"); + * + * qemu_log_unlock(f); + * + */ 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 aae72985f0..867fe327e4 100644 --- a/include/qemu/log.h +++ b/include/qemu/log.h @@ -41,7 +41,33 @@ bool qemu_log_separate(void); /* Lock/unlock output. */ +/** + * Acquires a lock on the current log output stream. + * The returned FILE object must be passed to + * qemu_log_unlock() to later release the lock. + * + * This should be used to protect a sequence of calls + * to qemu_log(), if they are being used to incrementally + * output a single line of text. For qemu_log() calls which + * output a complete line of text it is not required to + * take explicit locks. + * + * The returned FILE object may be used to directly + * output log messages, however, doing so will prevent + * the inclusion of configured log message prefixes. + * It is thus recommended that this be used sparingly, + * only in cases where it is required to dump large + * data volumes. Use of qemu_log() is preferred for + * most output tasks. + * + * 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 af9a3e9123..eaf493f0df 100644 --- a/rust/util/src/log.rs +++ b/rust/util/src/log.rs @@ -55,6 +55,13 @@ impl LogGuard { /// writeln!(log, "test"); /// } /// ``` + /// + /// Note that directly writing to the log output will prevent the + /// inclusion of configured log prefixes. It is thus recommended + /// that this be used sparingly, only in cases where it is required + /// to dump large data volumes. Use of [`log_mask_ln!()`](crate::log_mask_ln) + /// macro() is preferred for most output tasks. + pub fn new() -> Option<Self> { let f = unsafe { bindings::qemu_log_trylock() }.cast(); NonNull::new(f).map(Self) -- 2.50.1