012842c0 | 21-Jul-2025 |
Daniel P. Berrangé <berrange@redhat.com> |
log: make '-msg timestamp=on' apply to all qemu_log usage
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
log: make '-msg timestamp=on' apply to all qemu_log usage
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>
show more ...
|
09612de7 | 06-Jan-2021 |
Daniel P. Berrangé <berrange@redhat.com> |
tracetool: also strip %l and %ll from systemtap format strings
All variables are 64-bit and so %l / %ll are not required, and the latter is actually invalid:
$ sudo stap -e 'probe begin{printf ("
tracetool: also strip %l and %ll from systemtap format strings
All variables are 64-bit and so %l / %ll are not required, and the latter is actually invalid:
$ sudo stap -e 'probe begin{printf ("BEGIN")}' -I . parse error: invalid or missing conversion specifier saw: operator ',' at ./qemu-system-x86_64-log.stp:15118:101 source: printf("%d@%d vhost_vdpa_set_log_base dev: %p base: 0x%x size: %llu refcnt: %d fd: %d log: %p\n", pid(), gettimeofday_ns(), dev, base, size, refcnt, fd, log)
^
Signed-off-by: Daniel P. Berrangé <berrange@redhat.com> Reviewed-by: Laurent Vivier <lvivier@redhat.com> Reviewed-by: Philippe Mathieu-Daudé <philmd@redhat.com> Tested-by: Laurent Vivier <lvivier@redhat.com> Message-id: 20210106130239.1004729-1-berrange@redhat.com
[Fixed "simiarly" typo found by Laurent Vivier <lvivier@redhat.com> --Stefan]
Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
show more ...
|
7fb48c0e | 27-Aug-2020 |
Stefan Hajnoczi <stefanha@redhat.com> |
tracetool: show trace-events filename/lineno in fmt string errors
The compiler encounters trace event format strings in generated code. Format strings are error-prone and therefore clear compiler er
tracetool: show trace-events filename/lineno in fmt string errors
The compiler encounters trace event format strings in generated code. Format strings are error-prone and therefore clear compiler errors are important.
Use the #line directive to show the trace-events filename and line number in format string errors: https://gcc.gnu.org/onlinedocs/gcc-10.2.0/cpp/Line-Control.html
For example, if the cpu_in trace event's %u is changed to %p the following error is reported:
trace-events:29:18: error: format ‘%p’ expects argument of type ‘void *’, but argument 7 has type ‘unsigned int’ [-Werror=format=]
Line 29 in trace-events is where cpu_in is defined. This works for any trace-events file in the QEMU source tree and the correct path is displayed.
Unfortunately there does not seem to be a way to set the column, so "18" is not the right character on that line.
Suggested-by: Peter Maydell <peter.maydell@linaro.org> Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com> Reviewed-by: Peter Maydell <peter.maydell@linaro.org> Message-Id: <20200827142915.108730-5-stefanha@redhat.com>
show more ...
|
4e66c9ef | 27-Aug-2020 |
Stefan Hajnoczi <stefanha@redhat.com> |
tracetool: add input filename and line number to Event
Store the input filename and line number in Event.
A later patch will use this to improve error messages.
Signed-off-by: Stefan Hajnoczi <ste
tracetool: add input filename and line number to Event
Store the input filename and line number in Event.
A later patch will use this to improve error messages.
Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com> Reviewed-by: Philippe Mathieu-Daudé <f4bug@amsat.org> Reviewed-by: Peter Maydell <peter.maydell@linaro.org> Message-Id: <20200827142915.108730-4-stefanha@redhat.com>
show more ...
|
294170c1 | 27-Aug-2020 |
Stefan Hajnoczi <stefanha@redhat.com> |
tracetool: add out_lineno and out_next_lineno to out()
Make the output file line number and next line number available to out().
A later patch will use this to improve error messages.
Signed-off-b
tracetool: add out_lineno and out_next_lineno to out()
Make the output file line number and next line number available to out().
A later patch will use this to improve error messages.
Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com> Reviewed-by: Peter Maydell <peter.maydell@linaro.org> Message-Id: <20200827142915.108730-3-stefanha@redhat.com>
show more ...
|
5e7477bc | 17-Jul-2020 |
Roman Bolshakov <r.bolshakov@yadro.com> |
scripts/tracetool: Use void pointer for vcpu
dtrace on macOS complains that CPUState * is used for a few probes:
dtrace: failed to compile script trace-dtrace-root.dtrace: line 130: syntax error
scripts/tracetool: Use void pointer for vcpu
dtrace on macOS complains that CPUState * is used for a few probes:
dtrace: failed to compile script trace-dtrace-root.dtrace: line 130: syntax error near "CPUState"
A comment in scripts/tracetool/__init__.py mentions that:
We only want to allow standard C types or fixed sized integer types. We don't want QEMU specific types as we can't assume trace backends can resolve all the typedefs
Fixes: 3d211d9f4dbee ("trace: Add 'vcpu' event property to trace guest vCPU") Reviewed-by: Daniel P. Berrangé <berrange@redhat.com> Reviewed-by: Stefan Hajnoczi <stefanha@redhat.com> Signed-off-by: Roman Bolshakov <r.bolshakov@yadro.com> Message-id: 20200717093517.73397-3-r.bolshakov@yadro.com Cc: Cameron Esfahani <dirty@apple.com> Signed-off-by: Roman Bolshakov <r.bolshakov@yadro.com> Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
show more ...
|