[Qemu-devel] [PULL 0/6] Tracing patches

[Qemu-devel] [PULL 0/6] Tracing patches

[Stefan Hajnoczi]

The following changes since commit b0b36e5d2e4c8a96c2f6dbc0981a9fd0cde111d8:

  doc: fix slirp description (2011-04-25 23:10:04 +0200)

are available in the git repository at:
  git://repo.or.cz/qemu/stefanha.git tracing

Lluís (3):
      docs/tracing.txt: minor documentation fixes
      trace: [ust] fix generation of 'trace.c' on events without args
      trace: [trace-events] fix print formats in some events

Paolo Bonzini (1):
      tracetool: allow ) in trace output string

Stefan Hajnoczi (2):
      trace: Remove %s in grlib trace events
      docs: Trace events must not expect pointer dereferencing

 docs/tracing.txt   |   23 ++++++++++++++---------
 hw/grlib_apbuart.c |    2 +-
 hw/grlib_gptimer.c |   29 ++++++++++++++---------------
 hw/grlib_irqmp.c   |    4 ++--
 scripts/tracetool  |    9 +++++----
 trace-events       |   14 +++++++-------
 6 files changed, 43 insertions(+), 38 deletions(-)

[Qemu-devel] [PATCH 1/6] tracetool: allow ) in trace output string

[Stefan Hajnoczi]

From: Paolo Bonzini <pbonzini@redhat.com>

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 <pbonzini@redhat.com>
Signed-off-by: Stefan Hajnoczi <stefanha@linux.vnet.ibm.com>
---
 scripts/tracetool |    2 +-
 1 files changed, 1 insertions(+), 1 deletions(-)

diff --git a/scripts/tracetool b/scripts/tracetool
index 412f695..9912f36 100755
--- a/scripts/tracetool
+++ b/scripts/tracetool
@@ -51,7 +51,7 @@ get_args()
 {
     local args
     args=${1#*\(}
-    args=${args%\)*}
+    args=${args%%\)*}
     echo "$args"
 }
 
-- 
1.7.4.1

[Qemu-devel] [PATCH 2/6] trace: Remove %s in grlib trace events

[Stefan Hajnoczi]

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 <stefanha@linux.vnet.ibm.com>
---
 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 101b150..169a56e 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 596a900..99e9033 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 f47c491..b8738fc 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 703b745..8272c86 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"
-- 
1.7.4.1

[Qemu-devel] [PATCH 3/6] docs: Trace events must not expect pointer dereferencing

[Stefan Hajnoczi]

Signed-off-by: Stefan Hajnoczi <stefanha@linux.vnet.ibm.com>
---
 docs/tracing.txt |    5 +++++
 1 files changed, 5 insertions(+), 0 deletions(-)

diff --git a/docs/tracing.txt b/docs/tracing.txt
index f15069c..905a083 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.
 
-- 
1.7.4.1

[Qemu-devel] [PATCH 4/6] docs/tracing.txt: minor documentation fixes

[Stefan Hajnoczi]

From: Lluís <xscript@gmx.net>

Signed-off-by: Lluís Vilanova <vilanova@ac.upc.edu>
Signed-off-by: Stefan Hajnoczi <stefanha@linux.vnet.ibm.com>
---
 docs/tracing.txt |   18 +++++++++---------
 1 files changed, 9 insertions(+), 9 deletions(-)

diff --git a/docs/tracing.txt b/docs/tracing.txt
index 905a083..c99a0f2 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.
 
-- 
1.7.4.1

[Qemu-devel] [PATCH 5/6] trace: [ust] fix generation of 'trace.c' on events without args

[Stefan Hajnoczi]

From: Lluís <xscript@gmx.net>

Signed-off-by: Lluís Vilanova <vilanova@ac.upc.edu>
Signed-off-by: Stefan Hajnoczi <stefanha@linux.vnet.ibm.com>
---
 scripts/tracetool |    7 ++++---
 1 files changed, 4 insertions(+), 3 deletions(-)

