On 25/9/25 12:31, Daniel P. Berrangé wrote:
On Thu, Sep 25, 2025 at 12:22:39PM +0200, Philippe Mathieu-Daudé wrote:
Hi Daniel,
On 25/9/25 11:44, Daniel P. Berrangé wrote:
This series is a tangent that came out of discussion in
https://lists.nongnu.org/archive/html/qemu-devel/2025-08/msg00903.html
In thinking about adding thread info to error_report, I came to realize we should likely make qemu_log behave consistently with error_report & friends. We already honour '-msg timestamp=on', but don't honour 'guest-name=on' and also don't include the binary name.
The main things to note:
* error_report/warn_report/qemu_log share the same output format and -msg applies to both
* -msg debug-threads=on is now unconditionally enabled and thus the param is deprecated & ignored
* Thread ID and name are unconditionally enabled
* Guest name is surrounded in [...] brackets
* The default output lines are typically 15 chars wider given that we always include the thread ID + name now
* This takes the liberty of assigning the new file to the existing error-report.c maintainer (Markus) Since splitting it off into message.c instead of putting it all in error-report.c felt slightly nicer.
One thing I didn't tackle is making the location info get reported for qemu_log. This is used to give context for error messages when parsing some CLI args, and could be interesting for log messages associated with those same CLI args.
Testing with this change on top ...:
-- >8 -- diff --git a/include/qemu/message.h b/include/qemu/message.h index 2cc092c993b..97fd2a94fbd 100644 --- a/include/qemu/message.h +++ b/include/qemu/message.h @@ -10,2 +10,3 @@ enum QMessageFormatFlags { QMESSAGE_FORMAT_THREAD_INFO = (1 << 3), + QMESSAGE_FORMAT_VCPU_ID = (1 << 4), }; diff --git a/system/vl.c b/system/vl.c index bf9f80491f2..2f43a075be9 100644 --- a/system/vl.c +++ b/system/vl.c @@ -149,3 +149,4 @@ (QMESSAGE_FORMAT_PROGRAM_NAME | \ - QMESSAGE_FORMAT_THREAD_INFO) + QMESSAGE_FORMAT_THREAD_INFO | \ + QMESSAGE_FORMAT_VCPU_ID)
diff --git a/util/message.c b/util/message.c index 7d94b9d970d..19d1331403a 100644 --- a/util/message.c +++ b/util/message.c @@ -6,2 +6,3 @@ #include "monitor/monitor.h" +#include "hw/core/cpu.h"
@@ -46,2 +47,8 @@ void qmessage_context_print(FILE *fp) } + + if (message_format & QMESSAGE_FORMAT_VCPU_ID) { + if (current_cpu) { + fprintf(fp, "(cpuid:%d): ", current_cpu->cpu_index); + } + } } ---
... on a branch where I test heavy vcpu context switching.
When using tracing + stderr AND the stdio console, I sometimes get the trace events to disappear at some point. Not sure why (or if related to my branch) yet.
When redirecting traces to a file ('-D foo.log'), all traces are collected (no hang).
In both cases I notice a high performance slow down (when tracing is used).
Suspicions: - flocking
The logging code (and thus tracing) already used flockfile in qemu_log, so that should not be new. Only error_report gained new flockfile calls in this series.
- new formatting
Seems the more likely option. If practical, a git bisect across the series should show which part introduced any slowdown.
This is planned.
Assuming you've not given any -msg option to QEMU though, the finger
Indeed.
probably points towards the thread name code, as the bit that is new and enabled by default.
I thought about that then noticed the thread name is const (preformatted once in each qemu_thread_get_name() implementation).
With regards, Daniel