* [PULL 0/1] Tracing patches
@ 2025-07-24 14:46 Stefan Hajnoczi
2025-07-24 14:46 ` [PULL 1/1] log: make '-msg timestamp=on' apply to all qemu_log usage Stefan Hajnoczi
2025-07-25 15:25 ` [PULL 0/1] Tracing patches Stefan Hajnoczi
0 siblings, 2 replies; 5+ messages in thread
From: Stefan Hajnoczi @ 2025-07-24 14:46 UTC (permalink / raw)
To: qemu-devel
Cc: Pierrick Bouvier, Mahmoud Mandour, Mads Ynddal, Alexandre Iooss,
Stefan Hajnoczi, Alex Bennée
The following changes since commit 9e601684dc24a521bb1d23215a63e5c6e79ea0bb:
Update version for the v10.1.0-rc0 release (2025-07-22 15:48:48 -0400)
are available in the Git repository at:
https://gitlab.com/stefanha/qemu.git tags/tracing-pull-request
for you to fetch changes up to 012842c075520dbe1bd96a2fdcf4e218874ba443:
log: make '-msg timestamp=on' apply to all qemu_log usage (2025-07-24 10:12:21 -0400)
----------------------------------------------------------------
Pull request
This commit is still worth having in QEMU 10.1 for the all-round improvements
made (consistent timestamping, binary size reduction, header pollution cleanup)
even if it's debatable whether this is a bug fix.
----------------------------------------------------------------
Daniel P. Berrangé (1):
log: make '-msg timestamp=on' apply to all qemu_log usage
util/log.c | 20 +++++++++++++++++++-
scripts/tracetool/backend/log.py | 14 +-------------
2 files changed, 20 insertions(+), 14 deletions(-)
--
2.50.1
^ permalink raw reply [flat|nested] 5+ messages in thread
* [PULL 1/1] log: make '-msg timestamp=on' apply to all qemu_log usage
2025-07-24 14:46 [PULL 0/1] Tracing patches Stefan Hajnoczi
@ 2025-07-24 14:46 ` Stefan Hajnoczi
2025-07-25 17:04 ` Pierrick Bouvier
2025-07-25 15:25 ` [PULL 0/1] Tracing patches Stefan Hajnoczi
1 sibling, 1 reply; 5+ messages in thread
From: Stefan Hajnoczi @ 2025-07-24 14:46 UTC (permalink / raw)
To: qemu-devel
Cc: Pierrick Bouvier, Mahmoud Mandour, Mads Ynddal, Alexandre Iooss,
Stefan Hajnoczi, Alex Bennée, Daniel P. Berrangé,
Markus Armbruster, Vladimir Sementsov-Ogievskiy
From: Daniel P. Berrangé <berrange@redhat.com>
Currently the tracing 'log' back emits special code to add timestamps
to trace points sent via qemu_log(). This current impl is a bad design
for a number of reasons.
* It changes the QEMU headers, such that 'error-report.h' content
is visible to all files using tracing, but only when the 'log'
backend is enabled. This has led to build failure bugs as devs
rarely test without the (default) 'log' backend enabled, and
CI can't cover every scenario for every trace backend.
* It bloats the trace points definitions which are inlined into
every probe location due to repeated inlining of timestamp
formatting code, adding MBs of overhead to QEMU.
* The tracing subsystem should not be treated any differently
from other users of qemu_log. They all would benefit from
having timestamps present.
* The timestamp emitted with the tracepoints is in a needlessly
different format to that used by error_report() in response
to '-msg timestamp=on'.
This fixes all these issues simply by moving timestamp formatting
into qemu_log, using the same approach as for error_report.
The code before:
static inline void _nocheck__trace_qcrypto_tls_creds_get_path(void * creds, const char * filename, const char * path)
{
if (trace_event_get_state(TRACE_QCRYPTO_TLS_CREDS_GET_PATH) && qemu_loglevel_mask(LOG_TRACE)) {
if (message_with_timestamp) {
struct timeval _now;
gettimeofday(&_now, NULL);
qemu_log("%d@%zu.%06zu:qcrypto_tls_creds_get_path " "TLS creds path creds=%p filename=%s path=%s" "\n",
qemu_get_thread_id(),
(size_t)_now.tv_sec, (size_t)_now.tv_usec
, creds, filename, path);
} else {
qemu_log("qcrypto_tls_creds_get_path " "TLS creds path creds=%p filename=%s path=%s" "\n", creds, filename, path);
}
}
}
and after:
static inline void _nocheck__trace_qcrypto_tls_creds_get_path(void * creds, const char * filename, const char * path)
{
if (trace_event_get_state(TRACE_QCRYPTO_TLS_CREDS_GET_PATH) && qemu_loglevel_mask(LOG_TRACE)) {
qemu_log("qcrypto_tls_creds_get_path " "TLS creds path creds=%p filename=%s path=%s" "\n", creds, filename, path);
}
}
The log and error messages before:
$ qemu-system-x86_64 -trace qcrypto* -object tls-creds-x509,id=tls0,dir=$HOME/tls -msg timestamp=on
2986097@1753122905.917608:qcrypto_tls_creds_x509_load TLS creds x509 load creds=0x55d925bd9490 dir=/var/home/berrange/tls
2986097@1753122905.917621:qcrypto_tls_creds_get_path TLS creds path creds=0x55d925bd9490 filename=ca-cert.pem path=<none>
2025-07-21T18:35:05.917626Z qemu-system-x86_64: Unable to access credentials /var/home/berrange/tls/ca-cert.pem: No such file or directory
and after:
$ qemu-system-x86_64 -trace qcrypto* -object tls-creds-x509,id=tls0,dir=$HOME/tls -msg timestamp=on
2025-07-21T18:43:28.089797Z qcrypto_tls_creds_x509_load TLS creds x509 load creds=0x55bf5bf12380 dir=/var/home/berrange/tls
2025-07-21T18:43:28.089815Z qcrypto_tls_creds_get_path TLS creds path creds=0x55bf5bf12380 filename=ca-cert.pem path=<none>
2025-07-21T18:43:28.089819Z qemu-system-x86_64: Unable to access credentials /var/home/berrange/tls/ca-cert.pem: No such file or directory
The binary size before:
$ ls -alh qemu-system-x86_64
-rwxr-xr-x. 1 berrange berrange 87M Jul 21 19:39 qemu-system-x86_64
$ strip qemu-system-x86_64
$ ls -alh qemu-system-x86_64
-rwxr-xr-x. 1 berrange berrange 30M Jul 21 19:39 qemu-system-x86_64
and after:
$ ls -alh qemu-system-x86_64
-rwxr-xr-x. 1 berrange berrange 85M Jul 21 19:41 qemu-system-x86_64
$ strip qemu-system-x86_64
$ ls -alh qemu-system-x86_64
-rwxr-xr-x. 1 berrange berrange 29M Jul 21 19:41 qemu-system-x86_64
Signed-off-by: Daniel P. Berrangé <berrange@redhat.com>
Reviewed-by: Markus Armbruster <armbru@redhat.com>
Reviewed-by: Vladimir Sementsov-Ogievskiy <vsementsov@yandex-team.ru>
Message-id: 20250721185452.3016488-1-berrange@redhat.com
Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
---
util/log.c | 20 +++++++++++++++++++-
scripts/tracetool/backend/log.py | 14 +-------------
2 files changed, 20 insertions(+), 14 deletions(-)
diff --git a/util/log.c b/util/log.c
index 58d24de48a..abdcb6b311 100644
--- a/util/log.c
+++ b/util/log.c
@@ -145,10 +145,28 @@ void qemu_log_unlock(FILE *logfile)
void qemu_log(const char *fmt, ...)
{
- FILE *f = qemu_log_trylock();
+ FILE *f;
+ g_autofree const char *timestr = NULL;
+
+ /*
+ * Prepare the timestamp *outside* the logging
+ * lock so it better reflects when the message
+ * was emitted if we are delayed acquiring the
+ * mutex
+ */
+ if (message_with_timestamp) {
+ g_autoptr(GDateTime) dt = g_date_time_new_now_utc();
+ timestr = g_date_time_format_iso8601(dt);
+ }
+
+ f = qemu_log_trylock();
if (f) {
va_list ap;
+ if (timestr) {
+ fprintf(f, "%s ", timestr);
+ }
+
va_start(ap, fmt);
vfprintf(f, fmt, ap);
va_end(ap);
diff --git a/scripts/tracetool/backend/log.py b/scripts/tracetool/backend/log.py
index 5c9d09dd11..eb50ceea34 100644
--- a/scripts/tracetool/backend/log.py
+++ b/scripts/tracetool/backend/log.py
@@ -20,7 +20,6 @@
def generate_h_begin(events, group):
out('#include "qemu/log-for-trace.h"',
- '#include "qemu/error-report.h"',
'')
@@ -32,20 +31,9 @@ def generate_h(event, group):
cond = "trace_event_get_state(%s)" % ("TRACE_" + event.name.upper())
out(' if (%(cond)s && qemu_loglevel_mask(LOG_TRACE)) {',
- ' if (message_with_timestamp) {',
- ' struct timeval _now;',
- ' gettimeofday(&_now, NULL);',
'#line %(event_lineno)d "%(event_filename)s"',
- ' qemu_log("%%d@%%zu.%%06zu:%(name)s " %(fmt)s "\\n",',
- ' qemu_get_thread_id(),',
- ' (size_t)_now.tv_sec, (size_t)_now.tv_usec',
- ' %(argnames)s);',
+ ' qemu_log("%(name)s " %(fmt)s "\\n"%(argnames)s);',
'#line %(out_next_lineno)d "%(out_filename)s"',
- ' } else {',
- '#line %(event_lineno)d "%(event_filename)s"',
- ' qemu_log("%(name)s " %(fmt)s "\\n"%(argnames)s);',
- '#line %(out_next_lineno)d "%(out_filename)s"',
- ' }',
' }',
cond=cond,
event_lineno=event.lineno,
--
2.50.1
^ permalink raw reply related [flat|nested] 5+ messages in thread
* Re: [PULL 0/1] Tracing patches
2025-07-24 14:46 [PULL 0/1] Tracing patches Stefan Hajnoczi
2025-07-24 14:46 ` [PULL 1/1] log: make '-msg timestamp=on' apply to all qemu_log usage Stefan Hajnoczi
@ 2025-07-25 15:25 ` Stefan Hajnoczi
1 sibling, 0 replies; 5+ messages in thread
From: Stefan Hajnoczi @ 2025-07-25 15:25 UTC (permalink / raw)
To: Stefan Hajnoczi
Cc: qemu-devel, Pierrick Bouvier, Mahmoud Mandour, Mads Ynddal,
Alexandre Iooss, Stefan Hajnoczi, Alex Bennée
[-- Attachment #1: Type: text/plain, Size: 116 bytes --]
Applied, thanks.
Please update the changelog at https://wiki.qemu.org/ChangeLog/10.1 for any user-visible changes.
[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 488 bytes --]
^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: [PULL 1/1] log: make '-msg timestamp=on' apply to all qemu_log usage
2025-07-24 14:46 ` [PULL 1/1] log: make '-msg timestamp=on' apply to all qemu_log usage Stefan Hajnoczi
@ 2025-07-25 17:04 ` Pierrick Bouvier
2025-07-25 17:20 ` Daniel P. Berrangé
0 siblings, 1 reply; 5+ messages in thread
From: Pierrick Bouvier @ 2025-07-25 17:04 UTC (permalink / raw)
To: Stefan Hajnoczi, qemu-devel
Cc: Mahmoud Mandour, Mads Ynddal, Alexandre Iooss, Alex Bennée,
Daniel P. Berrangé, Markus Armbruster,
Vladimir Sementsov-Ogievskiy
On 7/24/25 7:46 AM, Stefan Hajnoczi wrote:
> From: Daniel P. Berrangé <berrange@redhat.com>
>
> Currently the tracing 'log' back emits special code to add timestamps
> to trace points sent via qemu_log(). This current impl is a bad design
> for a number of reasons.
>
> * It changes the QEMU headers, such that 'error-report.h' content
> is visible to all files using tracing, but only when the 'log'
> backend is enabled. This has led to build failure bugs as devs
> rarely test without the (default) 'log' backend enabled, and
> CI can't cover every scenario for every trace backend.
>
> * It bloats the trace points definitions which are inlined into
> every probe location due to repeated inlining of timestamp
> formatting code, adding MBs of overhead to QEMU.
>
> * The tracing subsystem should not be treated any differently
> from other users of qemu_log. They all would benefit from
> having timestamps present.
>
> * The timestamp emitted with the tracepoints is in a needlessly
> different format to that used by error_report() in response
> to '-msg timestamp=on'.
>
> This fixes all these issues simply by moving timestamp formatting
> into qemu_log, using the same approach as for error_report.
>
> The code before:
>
> static inline void _nocheck__trace_qcrypto_tls_creds_get_path(void * creds, const char * filename, const char * path)
> {
> if (trace_event_get_state(TRACE_QCRYPTO_TLS_CREDS_GET_PATH) && qemu_loglevel_mask(LOG_TRACE)) {
> if (message_with_timestamp) {
> struct timeval _now;
> gettimeofday(&_now, NULL);
> qemu_log("%d@%zu.%06zu:qcrypto_tls_creds_get_path " "TLS creds path creds=%p filename=%s path=%s" "\n",
> qemu_get_thread_id(),
> (size_t)_now.tv_sec, (size_t)_now.tv_usec
> , creds, filename, path);
> } else {
> qemu_log("qcrypto_tls_creds_get_path " "TLS creds path creds=%p filename=%s path=%s" "\n", creds, filename, path);
> }
> }
> }
>
> and after:
>
> static inline void _nocheck__trace_qcrypto_tls_creds_get_path(void * creds, const char * filename, const char * path)
> {
> if (trace_event_get_state(TRACE_QCRYPTO_TLS_CREDS_GET_PATH) && qemu_loglevel_mask(LOG_TRACE)) {
> qemu_log("qcrypto_tls_creds_get_path " "TLS creds path creds=%p filename=%s path=%s" "\n", creds, filename, path);
> }
> }
>
> The log and error messages before:
>
> $ qemu-system-x86_64 -trace qcrypto* -object tls-creds-x509,id=tls0,dir=$HOME/tls -msg timestamp=on
> 2986097@1753122905.917608:qcrypto_tls_creds_x509_load TLS creds x509 load creds=0x55d925bd9490 dir=/var/home/berrange/tls
> 2986097@1753122905.917621:qcrypto_tls_creds_get_path TLS creds path creds=0x55d925bd9490 filename=ca-cert.pem path=<none>
> 2025-07-21T18:35:05.917626Z qemu-system-x86_64: Unable to access credentials /var/home/berrange/tls/ca-cert.pem: No such file or directory
>
> and after:
>
> $ qemu-system-x86_64 -trace qcrypto* -object tls-creds-x509,id=tls0,dir=$HOME/tls -msg timestamp=on
> 2025-07-21T18:43:28.089797Z qcrypto_tls_creds_x509_load TLS creds x509 load creds=0x55bf5bf12380 dir=/var/home/berrange/tls
> 2025-07-21T18:43:28.089815Z qcrypto_tls_creds_get_path TLS creds path creds=0x55bf5bf12380 filename=ca-cert.pem path=<none>
> 2025-07-21T18:43:28.089819Z qemu-system-x86_64: Unable to access credentials /var/home/berrange/tls/ca-cert.pem: No such file or directory
>
> The binary size before:
>
> $ ls -alh qemu-system-x86_64
> -rwxr-xr-x. 1 berrange berrange 87M Jul 21 19:39 qemu-system-x86_64
> $ strip qemu-system-x86_64
> $ ls -alh qemu-system-x86_64
> -rwxr-xr-x. 1 berrange berrange 30M Jul 21 19:39 qemu-system-x86_64
>
> and after:
>
> $ ls -alh qemu-system-x86_64
> -rwxr-xr-x. 1 berrange berrange 85M Jul 21 19:41 qemu-system-x86_64
> $ strip qemu-system-x86_64
> $ ls -alh qemu-system-x86_64
> -rwxr-xr-x. 1 berrange berrange 29M Jul 21 19:41 qemu-system-x86_64
>
> Signed-off-by: Daniel P. Berrangé <berrange@redhat.com>
> Reviewed-by: Markus Armbruster <armbru@redhat.com>
> Reviewed-by: Vladimir Sementsov-Ogievskiy <vsementsov@yandex-team.ru>
> Message-id: 20250721185452.3016488-1-berrange@redhat.com
> Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
> ---
> util/log.c | 20 +++++++++++++++++++-
> scripts/tracetool/backend/log.py | 14 +-------------
> 2 files changed, 20 insertions(+), 14 deletions(-)
>
> diff --git a/util/log.c b/util/log.c
> index 58d24de48a..abdcb6b311 100644
> --- a/util/log.c
> +++ b/util/log.c
> @@ -145,10 +145,28 @@ void qemu_log_unlock(FILE *logfile)
>
> void qemu_log(const char *fmt, ...)
> {
> - FILE *f = qemu_log_trylock();
> + FILE *f;
> + g_autofree const char *timestr = NULL;
> +
> + /*
> + * Prepare the timestamp *outside* the logging
> + * lock so it better reflects when the message
> + * was emitted if we are delayed acquiring the
> + * mutex
> + */
> + if (message_with_timestamp) {
> + g_autoptr(GDateTime) dt = g_date_time_new_now_utc();
> + timestr = g_date_time_format_iso8601(dt);
> + }
> +
> + f = qemu_log_trylock();
> if (f) {
> va_list ap;
>
> + if (timestr) {
> + fprintf(f, "%s ", timestr);
> + }
> +
> va_start(ap, fmt);
> vfprintf(f, fmt, ap);
> va_end(ap);
> diff --git a/scripts/tracetool/backend/log.py b/scripts/tracetool/backend/log.py
> index 5c9d09dd11..eb50ceea34 100644
> --- a/scripts/tracetool/backend/log.py
> +++ b/scripts/tracetool/backend/log.py
> @@ -20,7 +20,6 @@
>
> def generate_h_begin(events, group):
> out('#include "qemu/log-for-trace.h"',
> - '#include "qemu/error-report.h"',
> '')
>
>
> @@ -32,20 +31,9 @@ def generate_h(event, group):
> cond = "trace_event_get_state(%s)" % ("TRACE_" + event.name.upper())
>
> out(' if (%(cond)s && qemu_loglevel_mask(LOG_TRACE)) {',
> - ' if (message_with_timestamp) {',
> - ' struct timeval _now;',
> - ' gettimeofday(&_now, NULL);',
> '#line %(event_lineno)d "%(event_filename)s"',
> - ' qemu_log("%%d@%%zu.%%06zu:%(name)s " %(fmt)s "\\n",',
> - ' qemu_get_thread_id(),',
> - ' (size_t)_now.tv_sec, (size_t)_now.tv_usec',
> - ' %(argnames)s);',
> + ' qemu_log("%(name)s " %(fmt)s "\\n"%(argnames)s);',
> '#line %(out_next_lineno)d "%(out_filename)s"',
> - ' } else {',
> - '#line %(event_lineno)d "%(event_filename)s"',
> - ' qemu_log("%(name)s " %(fmt)s "\\n"%(argnames)s);',
> - '#line %(out_next_lineno)d "%(out_filename)s"',
> - ' }',
> ' }',
> cond=cond,
> event_lineno=event.lineno,
This broke compilation in debug on linux with all targets due to missing
include. Not a big deal, but it's a bit surprising it passed our CI. Do
we sometimes skip it for "simple" patches?
Fix:
https://lore.kernel.org/qemu-devel/20250725165749.3893240-1-pierrick.bouvier@linaro.org/T/#u
Regards,
Pierrick
^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: [PULL 1/1] log: make '-msg timestamp=on' apply to all qemu_log usage
2025-07-25 17:04 ` Pierrick Bouvier
@ 2025-07-25 17:20 ` Daniel P. Berrangé
0 siblings, 0 replies; 5+ messages in thread
From: Daniel P. Berrangé @ 2025-07-25 17:20 UTC (permalink / raw)
To: Pierrick Bouvier
Cc: Stefan Hajnoczi, qemu-devel, Mahmoud Mandour, Mads Ynddal,
Alexandre Iooss, Alex Bennée, Markus Armbruster,
Vladimir Sementsov-Ogievskiy
On Fri, Jul 25, 2025 at 10:04:50AM -0700, Pierrick Bouvier wrote:
> On 7/24/25 7:46 AM, Stefan Hajnoczi wrote:
> > From: Daniel P. Berrangé <berrange@redhat.com>
> >
> > Currently the tracing 'log' back emits special code to add timestamps
> > to trace points sent via qemu_log(). This current impl is a bad design
> > for a number of reasons.
> >
> > * It changes the QEMU headers, such that 'error-report.h' content
> > is visible to all files using tracing, but only when the 'log'
> > backend is enabled. This has led to build failure bugs as devs
> > rarely test without the (default) 'log' backend enabled, and
> > CI can't cover every scenario for every trace backend.
> >
> > * It bloats the trace points definitions which are inlined into
> > every probe location due to repeated inlining of timestamp
> > formatting code, adding MBs of overhead to QEMU.
> >
> > * The tracing subsystem should not be treated any differently
> > from other users of qemu_log. They all would benefit from
> > having timestamps present.
> >
> > * The timestamp emitted with the tracepoints is in a needlessly
> > different format to that used by error_report() in response
> > to '-msg timestamp=on'.
> >
> > This fixes all these issues simply by moving timestamp formatting
> > into qemu_log, using the same approach as for error_report.
> >
> > The code before:
> >
> > static inline void _nocheck__trace_qcrypto_tls_creds_get_path(void * creds, const char * filename, const char * path)
> > {
> > if (trace_event_get_state(TRACE_QCRYPTO_TLS_CREDS_GET_PATH) && qemu_loglevel_mask(LOG_TRACE)) {
> > if (message_with_timestamp) {
> > struct timeval _now;
> > gettimeofday(&_now, NULL);
> > qemu_log("%d@%zu.%06zu:qcrypto_tls_creds_get_path " "TLS creds path creds=%p filename=%s path=%s" "\n",
> > qemu_get_thread_id(),
> > (size_t)_now.tv_sec, (size_t)_now.tv_usec
> > , creds, filename, path);
> > } else {
> > qemu_log("qcrypto_tls_creds_get_path " "TLS creds path creds=%p filename=%s path=%s" "\n", creds, filename, path);
> > }
> > }
> > }
> >
> > and after:
> >
> > static inline void _nocheck__trace_qcrypto_tls_creds_get_path(void * creds, const char * filename, const char * path)
> > {
> > if (trace_event_get_state(TRACE_QCRYPTO_TLS_CREDS_GET_PATH) && qemu_loglevel_mask(LOG_TRACE)) {
> > qemu_log("qcrypto_tls_creds_get_path " "TLS creds path creds=%p filename=%s path=%s" "\n", creds, filename, path);
> > }
> > }
> >
> > The log and error messages before:
> >
> > $ qemu-system-x86_64 -trace qcrypto* -object tls-creds-x509,id=tls0,dir=$HOME/tls -msg timestamp=on
> > 2986097@1753122905.917608:qcrypto_tls_creds_x509_load TLS creds x509 load creds=0x55d925bd9490 dir=/var/home/berrange/tls
> > 2986097@1753122905.917621:qcrypto_tls_creds_get_path TLS creds path creds=0x55d925bd9490 filename=ca-cert.pem path=<none>
> > 2025-07-21T18:35:05.917626Z qemu-system-x86_64: Unable to access credentials /var/home/berrange/tls/ca-cert.pem: No such file or directory
> >
> > and after:
> >
> > $ qemu-system-x86_64 -trace qcrypto* -object tls-creds-x509,id=tls0,dir=$HOME/tls -msg timestamp=on
> > 2025-07-21T18:43:28.089797Z qcrypto_tls_creds_x509_load TLS creds x509 load creds=0x55bf5bf12380 dir=/var/home/berrange/tls
> > 2025-07-21T18:43:28.089815Z qcrypto_tls_creds_get_path TLS creds path creds=0x55bf5bf12380 filename=ca-cert.pem path=<none>
> > 2025-07-21T18:43:28.089819Z qemu-system-x86_64: Unable to access credentials /var/home/berrange/tls/ca-cert.pem: No such file or directory
> >
> > The binary size before:
> >
> > $ ls -alh qemu-system-x86_64
> > -rwxr-xr-x. 1 berrange berrange 87M Jul 21 19:39 qemu-system-x86_64
> > $ strip qemu-system-x86_64
> > $ ls -alh qemu-system-x86_64
> > -rwxr-xr-x. 1 berrange berrange 30M Jul 21 19:39 qemu-system-x86_64
> >
> > and after:
> >
> > $ ls -alh qemu-system-x86_64
> > -rwxr-xr-x. 1 berrange berrange 85M Jul 21 19:41 qemu-system-x86_64
> > $ strip qemu-system-x86_64
> > $ ls -alh qemu-system-x86_64
> > -rwxr-xr-x. 1 berrange berrange 29M Jul 21 19:41 qemu-system-x86_64
> >
> > Signed-off-by: Daniel P. Berrangé <berrange@redhat.com>
> > Reviewed-by: Markus Armbruster <armbru@redhat.com>
> > Reviewed-by: Vladimir Sementsov-Ogievskiy <vsementsov@yandex-team.ru>
> > Message-id: 20250721185452.3016488-1-berrange@redhat.com
> > Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
> > ---
> > util/log.c | 20 +++++++++++++++++++-
> > scripts/tracetool/backend/log.py | 14 +-------------
> > 2 files changed, 20 insertions(+), 14 deletions(-)
> >
> > diff --git a/util/log.c b/util/log.c
> > index 58d24de48a..abdcb6b311 100644
> > --- a/util/log.c
> > +++ b/util/log.c
> > @@ -145,10 +145,28 @@ void qemu_log_unlock(FILE *logfile)
> > void qemu_log(const char *fmt, ...)
> > {
> > - FILE *f = qemu_log_trylock();
> > + FILE *f;
> > + g_autofree const char *timestr = NULL;
> > +
> > + /*
> > + * Prepare the timestamp *outside* the logging
> > + * lock so it better reflects when the message
> > + * was emitted if we are delayed acquiring the
> > + * mutex
> > + */
> > + if (message_with_timestamp) {
> > + g_autoptr(GDateTime) dt = g_date_time_new_now_utc();
> > + timestr = g_date_time_format_iso8601(dt);
> > + }
> > +
> > + f = qemu_log_trylock();
> > if (f) {
> > va_list ap;
> > + if (timestr) {
> > + fprintf(f, "%s ", timestr);
> > + }
> > +
> > va_start(ap, fmt);
> > vfprintf(f, fmt, ap);
> > va_end(ap);
> > diff --git a/scripts/tracetool/backend/log.py b/scripts/tracetool/backend/log.py
> > index 5c9d09dd11..eb50ceea34 100644
> > --- a/scripts/tracetool/backend/log.py
> > +++ b/scripts/tracetool/backend/log.py
> > @@ -20,7 +20,6 @@
> > def generate_h_begin(events, group):
> > out('#include "qemu/log-for-trace.h"',
> > - '#include "qemu/error-report.h"',
> > '')
> > @@ -32,20 +31,9 @@ def generate_h(event, group):
> > cond = "trace_event_get_state(%s)" % ("TRACE_" + event.name.upper())
> > out(' if (%(cond)s && qemu_loglevel_mask(LOG_TRACE)) {',
> > - ' if (message_with_timestamp) {',
> > - ' struct timeval _now;',
> > - ' gettimeofday(&_now, NULL);',
> > '#line %(event_lineno)d "%(event_filename)s"',
> > - ' qemu_log("%%d@%%zu.%%06zu:%(name)s " %(fmt)s "\\n",',
> > - ' qemu_get_thread_id(),',
> > - ' (size_t)_now.tv_sec, (size_t)_now.tv_usec',
> > - ' %(argnames)s);',
> > + ' qemu_log("%(name)s " %(fmt)s "\\n"%(argnames)s);',
> > '#line %(out_next_lineno)d "%(out_filename)s"',
> > - ' } else {',
> > - '#line %(event_lineno)d "%(event_filename)s"',
> > - ' qemu_log("%(name)s " %(fmt)s "\\n"%(argnames)s);',
> > - '#line %(out_next_lineno)d "%(out_filename)s"',
> > - ' }',
> > ' }',
> > cond=cond,
> > event_lineno=event.lineno,
>
> This broke compilation in debug on linux with all targets due to missing
> include. Not a big deal, but it's a bit surprising it passed our CI. Do we
> sometimes skip it for "simple" patches?
Actually this patch did not break this. Xen was already broken for any
scenario which turned off the 'log' trace backend, which is what prompted
creation of this patch. See the thread here:
https://lists.nongnu.org/archive/html/qemu-devel/2025-07/msg04831.html
WRT CI, the Xen issue only exists if building against fairly new Xen
versions, and have turned off the log trace backend. Given limited
resources we can't test every possible build scenario in our CI, and
this is unfortunately an example of this limitation.
This patch will avoid such bugs recurring in future by ensuring that
configure arg choices won't affect whether error-report.h is included
by default or not.
> Fix: https://lore.kernel.org/qemu-devel/20250725165749.3893240-1-pierrick.bouvier@linaro.org/T/#u
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 :|
^ permalink raw reply [flat|nested] 5+ messages in thread
end of thread, other threads:[~2025-07-25 17:22 UTC | newest]
Thread overview: 5+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2025-07-24 14:46 [PULL 0/1] Tracing patches Stefan Hajnoczi
2025-07-24 14:46 ` [PULL 1/1] log: make '-msg timestamp=on' apply to all qemu_log usage Stefan Hajnoczi
2025-07-25 17:04 ` Pierrick Bouvier
2025-07-25 17:20 ` Daniel P. Berrangé
2025-07-25 15:25 ` [PULL 0/1] Tracing patches Stefan Hajnoczi
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).