Patchwork apic: convert debug printf statements to tracepoints

login
register
mail settings
Submitter Blue Swirl
Date Oct. 17, 2010, 7:55 a.m.
Message ID <AANLkTinUw8-tGxiNN2K=bz3ZZEFUZrLn=YSHGm2mUWfc@mail.gmail.com>
Download mbox | patch
Permalink /patch/68066/
State New
Headers show

Comments

Blue Swirl - Oct. 17, 2010, 7:55 a.m.
Replace debug printf statements with tracepoints.

Cc: Stefan Hajnoczi <stefanha@linux.vnet.ibm.com>
Signed-off-by: Blue Swirl <blauwirbel@gmail.com>
---
However, when I tried to use coalescing_apic.bin (triggers coalescing
events, see [1]), simpletrace.py chokes:

./qemu -bios ./ -monitor stdio coalescing_apic.bin -trace file=foo
QEMU 0.13.50 monitor - type 'help' for more information
(qemu) info trace
Event 25 : 3 7 0 0 0
Event 25 : 3 7 0 0 0
Event 25 : 3 7 0 0 0
Event 25 : 3 7 0 0 0
Event 25 : 3 7 0 0 0
Event 25 : 3 7 0 0 0
Event 30 : 350 5700 0 0 0
Event 30 : f0 100 0 0 0
Event 26 : 0 0 0 70 0
Event 33 : 1 0 0 0 0
Event 30 : b0 0 0 0 0
Event 26 : 0 0 0 70 0
Event 33 : 2 0 0 0 0
Event 30 : b0 0 0 0 0
Event 26 : 0 0 0 70 0
Event 33 : 3 0 0 0 0
Event 30 : b0 0 0 0 0
Event 26 : 0 0 0 70 0
Event 33 : 4 0 0 0 0
Event 30 : b0 0 0 0 0
Event 26 : 0 0 0 70 0
Event 33 : 5 0 0 0 0
Event 30 : b0 0 0 0 0
Event 26 : 0 0 0 70 0
Event 33 : 6 0 0 0 0
Event 30 : b0 0 0 0 0
Event 26 : 0 0 0 70 0
Event 33 : 7 0 0 0 0
Event 30 : b0 0 0 0 0
(qemu) q
$ /src/qemu/simpletrace.py /src/qemu/trace-events foo
apic_local_deliver 0.000 vector=0x3 lvt=0x7
apic_local_deliver 23.527 vector=0x3 lvt=0x7
apic_local_deliver 3.921 vector=0x3 lvt=0x7
apic_local_deliver 2.940 vector=0x3 lvt=0x7
apic_local_deliver 2.941 vector=0x3 lvt=0x7
apic_local_deliver 4.411 vector=0x3 lvt=0x7
apic_get_irq_delivered 3706.866 apic_irq_delivered=0x350
apic_get_irq_delivered 2.450 apic_irq_delivered=0xf0
apic_deliver_irq 266872.726 dest=0x0 dest_mode=0x0 delivery_mode=0x0
vector_num=0x70 polarity=0x0 trigger_mode=0x0
Traceback (most recent call last):
  File "/src/qemu/simpletrace.py", line 93, in <module>
    print formatter.format_record(rec)
  File "/src/qemu/simpletrace.py", line 81, in format_record
    event = self.events[rec[0]]
KeyError: 33

[1] http://article.gmane.org/gmane.comp.emulators.qemu/72414

 hw/apic.c    |   48 ++++++++++++++++++------------------------------
 trace-events |   12 ++++++++++++
 2 files changed, 30 insertions(+), 30 deletions(-)

+# coalescing
+apic_reset_irq_delivered(int apic_irq_delivered) "old coalescing %d"
+apic_get_irq_delivered(int apic_irq_delivered) "returning coalescing %d"
+apic_set_irq(int apic_irq_delivered) "coalescing %d"
Stefan Hajnoczi - Oct. 18, 2010, 12:42 p.m.
Thanks for pointing out this problem with simpletrace.py.  There are two
issues:

1. The regular expression used by simpletrace.py to parse trace event
   declarations cannot cope with concatenated string literals.
2. Format strings must begin and end with double quotes.  This was previously
   undocumented but is necessary because cpp is not run over trace-events, so
   parsing the strings and portability macros is non-trivial.

The follow-up patches fix the regex, add documentation for the format string
double quotes requirement, and update your patch.

simpletrace.py should work for the coalesced apic trace events now.

Stefan

Patch

diff --git a/hw/apic.c b/hw/apic.c
index d686b51..63d62c7 100644
--- a/hw/apic.c
+++ b/hw/apic.c
@@ -21,23 +21,7 @@ 
 #include "qemu-timer.h"
 #include "host-utils.h"
 #include "sysbus.h"
