summary refs log tree commit diff stats
path: root/scripts/tracetool/backend/log.py (follow)
Commit message (Collapse)AuthorAgeFilesLines
* log: make '-msg timestamp=on' apply to all qemu_log usageDaniel P. Berrangé2025-07-241-13/+1
| | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | 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>
* tracetool: removed the unused vcpu propertyTanish Desai2025-07-221-5/+1
| | | | | | | | | | | | The vcpu property is no longer used in these backends. Removing it avoids unnecessary checks and simplifies the code generation for these trace backends. Reviewed-by: Stefan Hajnoczi <stefanha@redhat.com> Reviewed-by: Alex Bennée <alex.bennee@linaro.org> Signed-off-by: Tanish Desai <tanishdesai37@gmail.com> Message-id: 20250722114352.3624-1-tanishdesai37@gmail.com Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
* meson: fix Windows buildoltolm2025-06-161-3/+1
| | | | | | | | | | | | The build fails on Windows. Replace calls to Unix programs like ´cat´, ´sed´ and ´true´ with calls to ´python´ and wrap calls to ´os.path.relpath´ in try-except because it can fail when the two paths are on different drives. Make sure to convert the Windows paths to Unix paths to prevent warnings in generated files. Signed-off-by: oltolm <oleg.tolmatcev@gmail.com> Message-id: 20250612221521.1109-2-oleg.tolmatcev@gmail.com Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
* tracetool: use relative paths for '#line' preprocessor directivesThomas De Schampheleire2023-04-241-1/+3
| | | | | | | | | | The event filename is an absolute path. Convert it to a relative path when writing '#line' directives, to preserve reproducibility of the generated output when different base paths are used. Signed-off-by: Thomas De Schampheleire <thomas.de_schampheleire@nokia.com> Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com> Message-Id: <20230406080045.21696-1-thomas.de_schampheleire@nokia.com>
* trace: make the 'log' backend timestamp configurableStefan Hajnoczi2021-02-011-6/+13
| | | | | | | | | | | | | | Timestamps in tracing output can be distracting. Make it possible to control tid/timestamp printing with -msg timestamp=on|off. The default is no tid/timestamps. Previously they were always printed. Suggested-by: BALATON Zoltan <balaton@eik.bme.hu> Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com> Tested-by: Philippe Mathieu-Daudé <philmd@redhat.com> Tested-by: BALATON Zoltan <balaton@eik.bme.hu> Reviewed-by: Philippe Mathieu-Daudé <philmd@redhat.com> Message-id: 20210125113507.224287-3-stefanha@redhat.com Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
* tracetool: show trace-events filename/lineno in fmt string errorsStefan Hajnoczi2021-01-041-0/+4
| | | | | | | | | | | | | | | | | | | | | | | | | | | 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>
* scripts/tracetool: Update maintainer email addressPhilippe Mathieu-Daudé2020-06-241-1/+1
| | | | | | | | | | | | | | | | | There is an effort in progress to generate a QEMU Python package. As I'm not sure this old email is still valid, update it to not produce package with broken maintainer email. Patch created mechanically by running: $ sed -i 's,\(__email__ *= "\)stefanha@linux.vnet.ibm.com",\1stefanha@redhat.com",' \ $(git grep -l 'email.*stefanha@linux.vnet.ibm.com') Signed-off-by: Philippe Mathieu-Daudé <philmd@redhat.com> Reviewed-by: John Snow <jsnow@redhat.com> Message-id: 20200511082816.696-1-philmd@redhat.com Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
* scripts/tracetool: Remove shebang headerPhilippe Mathieu-Daudé2020-02-071-1/+0
| | | | | | | | | | | | | | | | | Patch created mechanically by running: $ chmod 644 $(git grep -lF '#!/usr/bin/env python' \ | xargs grep -L 'if __name__.*__main__') $ sed -i "/^#\!\/usr\/bin\/\(env\ \)\?python.\?$/d" \ $(git grep -lF '#!/usr/bin/env python' \ | xargs grep -L 'if __name__.*__main__') Reported-by: Vladimir Sementsov-Ogievskiy <vsementsov@virtuozzo.com> Suggested-by: Stefan Hajnoczi <stefanha@redhat.com> Acked-by: Stefan Hajnoczi <stefanha@redhat.com> Acked-by: Paolo Bonzini <pbonzini@redhat.com> Message-Id: <20200130163232.10446-9-philmd@redhat.com> Signed-off-by: Philippe Mathieu-Daudé <philmd@redhat.com>
* tracetool: Include thread id information in log backendFabiano Rosas2018-12-121-1/+1
| | | | | | | | | | | | | | | | | | | | | | | | | | Currently the log backend prints the process id of QEMU at the start of each output line, but since threads share the same PID there is no clear distinction between their outputs. Having the thread id present in the log makes it easier to see when output comes from different threads. E.g.: 12423@1538597569.672527:qemu_mutex_lock waiting on mutex 0x1103ee60 (/root/qemu/util/main-loop.c:236) ... 12430@1538597569.503928:qemu_mutex_unlock released mutex 0x1103ee60 (/root/qemu/cpus.c:1238) 12431@1538597569.503937:qemu_mutex_locked taken mutex 0x1103ee60 (/root/qemu/cpus.c:1257) ^here In the above, 12423 is the main process id and 12430 & 12431 are the two vcpu threads. (qemu) info cpus * CPU #0: thread_id=12430 CPU #1: thread_id=12431 Suggested-by: Murilo Opsfelder Araujo <muriloo@linux.ibm.com> Signed-off-by: Fabiano Rosas <farosas@linux.ibm.com> Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
* trace: Fix format string for the struct timeval members casted to size_tPhilippe Mathieu-Daudé2018-06-291-1/+1
| | | | | | | | | | | | | | | | | | | | | | | This fixes when using GCC with -Wformat-signedness: migration/trace.h: In function ‘_nocheck__trace_dirty_bitmap_load_success’: migration/trace.h:6368:24: error: format ‘%zd’ expects argument of type ‘signed size_t’, but argument 3 has type ‘long unsigned int’ [-Werror=format=] qemu_log("%d@%zd.%06zd:dirty_bitmap_load_success " "" "\n", ~~^ %ld migration/trace.h:6370:18: (size_t)_now.tv_sec, (size_t)_now.tv_usec ~~~~~~~~~~~~~~~~~~~ migration/trace.h:6368:30: error: format ‘%zd’ expects argument of type ‘signed size_t’, but argument 4 has type ‘long unsigned int’ [-Werror=format=] qemu_log("%d@%zd.%06zd:dirty_bitmap_load_success " "" "\n", ~~~~^ %06ld migration/trace.h:6370:39: (size_t)_now.tv_sec, (size_t)_now.tv_usec ~~~~~~~~~~~~~~~~~~~~ Signed-off-by: Philippe Mathieu-Daudé <f4bug@amsat.org> Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
* log-for-trace.h: Split out parts of log.h used by trace.hPeter Maydell2018-03-121-7/+6
| | | | | | | | | | | | | | | | | | | | | | A persistent build problem we see is where a source file accidentally omits the #include of log.h. This slips through local developer testing because if you configure with the default (log) trace backend trace.h will pull in log.h for you. Compilation fails only if some other backend is selected. To make this error cause a compile failure regardless of the configured trace backend, split out the parts of log.h that trace.h requires into a new log-for-trace.h header. Since almost all manual uses of the log.h functions will use constants or functions which aren't in log-for-trace.h, this will let us catch missing #include "qemu/log.h" more consistently. Signed-off-by: Peter Maydell <peter.maydell@linaro.org> Reviewed-by: Eric Blake <eblake@redhat.com> Reviewed-by: Richard Henderson <richard.henderson@linaro.org> Message-id: 20180213140029.8308-1-peter.maydell@linaro.org Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
* trace: add TRACE_<event>_BACKEND_DSTATE()Stefan Hajnoczi2017-08-011-0/+5
| | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | QEMU keeps track of trace event enabled/disabled state and provides monitor commands to inspect and modify the "dstate". SystemTap and LTTng UST maintain independent enabled/disabled states for each trace event, the other backends rely on QEMU dstate. Introduce a new per-event macro that combines backend-specific dstate like this: #define TRACE_MY_EVENT_BACKEND_DSTATE() ( \ QEMU_MY_EVENT_ENABLED() || /* SystemTap */ \ tracepoint_enabled(qemu, my_event) /* LTTng UST */ || \ false) This will be used to extend trace_event_get_state() in the next patch. [Daniel Berrange pointed out that QEMU_MY_EVENT_ENABLED() must be true by default, not false. This way events will fire even if the DTrace implementation does not implement the SystemTap semaphores feature. Ubuntu Precise uses lttng-ust-dev 2.0.2 which does not have tracepoint_enabled(), so we need a compatibility wrapper to keep Travis builds passing. --Stefan] Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com> Message-id: 20170731140718.22010-2-stefanha@redhat.com Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com> fixup! trace: add TRACE_<event>_BACKEND_DSTATE()
* trace: [tcg, trivial] Re-align generated codeLluís Vilanova2017-07-171-9/+10
| | | | | | | | | | Last patch removed a nesting level in generated code. Re-align all code generated by backends to be 4-column aligned. Signed-off-by: Lluís Vilanova <vilanova@ac.upc.edu> Signed-off-by: Emilio G. Cota <cota@braap.org> Message-id: 149915824586.6295.17820926011082409033.stgit@frigg.lan Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
* trace: introduce a formal group name for trace eventsDaniel P. Berrange2016-10-121-2/+2
| | | | | | | | | | | | | | | | | | | | | | | The declarations in the generated-tracers.h file are assuming there's only ever going to be one instance of this header, as they are not namespaced. When we have one header per event group, if a single source file needs to include multiple sets of trace events, the symbols will all clash. This change thus introduces a '--group NAME' arg to the 'tracetool' program. This will cause all the symbols in the generated header files to be given a unique namespace. If no group is given, the group name 'common' is used, which is suitable for the current usage where there is only one global trace-events file used for code generation. Reviewed-by: Stefan Hajnoczi <stefanha@redhat.com> Signed-off-by: Daniel P. Berrange <berrange@redhat.com> Reviewed-by: Lluís Vilanova <vilanova@ac.upc.edu> Message-id: 1475588159-30598-21-git-send-email-berrange@redhat.com Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
* trace: remove duplicate control.h includes in generated-tracers.hDaniel P. Berrange2016-10-121-2/+1
| | | | | | | | | | | | The format/h.py file adds an include for control.h to generated-tracers.h. ftrace, log and syslog, then add more duplicate includes for control.h. Reviewed-by: Stefan Hajnoczi <stefanha@redhat.com> Reviewed-by: Lluís Vilanova <vilanova@ac.upc.edu> Signed-off-by: Daniel P. Berrange <berrange@redhat.com> Message-id: 1475588159-30598-8-git-send-email-berrange@redhat.com Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
* trace: Conditionally trace events based on their per-vCPU stateLluís Vilanova2016-07-181-10/+16
| | | | | | | | | | | | Events with the 'vcpu' property are conditionally emitted according to their per-vCPU state. Other events are emitted normally based on their global tracing state. Note that the per-vCPU condition check applies to all tracing backends. Signed-off-by: Lluís Vilanova <vilanova@ac.upc.edu> Reviewed-by: Stefan Hajnoczi <stefanha@redhat.com> Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
* Clean up includes some moreMarkus Armbruster2016-03-221-5/+1
| | | | | | | | | Manually drop redundant includes that scripts/clean-includes misses, e.g. because they're hidden in generator programs, or they use the wrong kind of delimiter. Signed-off-by: Markus Armbruster <armbru@redhat.com> Signed-off-by: Paolo Bonzini <pbonzini@redhat.com>
* trace: convert stderr backend to logPaolo Bonzini2016-02-031-0/+48
[Also update .travis.yml --enable-trace-backends=stderr --Stefan] Signed-off-by: Paolo Bonzini <pbonzini@redhat.com> Signed-off-by: Denis V. Lunev <den@openvz.org> Acked-by: Christian Borntraeger <borntraeger@de.ibm.com> Message-id: 1452174932-28657-10-git-send-email-den@openvz.org Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>