diff --git a/scripts/tracetool b/scripts/tracetool
index 9912f36..2155a57 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 <<EOF
@@ -345,7 +346,7 @@ DEFINE_TRACE(ust_$name);
 
 static void ust_${name}_probe($args)
 {
-    trace_mark(ust, $name, "$fmt", $argnames);
+    trace_mark(ust, $name, "$fmt"$argnames);
 }
 EOF
 
@@ -488,7 +489,7 @@ EOF
         cat <<EOF
   $arg = \$arg$i;
 EOF
-	i="$((i+1))"
+        i="$((i+1))"
     done
 
     cat <<EOF
@@ -585,7 +586,7 @@ tracetostap()
        exit 1
     fi
     if [ -z "$probeprefix" ]; then
-	probeprefix="qemu.$targettype.$targetarch";
+        probeprefix="qemu.$targettype.$targetarch";
     fi
     echo "/* This file is autogenerated by tracetool, do not edit. */"
     convert stap
-- 
1.7.4.1

[Qemu-devel] [PATCH 6/6] trace: [trace-events] fix print formats in some events

[Stefan Hajnoczi]

From: Lluís <xscript@gmx.net>

Signed-off-by: Lluís Vilanova <vilanova@ac.upc.edu>
Signed-off-by: Stefan Hajnoczi <stefanha@linux.vnet.ibm.com>
---
 trace-events |    4 ++--
 1 files changed, 2 insertions(+), 2 deletions(-)

diff --git a/trace-events b/trace-events
index 8272c86..77c96a5 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"
 
-- 
1.7.4.1

Re: [Qemu-devel] [PULL 0/6] Tracing patches

[Anthony Liguori]

On 04/26/2011 07:25 AM, Stefan Hajnoczi wrote:
> The following changes since commit b0b36e5d2e4c8a96c2f6dbc0981a9fd0cde111d8:
>
>    doc: fix slirp description (2011-04-25 23:10:04 +0200)
>
> are available in the git repository at:
>    git://repo.or.cz/qemu/stefanha.git tracing

Pulled.  Thanks.

Regards,

Anthony Liguori

>
> Lluís (3):
>        docs/tracing.txt: minor documentation fixes
>        trace: [ust] fix generation of 'trace.c' on events without args
>        trace: [trace-events] fix print formats in some events
>
> Paolo Bonzini (1):
>        tracetool: allow ) in trace output string
>
> Stefan Hajnoczi (2):
>        trace: Remove %s in grlib trace events
>        docs: Trace events must not expect pointer dereferencing
>
>   docs/tracing.txt   |   23 ++++++++++++++---------
>   hw/grlib_apbuart.c |    2 +-
>   hw/grlib_gptimer.c |   29 ++++++++++++++---------------
>   hw/grlib_irqmp.c   |    4 ++--
>   scripts/tracetool  |    9 +++++----
>   trace-events       |   14 +++++++-------
>   6 files changed, 43 insertions(+), 38 deletions(-)
>

Re: [Qemu-devel] [PATCH 4/6] docs/tracing.txt: minor documentation fixes

[Brad Hards]

On Tue, 26 Apr 2011 10:26:01 pm Stefan Hajnoczi wrote:
> -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
Would it read better if it said "There are a set..." (i.e. "are" instead of 
"is")?

Brad

Re: [Qemu-devel] docs/tracing.txt: minor documentation fixes

[Mike D. Day]

On 27/04/11 06:46 +1000, Brad Hards wrote:
> On Tue, 26 Apr 2011 10:26:01 pm Stefan Hajnoczi wrote:
> > -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
> Would it read better if it said "There are a set..." (i.e. "are" instead of 
> "is")?

I belive it's correct: there is a set. The alternative would be "there
are static trace events."

Mike

-- 
Mike Day | ultra@ncultra.org | "Endurance is a Virtue"