-
-//#define DEBUG_APIC
-//#define DEBUG_COALESCING
-
-#ifdef DEBUG_APIC
-#define DPRINTF(fmt, ...)                                       \
-    do { printf("apic: " fmt , ## __VA_ARGS__); } while (0)
-#else
-#define DPRINTF(fmt, ...)
-#endif
-
-#ifdef DEBUG_COALESCING
-#define DPRINTF_C(fmt, ...)                                     \
-    do { printf("apic: " fmt , ## __VA_ARGS__); } while (0)
-#else
-#define DPRINTF_C(fmt, ...)
-#endif
+#include "trace.h"

 /* APIC Local Vector Table */
 #define APIC_LVT_TIMER   0
@@ -168,8 +152,8 @@  static void apic_local_deliver(APICState *s, int vector)
     uint32_t lvt = s->lvt[vector];
     int trigger_mode;

-    DPRINTF("%s: vector %d delivery mode %d\n", __func__, vector,
-            (lvt >> 8) & 7);
+    trace_apic_local_deliver(vector, (lvt >> 8) & 7);
+
     if (lvt & APIC_LVT_MASKED)
         return;

@@ -300,9 +284,9 @@  void apic_deliver_irq(uint8_t dest, uint8_t dest_mode,
 {
     uint32_t deliver_bitmask[MAX_APIC_WORDS];

-    DPRINTF("%s: dest %d dest_mode %d delivery_mode %d vector %d"
-            " polarity %d trigger_mode %d\n", __func__, dest, dest_mode,
-            delivery_mode, vector_num, polarity, trigger_mode);
+    trace_apic_deliver_irq(dest, dest_mode, delivery_mode, vector_num,
+                           polarity, trigger_mode);
+
     apic_get_delivery_bitmask(deliver_bitmask, dest, dest_mode);
     apic_bus_deliver(deliver_bitmask, delivery_mode, vector_num, polarity,
                      trigger_mode);
@@ -312,7 +296,8 @@  void cpu_set_apic_base(DeviceState *d, uint64_t val)
 {
     APICState *s = DO_UPCAST(APICState, busdev.qdev, d);

-    DPRINTF("cpu_set_apic_base: %016" PRIx64 "\n", val);
+    trace_cpu_set_apic_base(val);
+
     if (!s)
         return;
     s->apicbase = (val & 0xfffff000) |
@@ -329,8 +314,8 @@  uint64_t cpu_get_apic_base(DeviceState *d)
 {
     APICState *s = DO_UPCAST(APICState, busdev.qdev, d);

-    DPRINTF("cpu_get_apic_base: %016" PRIx64 "\n",
-            s ? (uint64_t)s->apicbase: 0);
+    trace_cpu_get_apic_base(s ? (uint64_t)s->apicbase: 0);
+
     return s ? s->apicbase : 0;
 }

@@ -402,20 +387,23 @@  static void apic_update_irq(APICState *s)

 void apic_reset_irq_delivered(void)
 {
-    DPRINTF_C("%s: old coalescing %d\n", __func__, apic_irq_delivered);
+    trace_apic_reset_irq_delivered(apic_irq_delivered);
+
     apic_irq_delivered = 0;
 }

 int apic_get_irq_delivered(void)
 {
-    DPRINTF_C("%s: returning coalescing %d\n", __func__, apic_irq_delivered);
+    trace_apic_get_irq_delivered(apic_irq_delivered);
+
     return apic_irq_delivered;
 }

 static void apic_set_irq(APICState *s, int vector_num, int trigger_mode)
 {
     apic_irq_delivered += !get_bit(s->irr, vector_num);
-    DPRINTF_C("%s: coalescing %d\n", __func__, apic_irq_delivered);
+
+    trace_apic_set_irq(apic_irq_delivered);

     set_bit(s->irr, vector_num);
     if (trigger_mode)
@@ -769,7 +757,7 @@  static uint32_t apic_mem_readl(void *opaque,
target_phys_addr_t addr)
         val = 0;
         break;
     }
-    DPRINTF("read: " TARGET_FMT_plx " = %08x\n", addr, val);
+    trace_apic_mem_readl(addr, val);
     return val;
 }

@@ -805,7 +793,7 @@  static void apic_mem_writel(void *opaque,
target_phys_addr_t addr, uint32_t val)
     }
     s = DO_UPCAST(APICState, busdev.qdev, d);

-    DPRINTF("write: " TARGET_FMT_plx " = %08x\n", addr, val);
+    trace_apic_mem_writel(addr, val);

     switch(index) {
     case 0x02:
diff --git a/trace-events b/trace-events
index 4300178..1cac99a 100644
--- a/trace-events
+++ b/trace-events
@@ -69,3 +69,15 @@  disable cpu_out(unsigned int addr, unsigned int
val) "addr %#x value %u"
 # balloon.c
 # Since requests are raised via monitor, not many tracepoints are needed.
 disable balloon_event(void *opaque, unsigned long addr) "opaque %p addr %lu"
+
+# hw/apic.c
+apic_local_deliver(int vector, uint32_t lvt) "vector %d delivery mode %d"
+apic_deliver_irq(uint8_t dest, uint8_t dest_mode, uint8_t
delivery_mode, uint8_t vector_num, uint8_t polarity, uint8_t
trigger_mode) "dest %d dest_mode %d delivery_mode %d vector %d
polarity %d trigger_mode %d"
+cpu_set_apic_base(uint64_t val) "%016" PRIx64
+cpu_get_apic_base(uint64_t val) "%016" PRIx64
+apic_mem_readl(uint64_t addr, uint32_t val)  PRIx64 " = %08x"
+apic_mem_writel(uint64_t addr, uint32_t val) PRIx64 " = %08x"