If emitting a trace event requires computation for the parameters passed to the probe, the callers should guard that computation with trace_event_by_state_backends(), which is a macro expanding to the a check of the "TRACE_...._DSTATE()" expression. For the log backend this should include a check for LOG_TRACE being present in the configured log level.
Signed-off-by: Daniel P. Berrangé <[email protected]> --- scripts/tracetool/backend/log.py | 24 +++++++++++++++++----- tests/tracetool/all.h | 34 +++++++++++++++++++------------- tests/tracetool/all.rs | 16 +++++++++++---- tests/tracetool/log.h | 20 +++++++++---------- tests/tracetool/log.rs | 6 ++++-- 5 files changed, 65 insertions(+), 35 deletions(-) diff --git a/scripts/tracetool/backend/log.py b/scripts/tracetool/backend/log.py index 577ee158584..4a622dd4dcb 100644 --- a/scripts/tracetool/backend/log.py +++ b/scripts/tracetool/backend/log.py @@ -16,7 +16,6 @@ PUBLIC = True -CHECK_TRACE_EVENT_GET_STATE = True def generate_h_begin(events, group): @@ -29,11 +28,13 @@ def generate_h(event, group): if len(event.args) > 0: argnames = ", " + argnames - out(' if (qemu_loglevel_mask(LOG_TRACE)) {', + out(' if (trace_event_get_state(%(event_id)s) &&', + ' qemu_loglevel_mask(LOG_TRACE)) {', '#line %(event_lineno)d "%(event_filename)s"', ' qemu_log("%(name)s " %(fmt)s "\\n"%(argnames)s);', '#line %(out_next_lineno)d "%(out_filename)s"', - ' }', + ' }', + event_id="TRACE_" + event.name.upper(), event_lineno=event.lineno, event_filename=event.filename, name=event.name, @@ -41,10 +42,23 @@ def generate_h(event, group): argnames=argnames) +def generate_h_backend_dstate(event, group): + out(' (trace_event_get_state_dynamic_by_id(%(event_id)s) && \\', + ' qemu_loglevel_mask(LOG_TRACE)) || \\', + event_id="TRACE_" + event.name.upper()) + def generate_rs(event, group): - out(' let format_string = c"%(fmt)s\\n";', + out(' if trace_event_state_is_enabled(unsafe { _%(event_id)s_DSTATE}) {', + ' let format_string = c"%(fmt)s\\n";', ' if (unsafe { bindings::qemu_loglevel } & bindings::LOG_TRACE) != 0 {', ' unsafe { bindings::qemu_log(format_string.as_ptr() as *const c_char, %(args)s);}', ' }', + ' }', fmt=expand_format_string(event.fmt, event.name + " "), - args=event.args.rust_call_varargs()) + args=event.args.rust_call_varargs(), + event_id="TRACE_" + event.name.upper()) + +def generate_rs_backend_dstate(event, group): + out(' unsafe { (bindings::qemu_loglevel & bindings::LOG_TRACE) != 0 &&', + ' trace_event_state_is_enabled(_%(event_id)s_DSTATE) } ||', + event_id="TRACE_" + event.name.upper()) diff --git a/tests/tracetool/all.h b/tests/tracetool/all.h index 5627c1d8930..0ae2598eb1d 100644 --- a/tests/tracetool/all.h +++ b/tests/tracetool/all.h @@ -44,6 +44,8 @@ void _simple_trace_test_wibble(void *context, int value); #define TRACE_TEST_BLAH_BACKEND_DSTATE() ( \ QEMU_TEST_BLAH_ENABLED() || \ + (trace_event_get_state_dynamic_by_id(TRACE_TEST_BLAH) && \ + qemu_loglevel_mask(LOG_TRACE)) || \ tracepoint_enabled(qemu, test_blah) || \ trace_event_get_state_dynamic_by_id(TRACE_TEST_BLAH) || \ false) @@ -51,25 +53,28 @@ void _simple_trace_test_wibble(void *context, int value); static inline void trace_test_blah(void *context, const char *filename) { QEMU_TEST_BLAH(context, filename); + if (trace_event_get_state(TRACE_TEST_BLAH) && + qemu_loglevel_mask(LOG_TRACE)) { +#line 4 "trace-events" + qemu_log("test_blah " "Blah context=%p filename=%s" "\n", context, filename); +#line 61 "all.h" + } tracepoint(qemu, test_blah, context, filename); if (trace_event_get_state(TRACE_TEST_BLAH)) { #line 4 "trace-events" ftrace_write("test_blah " "Blah context=%p filename=%s" "\n" , context, filename); -#line 59 "all.h" - if (qemu_loglevel_mask(LOG_TRACE)) { -#line 4 "trace-events" - qemu_log("test_blah " "Blah context=%p filename=%s" "\n", context, filename); -#line 63 "all.h" - } +#line 67 "all.h" _simple_trace_test_blah(context, filename); #line 4 "trace-events" syslog(LOG_INFO, "test_blah " "Blah context=%p filename=%s" , context, filename); -#line 68 "all.h" +#line 71 "all.h" } } #define TRACE_TEST_WIBBLE_BACKEND_DSTATE() ( \ QEMU_TEST_WIBBLE_ENABLED() || \ + (trace_event_get_state_dynamic_by_id(TRACE_TEST_WIBBLE) && \ + qemu_loglevel_mask(LOG_TRACE)) || \ tracepoint_enabled(qemu, test_wibble) || \ trace_event_get_state_dynamic_by_id(TRACE_TEST_WIBBLE) || \ false) @@ -77,20 +82,21 @@ static inline void trace_test_blah(void *context, const char *filename) static inline void trace_test_wibble(void *context, int value) { QEMU_TEST_WIBBLE(context, value); + if (trace_event_get_state(TRACE_TEST_WIBBLE) && + qemu_loglevel_mask(LOG_TRACE)) { +#line 5 "trace-events" + qemu_log("test_wibble " "Wibble context=%p value=%d" "\n", context, value); +#line 90 "all.h" + } tracepoint(qemu, test_wibble, context, value); if (trace_event_get_state(TRACE_TEST_WIBBLE)) { #line 5 "trace-events" ftrace_write("test_wibble " "Wibble context=%p value=%d" "\n" , context, value); -#line 85 "all.h" - if (qemu_loglevel_mask(LOG_TRACE)) { -#line 5 "trace-events" - qemu_log("test_wibble " "Wibble context=%p value=%d" "\n", context, value); -#line 89 "all.h" - } +#line 96 "all.h" _simple_trace_test_wibble(context, value); #line 5 "trace-events" syslog(LOG_INFO, "test_wibble " "Wibble context=%p value=%d" , context, value); -#line 94 "all.h" +#line 100 "all.h" } } #endif /* TRACE_TESTSUITE_GENERATED_TRACERS_H */ diff --git a/tests/tracetool/all.rs b/tests/tracetool/all.rs index f48bdf4aab5..448ebce8281 100644 --- a/tests/tracetool/all.rs +++ b/tests/tracetool/all.rs @@ -37,6 +37,8 @@ fn trace_event_state_is_enabled(dstate: u8) -> bool { pub fn trace_test_blah_enabled() -> bool { (unsafe {qemu_test_blah_semaphore.get().read_volatile()}) != 0 || + unsafe { (bindings::qemu_loglevel & bindings::LOG_TRACE) != 0 && + trace_event_state_is_enabled(_TRACE_TEST_BLAH_DSTATE) } || trace_event_state_is_enabled(unsafe { _TRACE_TEST_BLAH_DSTATE}) || false } @@ -47,12 +49,14 @@ pub fn trace_test_blah(_context: *mut (), _filename: &std::ffi::CStr) { ::trace::probe!(qemu, test_blah, _context, _filename.as_ptr()); if trace_event_state_is_enabled(unsafe { _TRACE_TEST_BLAH_DSTATE}) { - let format_string = c"test_blah Blah context=%p filename=%s\n"; - unsafe {bindings::ftrace_write(format_string.as_ptr() as *const c_char, _context /* as *mut () */, _filename.as_ptr());} let format_string = c"test_blah Blah context=%p filename=%s\n"; if (unsafe { bindings::qemu_loglevel } & bindings::LOG_TRACE) != 0 { unsafe { bindings::qemu_log(format_string.as_ptr() as *const c_char, _context /* as *mut () */, _filename.as_ptr());} } + } + if trace_event_state_is_enabled(unsafe { _TRACE_TEST_BLAH_DSTATE}) { + let format_string = c"test_blah Blah context=%p filename=%s\n"; + unsafe {bindings::ftrace_write(format_string.as_ptr() as *const c_char, _context /* as *mut () */, _filename.as_ptr());} extern "C" { fn _simple_trace_test_blah(_context: *mut (), _filename: *const std::ffi::c_char); } unsafe { _simple_trace_test_blah(_context, _filename.as_ptr()); } let format_string = c"test_blah Blah context=%p filename=%s"; @@ -65,6 +69,8 @@ pub fn trace_test_blah(_context: *mut (), _filename: &std::ffi::CStr) pub fn trace_test_wibble_enabled() -> bool { (unsafe {qemu_test_wibble_semaphore.get().read_volatile()}) != 0 || + unsafe { (bindings::qemu_loglevel & bindings::LOG_TRACE) != 0 && + trace_event_state_is_enabled(_TRACE_TEST_WIBBLE_DSTATE) } || trace_event_state_is_enabled(unsafe { _TRACE_TEST_WIBBLE_DSTATE}) || false } @@ -75,12 +81,14 @@ pub fn trace_test_wibble(_context: *mut (), _value: std::ffi::c_int) { ::trace::probe!(qemu, test_wibble, _context, _value); if trace_event_state_is_enabled(unsafe { _TRACE_TEST_WIBBLE_DSTATE}) { - let format_string = c"test_wibble Wibble context=%p value=%d\n"; - unsafe {bindings::ftrace_write(format_string.as_ptr() as *const c_char, _context /* as *mut () */, _value /* as std::ffi::c_int */);} let format_string = c"test_wibble Wibble context=%p value=%d\n"; if (unsafe { bindings::qemu_loglevel } & bindings::LOG_TRACE) != 0 { unsafe { bindings::qemu_log(format_string.as_ptr() as *const c_char, _context /* as *mut () */, _value /* as std::ffi::c_int */);} } + } + if trace_event_state_is_enabled(unsafe { _TRACE_TEST_WIBBLE_DSTATE}) { + let format_string = c"test_wibble Wibble context=%p value=%d\n"; + unsafe {bindings::ftrace_write(format_string.as_ptr() as *const c_char, _context /* as *mut () */, _value /* as std::ffi::c_int */);} extern "C" { fn _simple_trace_test_wibble(_context: *mut (), _value: std::ffi::c_int); } unsafe { _simple_trace_test_wibble(_context, _value); } let format_string = c"test_wibble Wibble context=%p value=%d"; diff --git a/tests/tracetool/log.h b/tests/tracetool/log.h index ff510d54908..9957a854c00 100644 --- a/tests/tracetool/log.h +++ b/tests/tracetool/log.h @@ -16,32 +16,32 @@ extern uint8_t _TRACE_TEST_WIBBLE_DSTATE; #define TRACE_TEST_BLAH_BACKEND_DSTATE() ( \ - trace_event_get_state_dynamic_by_id(TRACE_TEST_BLAH) || \ + (trace_event_get_state_dynamic_by_id(TRACE_TEST_BLAH) && \ + qemu_loglevel_mask(LOG_TRACE)) || \ false) static inline void trace_test_blah(void *context, const char *filename) { - if (trace_event_get_state(TRACE_TEST_BLAH)) { - if (qemu_loglevel_mask(LOG_TRACE)) { + if (trace_event_get_state(TRACE_TEST_BLAH) && + qemu_loglevel_mask(LOG_TRACE)) { #line 4 "trace-events" qemu_log("test_blah " "Blah context=%p filename=%s" "\n", context, filename); -#line 29 "log.h" - } +#line 30 "log.h" } } #define TRACE_TEST_WIBBLE_BACKEND_DSTATE() ( \ - trace_event_get_state_dynamic_by_id(TRACE_TEST_WIBBLE) || \ + (trace_event_get_state_dynamic_by_id(TRACE_TEST_WIBBLE) && \ + qemu_loglevel_mask(LOG_TRACE)) || \ false) static inline void trace_test_wibble(void *context, int value) { - if (trace_event_get_state(TRACE_TEST_WIBBLE)) { - if (qemu_loglevel_mask(LOG_TRACE)) { + if (trace_event_get_state(TRACE_TEST_WIBBLE) && + qemu_loglevel_mask(LOG_TRACE)) { #line 5 "trace-events" qemu_log("test_wibble " "Wibble context=%p value=%d" "\n", context, value); -#line 44 "log.h" - } +#line 45 "log.h" } } #endif /* TRACE_TESTSUITE_GENERATED_TRACERS_H */ diff --git a/tests/tracetool/log.rs b/tests/tracetool/log.rs index 0f052bb2c9c..1adb38597e3 100644 --- a/tests/tracetool/log.rs +++ b/tests/tracetool/log.rs @@ -27,7 +27,8 @@ fn trace_event_state_is_enabled(dstate: u8) -> bool { #[allow(dead_code)] pub fn trace_test_blah_enabled() -> bool { - trace_event_state_is_enabled(unsafe { _TRACE_TEST_BLAH_DSTATE}) || + unsafe { (bindings::qemu_loglevel & bindings::LOG_TRACE) != 0 && + trace_event_state_is_enabled(_TRACE_TEST_BLAH_DSTATE) } || false } @@ -47,7 +48,8 @@ pub fn trace_test_blah(_context: *mut (), _filename: &std::ffi::CStr) #[allow(dead_code)] pub fn trace_test_wibble_enabled() -> bool { - trace_event_state_is_enabled(unsafe { _TRACE_TEST_WIBBLE_DSTATE}) || + unsafe { (bindings::qemu_loglevel & bindings::LOG_TRACE) != 0 && + trace_event_state_is_enabled(_TRACE_TEST_WIBBLE_DSTATE) } || false } -- 2.55.0
