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.
As an example of the current state, consider mixing error and
log output today:
- Default context:
# qemu-system-x86_64 -object tls-creds-x509,id=t0,dir=fish \
-d 'trace:qcrypto*'
qcrypto_tls_creds_x509_load TLS creds x509 load creds=0x55ac6d97f700 dir=fish
qcrypto_tls_creds_get_path TLS creds path creds=0x55ac6d97f700
filename=ca-cert.pem path=<none>
qemu-system-x86_64: Unable to access credentials fish/ca-cert.pem: No such
file or directory
- Full context:
# qemu-system-x86_64 -object tls-creds-x509,id=t0,dir=fish \
-d 'trace:qcrypto*' \
-msg guest-name=on,timestamp=on \
-name "fish food"
2025-08-19T20:14:16.791413Z qcrypto_tls_creds_x509_load TLS creds x509 load
creds=0x55e9a3458d10 dir=fish
2025-08-19T20:14:16.791429Z qcrypto_tls_creds_get_path TLS creds path
creds=0x55e9a3458d10 filename=ca-cert.pem path=<none>
2025-08-19T20:14:16.791433Z fish food qemu-system-x86_64: Unable to access
credentials fish/ca-cert.pem: No such file or directory
And after this series is complete:
- Default context:
# qemu-system-x86_64 -object tls-creds-x509,id=t0,dir=fish \
-d 'trace:qcrypto*'
qemu-system-x86_64(1184284:main): qcrypto_tls_creds_x509_load TLS creds x509
load creds=0x55a24ad5cb30 dir=fish
qemu-system-x86_64(1184284:main): qcrypto_tls_creds_get_path TLS creds path
creds=0x55a24ad5cb30 filename=ca-cert.pem path=<none>
qemu-system-x86_64(1184284:main): Unable to access credentials
fish/ca-cert.pem: No such file or directory
- Full context:
# qemu-system-x86_64 -object tls-creds-x509,id=t0,dir=fish \
-d 'trace:qcrypto*' \
-msg guest-name=on,timestamp=on \
-name "fish food"
2025-08-19T20:12:50.211823Z [fish food] qemu-system-x86_64(1168876:main):
qcrypto_tls_creds_x509_load TLS creds x509 load creds=0x5582183d8760 dir=fish
2025-08-19T20:12:50.211842Z [fish food] qemu-system-x86_64(1168876:main):
qcrypto_tls_creds_get_path TLS creds path creds=0x5582183d8760
filename=ca-cert.pem
+path=<none>
2025-08-19T20:12:50.211846Z [fish food] qemu-system-x86_64(1168876:main):
Unable to access credentials fish/ca-cert.pem: No such file or directory
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
- new formatting
Regards,
Phil.
