On Tue, Jan 13, 2026 at 11:19:13AM +0100, Markus Armbruster wrote:
Daniel P. Berrangé <berrange@redhat.com> writes:
There are three general patterns to QEMU log output
1. Single complete message calls
qemu_log("Some message\n");
2. Direct use of fprintf
FILE *f = qemu_log_trylock() fprintf(f, "..."); fprintf(f, "..."); fprintf(f, "...\n"); qemu_log_unlock(f)
3. Mixed use of qemu_log_trylock/qemu_log()
FILE *f = qemu_log_trylock() qemu_log("...."); qemu_log("...."); qemu_log("....\n"); qemu_log_unlock(f)
Fixes: 012842c07552 (log: make '-msg timestamp=on' apply to all qemu_log usage) Reported-by: Richard Henderson <richard.henderson@linaro.org> Signed-off-by: Daniel P. Berrangé <berrange@redhat.com> --- include/qemu/log.h | 7 +++++++ util/log.c | 49 ++++++++++++++++++++++++++-------------------- 2 files changed, 35 insertions(+), 21 deletions(-)
diff --git a/include/qemu/log.h b/include/qemu/log.h index e9d3c6806b..95f417c2b7 100644 --- a/include/qemu/log.h +++ b/include/qemu/log.h @@ -69,6 +69,13 @@ bool qemu_log_separate(void); */ FILE *qemu_log_trylock(void) G_GNUC_WARN_UNUSED_RESULT;
+/** + * As qemu_log_trylock(), but will also print the message + * context, if any is configured and this caused the + * acquisition of the FILE lock + */ +FILE *qemu_log_trylock_context(void) G_GNUC_WARN_UNUSED_RESULT;
This is used just once, in qemu_log(). Could be inlined into qemu_log().
If you prefer to keep it as a function, you could make it static.
The intent was that some, but not all, places which currently use qemu_log_trylock() really ought to be including configured message prefix, and hence would need to call this method. No such updates of callers are done in this series though.
I wouldn't guess that this prints from the function name. Dunno, qemu_log_start_line()? Might want to pair it with a qemu_log_end_line() then.
Telling function name is less important if it's static.
Personally the inclusion of "log" in its filename is sufficiently suggestive. I'll rename it to qemu_log_trylock_with_context which is the name Richard originally requested.
diff --git a/util/log.c b/util/log.c index c44d66b5ce..2ce7286f31 100644 --- a/util/log.c +++ b/util/log.c @@ -127,13 +127,39 @@ static FILE *qemu_log_trylock_with_err(Error **errp)
Not this patch's fault, but here goes anyway:
static FILE *qemu_log_trylock_with_err(Error **errp) { FILE *logfile;
logfile = thread_file; if (!logfile) { if (log_per_thread) { g_autofree char *filename = g_strdup_printf(global_filename, log_thread_id()); logfile = fopen(filename, "w"); if (!logfile) { error_setg_errno(errp, errno, "Error opening logfile %s for thread %d", filename, log_thread_id()); return NULL; } thread_file = logfile; qemu_log_thread_cleanup_notifier.notify = qemu_log_thread_cleanup; qemu_thread_atexit_add(&qemu_log_thread_cleanup_notifier); } else { rcu_read_lock(); /* * FIXME: typeof_strip_qual, as used by qatomic_rcu_read, * does not work with pointers to undefined structures, * such as we have with struct _IO_FILE and musl libc. * Since all we want is a read of a pointer, cast to void**, * which does work with typeof_strip_qual. */ logfile = qatomic_rcu_read((void **)&global_file); if (!logfile) { rcu_read_unlock(); return NULL;
Fails without setting @errp.
Trivial to fix, I'll include a patch for that in next posting.
} } }
qemu_flockfile(logfile);
return logfile; }
+FILE *qemu_log_trylock_context(void) +{ + FILE *f = qemu_log_trylock();
This can fail, and if it does...
+ if (log_depth == 1 && message_with_timestamp) { + g_autofree const char *timestr = NULL; + g_autoptr(GDateTime) dt = g_date_time_new_now_utc(); + timestr = g_date_time_format_iso8601(dt); + fprintf(f, "%s ", timestr);
... we crash here.
Opps, yes will fix. 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 :|