On Mon, Jul 21, 2025 at 07:54:52PM +0100, Daniel P. Berrangé wrote:
> 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é <berra...@redhat.com>
> ---
> scripts/tracetool/backend/log.py | 14 +-------------
> util/log.c | 20 +++++++++++++++++++-
> 2 files changed, 20 insertions(+), 14 deletions(-)Thanks, applied to my tracing tree: https://gitlab.com/stefanha/qemu/commits/tracing Stefan
signature.asc
Description: PGP signature
