From 1a96dd472c37ceeefc0d488cb7722c6714d2f0b7 Mon Sep 17 00:00:00 2001 From: Paolo Bonzini Date: Fri, 15 Apr 2011 15:23:59 +0200 Subject: [PATCH 1/6] tracetool: allow ) in trace output string Be greedy in matching the trailing "\)*" pattern. Otherwise, all the text in the trace string up to the last closed parenthesis is taken as part of the prototype. Signed-off-by: Paolo Bonzini Signed-off-by: Stefan Hajnoczi --- scripts/tracetool | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/scripts/tracetool b/scripts/tracetool index 412f695863..9912f368d2 100755 --- a/scripts/tracetool +++ b/scripts/tracetool @@ -51,7 +51,7 @@ get_args() { local args args=${1#*\(} - args=${args%\)*} + args=${args%%\)*} echo "$args" } From b4548fcc0314f5e118ed45b5774e9cd99f9a97d3 Mon Sep 17 00:00:00 2001 From: Stefan Hajnoczi Date: Thu, 14 Apr 2011 18:11:00 +0100 Subject: [PATCH 2/6] trace: Remove %s in grlib trace events Trace events cannot use %s in their format strings because trace backends vary in how they can deference pointers (if at all). Recording const char * values is not meaningful if their contents are not recorded too. Change grlib trace events that rely on strings so that they communicate similar information without using strings. A follow-up patch explains this limitation and updates docs/tracing.txt. Signed-off-by: Stefan Hajnoczi --- hw/grlib_apbuart.c | 2 +- hw/grlib_gptimer.c | 29 ++++++++++++++--------------- hw/grlib_irqmp.c | 4 ++-- trace-events | 10 +++++----- 4 files changed, 22 insertions(+), 23 deletions(-) diff --git a/hw/grlib_apbuart.c b/hw/grlib_apbuart.c index 101b150aa5..169a56eb1b 100644 --- a/hw/grlib_apbuart.c +++ b/hw/grlib_apbuart.c @@ -133,7 +133,7 @@ grlib_apbuart_writel(void *opaque, target_phys_addr_t addr, uint32_t value) break; } - trace_grlib_apbuart_unknown_register("write", addr); + trace_grlib_apbuart_writel_unknown(addr, value); } static CPUReadMemoryFunc * const grlib_apbuart_read[] = { diff --git a/hw/grlib_gptimer.c b/hw/grlib_gptimer.c index 596a9000a1..99e90336b6 100644 --- a/hw/grlib_gptimer.c +++ b/hw/grlib_gptimer.c @@ -165,15 +165,15 @@ static uint32_t grlib_gptimer_readl(void *opaque, target_phys_addr_t addr) /* Unit registers */ switch (addr) { case SCALER_OFFSET: - trace_grlib_gptimer_readl(-1, "scaler:", unit->scaler); + trace_grlib_gptimer_readl(-1, addr, unit->scaler); return unit->scaler; case SCALER_RELOAD_OFFSET: - trace_grlib_gptimer_readl(-1, "reload:", unit->reload); + trace_grlib_gptimer_readl(-1, addr, unit->reload); return unit->reload; case CONFIG_OFFSET: - trace_grlib_gptimer_readl(-1, "config:", unit->config); + trace_grlib_gptimer_readl(-1, addr, unit->config); return unit->config; default: @@ -189,17 +189,16 @@ static uint32_t grlib_gptimer_readl(void *opaque, target_phys_addr_t addr) switch (timer_addr) { case COUNTER_OFFSET: value = ptimer_get_count(unit->timers[id].ptimer); - trace_grlib_gptimer_readl(id, "counter value:", value); + trace_grlib_gptimer_readl(id, addr, value); return value; case COUNTER_RELOAD_OFFSET: value = unit->timers[id].reload; - trace_grlib_gptimer_readl(id, "reload value:", value); + trace_grlib_gptimer_readl(id, addr, value); return value; case CONFIG_OFFSET: - trace_grlib_gptimer_readl(id, "scaler value:", - unit->timers[id].config); + trace_grlib_gptimer_readl(id, addr, unit->timers[id].config); return unit->timers[id].config; default: @@ -208,7 +207,7 @@ static uint32_t grlib_gptimer_readl(void *opaque, target_phys_addr_t addr) } - trace_grlib_gptimer_unknown_register("read", addr); + trace_grlib_gptimer_readl(-1, addr, 0); return 0; } @@ -226,19 +225,19 @@ grlib_gptimer_writel(void *opaque, target_phys_addr_t addr, uint32_t value) case SCALER_OFFSET: value &= 0xFFFF; /* clean up the value */ unit->scaler = value; - trace_grlib_gptimer_writel(-1, "scaler:", unit->scaler); + trace_grlib_gptimer_writel(-1, addr, unit->scaler); return; case SCALER_RELOAD_OFFSET: value &= 0xFFFF; /* clean up the value */ unit->reload = value; - trace_grlib_gptimer_writel(-1, "reload:", unit->reload); + trace_grlib_gptimer_writel(-1, addr, unit->reload); grlib_gptimer_set_scaler(unit, value); return; case CONFIG_OFFSET: /* Read Only (disable timer freeze not supported) */ - trace_grlib_gptimer_writel(-1, "config (Read Only):", 0); + trace_grlib_gptimer_writel(-1, addr, 0); return; default: @@ -253,18 +252,18 @@ grlib_gptimer_writel(void *opaque, target_phys_addr_t addr, uint32_t value) /* GPTimer registers */ switch (timer_addr) { case COUNTER_OFFSET: - trace_grlib_gptimer_writel(id, "counter:", value); + trace_grlib_gptimer_writel(id, addr, value); unit->timers[id].counter = value; grlib_gptimer_enable(&unit->timers[id]); return; case COUNTER_RELOAD_OFFSET: - trace_grlib_gptimer_writel(id, "reload:", value); + trace_grlib_gptimer_writel(id, addr, value); unit->timers[id].reload = value; return; case CONFIG_OFFSET: - trace_grlib_gptimer_writel(id, "config:", value); + trace_grlib_gptimer_writel(id, addr, value); if (value & GPTIMER_INT_PENDING) { /* clear pending bit */ @@ -297,7 +296,7 @@ grlib_gptimer_writel(void *opaque, target_phys_addr_t addr, uint32_t value) } - trace_grlib_gptimer_unknown_register("write", addr); + trace_grlib_gptimer_writel(-1, addr, value); } static CPUReadMemoryFunc * const grlib_gptimer_read[] = { diff --git a/hw/grlib_irqmp.c b/hw/grlib_irqmp.c index f47c491a48..b8738fc04d 100644 --- a/hw/grlib_irqmp.c +++ b/hw/grlib_irqmp.c @@ -220,7 +220,7 @@ static uint32_t grlib_irqmp_readl(void *opaque, target_phys_addr_t addr) return state->extended[cpu]; } - trace_grlib_irqmp_unknown_register("read", addr); + trace_grlib_irqmp_readl_unknown(addr); return 0; } @@ -308,7 +308,7 @@ grlib_irqmp_writel(void *opaque, target_phys_addr_t addr, uint32_t value) return; } - trace_grlib_irqmp_unknown_register("write", addr); + trace_grlib_irqmp_writel_unknown(addr, value); } static CPUReadMemoryFunc * const grlib_irqmp_read[] = { diff --git a/trace-events b/trace-events index 703b745bc4..8272c86c6a 100644 --- a/trace-events +++ b/trace-events @@ -235,19 +235,19 @@ disable grlib_gptimer_disabled(int id, uint32_t config) "timer:%d Timer disable disable grlib_gptimer_restart(int id, uint32_t reload) "timer:%d reload val: 0x%x" disable grlib_gptimer_set_scaler(uint32_t scaler, uint32_t freq) "scaler:0x%x freq: 0x%x" disable grlib_gptimer_hit(int id) "timer:%d HIT" -disable grlib_gptimer_readl(int id, const char *s, uint32_t val) "timer:%d %s 0x%x" -disable grlib_gptimer_writel(int id, const char *s, uint32_t val) "timer:%d %s 0x%x" -disable grlib_gptimer_unknown_register(const char *op, uint64_t val) "%s unknown register 0x%"PRIx64"" +disable grlib_gptimer_readl(int id, uint64_t addr, uint32_t val) "timer:%d addr 0x%"PRIx64" 0x%x" +disable grlib_gptimer_writel(int id, uint64_t addr, uint32_t val) "timer:%d addr 0x%"PRIx64" 0x%x" # hw/grlib_irqmp.c disable grlib_irqmp_check_irqs(uint32_t pend, uint32_t force, uint32_t mask, uint32_t lvl1, uint32_t lvl2) "pend:0x%04x force:0x%04x mask:0x%04x lvl1:0x%04x lvl0:0x%04x\n" disable grlib_irqmp_ack(int intno) "interrupt:%d" disable grlib_irqmp_set_irq(int irq) "Raise CPU IRQ %d" -disable grlib_irqmp_unknown_register(const char *op, uint64_t val) "%s unknown register 0x%"PRIx64"" +disable grlib_irqmp_readl_unknown(uint64_t addr) "addr 0x%"PRIx64"" +disable grlib_irqmp_writel_unknown(uint64_t addr, uint32_t value) "addr 0x%"PRIx64" value 0x%x" # hw/grlib_apbuart.c disable grlib_apbuart_event(int event) "event:%d" -disable grlib_apbuart_unknown_register(const char *op, uint64_t val) "%s unknown register 0x%"PRIx64"" +disable grlib_apbuart_writel_unknown(uint64_t addr, uint32_t value) "addr 0x%"PRIx64" value 0x%x" # hw/leon3.c disable leon3_set_irq(int intno) "Set CPU IRQ %d" From e6a750aab57e4dccefd6291dba4fee6b9b3bf9ee Mon Sep 17 00:00:00 2001 From: Stefan Hajnoczi Date: Thu, 14 Apr 2011 18:24:50 +0100 Subject: [PATCH 3/6] docs: Trace events must not expect pointer dereferencing Signed-off-by: Stefan Hajnoczi --- docs/tracing.txt | 5 +++++ 1 file changed, 5 insertions(+) diff --git a/docs/tracing.txt b/docs/tracing.txt index f15069c96b..905a0837db 100644 --- a/docs/tracing.txt +++ b/docs/tracing.txt @@ -69,6 +69,11 @@ Trace events should use types as follows: cannot include all user-defined struct declarations and it is therefore necessary to use void * for pointers to structs. + Pointers (including char *) cannot be dereferenced easily (or at all) in + some trace backends. If pointers are used, ensure they are meaningful by + themselves and do not assume the data they point to will be traced. Do + not pass in string arguments. + * For everything else, use primitive scalar types (char, int, long) with the appropriate signedness. From 7b92e5bc6d7a61e9e7669b679a87480a6d1ad1a6 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Llu=C3=ADs?= Date: Wed, 6 Apr 2011 20:33:56 +0200 Subject: [PATCH 4/6] docs/tracing.txt: minor documentation fixes MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Signed-off-by: Lluís Vilanova Signed-off-by: Stefan Hajnoczi --- docs/tracing.txt | 18 +++++++++--------- 1 file changed, 9 insertions(+), 9 deletions(-) diff --git a/docs/tracing.txt b/docs/tracing.txt index 905a0837db..c99a0f27cf 100644 --- a/docs/tracing.txt +++ b/docs/tracing.txt @@ -26,14 +26,14 @@ for debugging, profiling, and observing execution. == Trace events == -There is a set of static trace events declared in the trace-events source +There is a set of static trace events declared in the "trace-events" source file. Each trace event declaration names the event, its arguments, and the format string which can be used for pretty-printing: qemu_malloc(size_t size, void *ptr) "size %zu ptr %p" qemu_free(void *ptr) "ptr %p" -The trace-events file is processed by the tracetool script during build to +The "trace-events" file is processed by the "tracetool" script during build to generate code for the trace events. Trace events are invoked directly from source code like this: @@ -52,10 +52,10 @@ source code like this: === Declaring trace events === -The tracetool script produces the trace.h header file which is included by +The "tracetool" script produces the trace.h header file which is included by every source file that uses trace events. Since many source files include -trace.h, it uses a minimum of types and other header files included to keep -the namespace clean and compile times and dependencies down. +trace.h, it uses a minimum of types and other header files included to keep the +namespace clean and compile times and dependencies down. Trace events should use types as follows: @@ -110,10 +110,10 @@ portability macros, ensure they are preceded and followed by double quotes: == Trace backends == -The tracetool script automates tedious trace event code generation and also +The "tracetool" script automates tedious trace event code generation and also keeps the trace event declarations independent of the trace backend. The trace events are not tightly coupled to a specific trace backend, such as LTTng or -SystemTap. Support for trace backends can be added by extending the tracetool +SystemTap. Support for trace backends can be added by extending the "tracetool" script. The trace backend is chosen at configure time and only one trace backend can @@ -181,12 +181,12 @@ events at runtime inside QEMU: ==== Analyzing trace files ==== The "simple" backend produces binary trace files that can be formatted with the -simpletrace.py script. The script takes the trace-events file and the binary +simpletrace.py script. The script takes the "trace-events" file and the binary trace: ./simpletrace.py trace-events trace-12345 -You must ensure that the same trace-events file was used to build QEMU, +You must ensure that the same "trace-events" file was used to build QEMU, otherwise trace event declarations may have changed and output will not be consistent. From fa2d480a20345b8f10881712dbcf3f5f48b5905b Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Llu=C3=ADs?= Date: Wed, 6 Apr 2011 20:34:03 +0200 Subject: [PATCH 5/6] trace: [ust] fix generation of 'trace.c' on events without args MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Signed-off-by: Lluís Vilanova Signed-off-by: Stefan Hajnoczi --- scripts/tracetool | 7 ++++--- 1 file changed, 4 insertions(+), 3 deletions(-) diff --git a/scripts/tracetool b/scripts/tracetool index 9912f368d2..2155a57df2 100755 --- a/scripts/tracetool +++ b/scripts/tracetool @@ -338,6 +338,7 @@ linetoc_ust() name=$(get_name "$1") args=$(get_args "$1") argnames=$(get_argnames "$1", ",") + [ -z "$argnames" ] || argnames=", $argnames" fmt=$(get_fmt "$1") cat < Date: Wed, 6 Apr 2011 20:34:11 +0200 Subject: [PATCH 6/6] trace: [trace-events] fix print formats in some events MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Signed-off-by: Lluís Vilanova Signed-off-by: Stefan Hajnoczi --- trace-events | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/trace-events b/trace-events index 8272c86c6a..77c96a5978 100644 --- a/trace-events +++ b/trace-events @@ -254,8 +254,8 @@ disable leon3_set_irq(int intno) "Set CPU IRQ %d" disable leon3_reset_irq(int intno) "Reset CPU IRQ %d" # spice-qemu-char.c -disable spice_vmc_write(ssize_t out, int len) "spice wrottn %lu of requested %zd" -disable spice_vmc_read(int bytes, int len) "spice read %lu of requested %zd" +disable spice_vmc_write(ssize_t out, int len) "spice wrottn %zd of requested %d" +disable spice_vmc_read(int bytes, int len) "spice read %d of requested %d" disable spice_vmc_register_interface(void *scd) "spice vmc registered interface %p" disable spice_vmc_unregister_interface(void *scd) "spice vmc unregistered interface %p"