Monitor support QEMU trace framework

simpletrace.c +0 -0

index 2fec4d3..239ae3f 100644

simpletrace.c +2 -0

+    }
+}

tracetool +1 -0

index 9ea9c08..2c73bab 100755
@@ -130,6 +130,7 @@ void trace2(TraceEvent event, unsigned long x1, unsigned long x2);
 void trace3(TraceEvent event, unsigned long x1, unsigned long x2, unsigned long x3);
 void trace4(TraceEvent event, unsigned long x1, unsigned long x2, unsigned long x3, unsigned long x4);
 void trace5(TraceEvent event, unsigned long x1, unsigned long x2, unsigned long x3, unsigned long x4, unsigned long x5);
+void do_info_trace(Monitor *mon);
 EOF
 
     simple_event_num=0

Quoted 9 lines · Prerna Saxena

simpletrace.c +1 -0

index 2fec4d3..239ae3f 100644
@@ -62,3 +62,16 @@ void trace4(TraceEvent event, unsigned long x1, unsigned long x2, unsigned long
  void trace5(TraceEvent event, unsigned long x1, unsigned long x2, unsigned long x3, unsigned long x4, unsigned long x5) {
      trace(event, x1, x2, x3, x4, x5);
  }
+

simpletrace.c void trace4(TraceEvent event, unsigned long x1, unsigned long x2, unsigned long · line 70

Quoted 5 lines

simpletrace.c +5 -0

+void do_info_trace(Monitor *mon)
+{
+    unsigned int i, max_idx;
+
+    max_idx = trace_idx ? trace_idx : TRACE_BUF_LEN;

trace_idx is always in the range [0, TRACE_BUF_LEN). There is no need to perform this test.

simpletrace.c void trace4(TraceEvent event, unsigned long x1, unsigned long x2, unsigned long · line 72

Quoted 3 lines

simpletrace.c +2 -0

+
+    for (i=0; i<max_idx ;i++) {

Whitespace "i=0; i<max_idx ;i++". "i = 0; i< max_idx; i++" is pretty common across QEMU.

simpletrace.c void trace4(TraceEvent event, unsigned long x1, unsigned long x2, unsigned long · line 75

Quoted 3 lines

simpletrace.c +3 -0

+        monitor_printf(mon, "Event %ld : %ld %ld %ld %ld %ld\n",
+                          trace_buf[i].event, trace_buf[i].x1, trace_buf[i].x2,
+                            trace_buf[i].x3, trace_buf[i].x4, trace_buf[i].x5);

Getting only numeric output is the limitation of a binary trace. It would probably be possible to pretty-print without much additional code by using the format strings from the trace-events file.

I think the numeric dump is good for now though. Hex is more compact than decimal and would make pointers easier to spot. Want to change this?

Quoted 17 lines

simpletrace.c +2 -0

+    }
+}

tracetool +1 -0

index 9ea9c08..2c73bab 100755
@@ -130,6 +130,7 @@ void trace2(TraceEvent event, unsigned long x1, unsigned long x2);
  void trace3(TraceEvent event, unsigned long x1, unsigned long x2, unsigned long x3);
  void trace4(TraceEvent event, unsigned long x1, unsigned long x2, unsigned long x3, unsigned long x4);
  void trace5(TraceEvent event, unsigned long x1, unsigned long x2, unsigned long x3, unsigned long x4, unsigned long x5);
+void do_info_trace(Monitor *mon);
  EOF
 
      simple_event_num=0

@@ -289,6 +290,7 @@ tracetoh()
  #define TRACE_H
 

tracetool tracetoh() · line 293

Quoted 2 lines

tracetool +1 -0

  #include "qemu-common.h"
+#include "monitor.h"

qemu-common.h forward-declares Monitor, I don't think you need monitor.h.

Stefan

Hi Stefan, Jan,
Thanks for taking a look.

Quoted 14 lines · Stefan Hajnoczi

Quoted 12 lines · Prerna Saxena

simpletrace.c +0 -0

index 2fec4d3..239ae3f 100644
@@ -62,3 +62,16 @@ void trace4(TraceEvent event, unsigned long x1,

unsigned long x2, unsigned long
 void trace5(TraceEvent event, unsigned long x1, unsigned long x2, unsigned long x3, unsigned long x4, unsigned long x5) { trace(event, x1, x2, x3, x4, x5);
 }
+

Quoted 8 lines

simpletrace.c void trace4(TraceEvent event, unsigned long x1, unsigned long x2, unsigned long · line 70

Quoted 5 lines

simpletrace.c +5 -0

+void do_info_trace(Monitor *mon)
+{
+    unsigned int i, max_idx;
+
+    max_idx = trace_idx ? trace_idx : TRACE_BUF_LEN;

trace_idx is always in the range [0, TRACE_BUF_LEN).  There is no need to perform this test.

I only display the logged contents in the trace buffer (till trace_idx) , and not the entire trace buffer. Only when the index is full that the entire buffer is displayed.

Quoted 10 lines

Quoted 5 lines

+        monitor_printf(mon, "Event %ld : %ld %ld %ld %ld %ld\n",
+                          trace_buf[i].event, trace_buf[i].x1, trace_buf[i].x2,
+                            trace_buf[i].x3, trace_buf[i].x4, trace_buf[i].x5);

Getting only numeric output is the limitation of a binary trace.  It would probably be possible to pretty-print without much additional code by using the format strings from the trace-events file.

Quoted 4 lines

I think the numeric dump is good for now though.  Hex is more compact than decimal and would make pointers easier to spot.  Want to change this?

I agree, but we can let this be a todo till after the first prototype goes upstream ?

I'll post patches by Monday that addresses your suggestions, and try to get it integrated with QMP.

This patch adds support for dynamically enabling/disabling of tracepoints. This is done by internally maintaining each tracepoint's state, and permitting logging of data from a tracepoint only if it is in an 'active' state.

Monitor commands added :
1) info tracepoints : to view all available tracepoints and
their state.
2) tracepoint NAME on|off : to enable/disable data logging from a
given tracepoint.
Eg, tracepoint paio_submit off
disables logging of data when paio_submit is hit.

Signed-off-by Prerna Saxena <[email protected]>

---

 monitor.c       |   16 ++++++++++++++
 qemu-monitor.hx |   18 ++++++++++++++++
 simpletrace.c   |   63 +++++++++++++++++++++++++++++++++++++++++++++++++++++++
 tracetool       |   30 +++++++++++++++++++++++---
 vl.c            |    6 +++++
 5 files changed, 129 insertions(+), 4 deletions(-)

monitor.c +16 -0

index 8b60830..238bdf0 100644
@@ -548,6 +548,15 @@ static void do_commit(Monitor *mon, const QDict *qdict)
     }
 }
 
+#ifdef CONFIG_SIMPLE_TRACE
+static void do_change_tracepoint_state(Monitor *mon, const QDict *qdict)
+{
+    const char *tp_name = qdict_get_str(qdict, "name");
+    bool new_state = qdict_get_bool(qdict, "option");
+    change_tracepoint_state(tp_name, new_state);
+}
+#endif
+
 static void user_monitor_complete(void *opaque, QObject *ret_data)
 {
     MonitorCompletionData *data = (MonitorCompletionData *)opaque; 

@@ -2791,6 +2800,13 @@ static const mon_cmd_t info_cmds[] = {
         .help       = "show current contents of trace buffer",
         .mhandler.info = do_info_trace,
     },
+    {
+        .name       = "tracepoints",
+        .args_type  = "",
+        .params     = "",
+        .help       = "show available tracepoints & their state",
+        .mhandler.info = do_info_all_tracepoints,
+    },
 #endif
     {
         .name       = NULL,

qemu-monitor.hx +18 -0

index 766c30f..8540b8f 100644
@@ -117,6 +117,8 @@ show device tree
 #ifdef CONFIG_SIMPLE_TRACE
 @item info trace
 show contents of trace buffer
+@item info tracepoints
+show available tracepoints and their state
 #endif
 @end table
 ETEXI

@@ -225,6 +227,22 @@ STEXI
 @item logfile @var{filename}
 @findex logfile
 Output logs to @var{filename}.
+#ifdef CONFIG_SIMPLE_TRACE
+ETEXI
+
+    {
+        .name       = "tracepoint",
+        .args_type  = "name:s,option:b",
+        .params     = "name on|off",
+        .help       = "changes status of a specific tracepoint",
+        .mhandler.cmd = do_change_tracepoint_state,
+    },
+
+STEXI
+@item tracepoint
+@findex tracepoint
+changes status of a tracepoint
+#endif
 ETEXI
 
     {

simpletrace.c +0 -0

index 239ae3f..4221a8f 100644

simpletrace.c +2 -0

+
+typedef struct {
     unsigned long event;
     unsigned long x1;
     unsigned long x2;

simpletrace.c +8 -0

+    trace_list[tevent].hash = qemu_hash(tname);
+    trace_list[tevent].state = 1; /* Enable all by default */
+}
 
 static void trace(TraceEvent event, unsigned long x1,
                   unsigned long x2, unsigned long x3,
                   unsigned long x4, unsigned long x5) {
     TraceRecord *rec = &trace_buf[trace_idx];
+
+    if (!trace_list[event].state) {
+        return;
+    }
+
     rec->event = event;
     rec->x1 = x1;
     rec->x2 = x2;

@@ -75,3 +99,42 @@ void do_info_trace(Monitor *mon)
                             trace_buf[i].x3, trace_buf[i].x4, trace_buf[i].x5);
     }

simpletrace.c +9 -0

+}
+
+static Tracepoint* find_tracepoint_by_name(const char *tname)
+{
+    unsigned int i, name_hash;
+
+    if (!tname) {
+        return NULL;
+    }

simpletrace.c +11 -0

+}
+
+void change_tracepoint_state(const char *tname, bool tstate)
+{
+    Tracepoint *tp;
+
+    tp = find_tracepoint_by_name(tname);
+    if (tp) {
+        tp->state = tstate;
+    }
+}

tracetool +9 -1

index 2c73bab..00af205 100755
@@ -123,14 +123,20 @@ linetoc_end_nop()
 linetoh_begin_simple()
 {
     cat <<EOF
+#include <stdbool.h>
+
 typedef unsigned int TraceEvent;
 
+void init_tracepoint_table(void);
+void init_tracepoint(const char *tname, TraceEvent tevent);
 void trace1(TraceEvent event, unsigned long x1);
 void trace2(TraceEvent event, unsigned long x1, unsigned long x2);
 void trace3(TraceEvent event, unsigned long x1, unsigned long x2, unsigned long x3);
 void trace4(TraceEvent event, unsigned long x1, unsigned long x2, unsigned long x3, unsigned long x4);
 void trace5(TraceEvent event, unsigned long x1, unsigned long x2, unsigned long x3, unsigned long x4, unsigned long x5);
 void do_info_trace(Monitor *mon);
+void do_info_all_tracepoints(Monitor *mon);
+void change_tracepoint_state(const char *tname, bool tstate);
 EOF
 
     simple_event_num=0

@@ -163,22 +169,38 @@ EOF
 
 linetoh_end_simple()
 {
-    return
+    cat <<EOF
+#define NR_TRACEPOINTS $simple_event_num
+EOF

tracetool +5 -1

+    simple_event_num=0
+
 }
 
 linetoc_simple()
 {
-    return
+    local name
+    name=$(get_name "$1")
+    cat <<EOF

tracetool +2 -0

+}
+EOF
 }
 
 linetoh_begin_ust()

vl.c +6 -0

index 328395e..dd07904 100644
@@ -163,6 +163,9 @@ int main(int argc, char **argv)
 #include "cpus.h"
 #include "arch_init.h"
 
+#ifdef CONFIG_SIMPLE_TRACE
+#include "trace.h"
+#endif
 //#define DEBUG_NET
 //#define DEBUG_SLIRP
 

@@ -3604,6 +3607,9 @@ int main(int argc, char **argv, char **envp)
     if (net_init_clients() < 0) {
         exit(1);
     }
+#ifdef CONFIG_SIMPLE_TRACE
+    init_tracepoint_table();
+#endif
 
     /* init the bluetooth world */
     if (foreach_device_config(DEV_BT, bt_parse))

Signature · 6 lines

-- 
Prerna Saxena

Linux Technology Centre,
IBM Systems and Technology Lab,
Bangalore, India

simpletrace.c line 9

Quoted 11 lines · Prerna Saxena

This patch adds support for dynamically enabling/disabling of tracepoints. This is done by internally maintaining each tracepoint's state, and permitting logging of data from a tracepoint only if it is in an 'active' state.
....
....
typedef struct {

simpletrace.c +4 -0

+    char *tp_name;
+    bool state;
+    unsigned int hash;
+} Tracepoint;

The tracing infrastructure avoids using the name 'tracepoint'. It calls them trace events. I didn't deliberately choose that name, but was unaware at the time that Linux tracing calls them tracepoints. Given that 'trace event' is currently used, it would be nice to remain consistent/reduce confusion.

How about:

typedef struct {
     const char *name;
     bool enabled;
     unsigned int hash;
} TraceEventState;

Or a nicer overall change might be to rename enum TraceEvent to TraceEventID and Tracepoint to TraceEvent.

Quoted 14 lines

simpletrace.c +7 -0

+
+typedef struct {
      unsigned long event;
      unsigned long x1;
      unsigned long x2;

@@ -18,11 +24,29 @@ enum {
  static TraceRecord trace_buf[TRACE_BUF_LEN];
  static unsigned int trace_idx;
  static FILE *trace_fp;
+static Tracepoint trace_list[NR_TRACEPOINTS];
+
+void init_tracepoint(const char *tname, TraceEvent tevent)
+{
+    if (!tname || tevent>  NR_TRACEPOINTS) {

Review enum { · line 33

Quoted 2 lines

(quoted diff) +2 -0

+        return;
+    }

I'd drop this check because only trace.c should use init_tracepoint() and you have ensured it uses correct arguments. Just a coding style suggestion; having redundant checks makes the code more verbose, may lead the reader to assume that this function really is called with junk arguments, and silently returning will not help make the issue visible.

simpletrace.c enum { · line 36

Quoted 3 lines

simpletrace.c +2 -0

+    trace_list[tevent].tp_name = (char*)qemu_malloc(strlen(tname)+1);
+    strncpy(trace_list[tevent].tp_name, tname, strlen(tname));

Or use qemmu_strdup() but we don't really need to allocate memory at all here. Just hold the const char* to a string literal since the trace event is a static object that is built into the binary.

Quoted 6 lines

simpletrace.c +5 -0

+    trace_list[tevent].hash = qemu_hash(tname);
+    trace_list[tevent].state = 1; /* Enable all by default */
+}
...
+void do_info_all_tracepoints(Monitor *mon)
+{

simpletrace.c void do_info_trace(Monitor *mon) · line 110

Quoted 6 lines

simpletrace.c +6 -0

+    unsigned int i;
+
+    for (i=0; i<NR_TRACEPOINTS; i++) {
+        monitor_printf(mon, "%s [Event ID %u] : state %u\n",
+                                trace_list[i].tp_name, i, trace_list[i].state);
+        }

Whitespace and indentation.

Quoted 16 lines

simpletrace.c +16 -0

+}
+
+static Tracepoint* find_tracepoint_by_name(const char *tname)
+{
+    unsigned int i, name_hash;
+
+    if (!tname) {
+        return NULL;
+    }
+
+    name_hash = qemu_hash(tname);
+
+    for (i=0; i<NR_TRACEPOINTS; i++) {
+        if (trace_list[i].hash == name_hash&&
+                       !strncmp(trace_list[i].tp_name, tname, strlen(tname))) {
+            return&trace_list[i];

simpletrace.c void do_info_trace(Monitor *mon) · line 129

Quoted 3 lines

simpletrace.c +3 -0

+        }
+    }
+    return NULL; /* indicates end of list reached without a match */

I don't see the need for hashing. We don't actually have a hash table and are doing a linear search. There will be a smallish constant number of trace events and only change_tracepoint_by_name() needs to do a lookup. There's no need to optimize that.

Is strncmp() used so looking up "foo" is like searching for foo*? The strlen(tname) should be outside the loop. I think that could be useful but we should document it or just use strcmp().

Quoted 46 lines

simpletrace.c +11 -0

+}
+
+void change_tracepoint_state(const char *tname, bool tstate)
+{
+    Tracepoint *tp;
+
+    tp = find_tracepoint_by_name(tname);
+    if (tp) {
+        tp->state = tstate;
+    }
+}

tracetool +9 -1

index 2c73bab..00af205 100755
@@ -123,14 +123,20 @@ linetoc_end_nop()
  linetoh_begin_simple()
  {
      cat<<EOF
+#include<stdbool.h>
+
  typedef unsigned int TraceEvent;
 
+void init_tracepoint_table(void);
+void init_tracepoint(const char *tname, TraceEvent tevent);
  void trace1(TraceEvent event, unsigned long x1);
  void trace2(TraceEvent event, unsigned long x1, unsigned long x2);
  void trace3(TraceEvent event, unsigned long x1, unsigned long x2, unsigned long x3);
  void trace4(TraceEvent event, unsigned long x1, unsigned long x2, unsigned long x3, unsigned long x4);
  void trace5(TraceEvent event, unsigned long x1, unsigned long x2, unsigned long x3, unsigned long x4, unsigned long x5);
  void do_info_trace(Monitor *mon);
+void do_info_all_tracepoints(Monitor *mon);
+void change_tracepoint_state(const char *tname, bool tstate);
  EOF
 
      simple_event_num=0

@@ -163,22 +169,38 @@ EOF
 
  linetoh_end_simple()
  {
-    return
+    cat<<EOF
+#define NR_TRACEPOINTS $simple_event_num
+EOF
  }
 

tracetool EOF · line 183

Quoted 8 lines

tracetool +5 -1

  linetoc_begin_simple()
  {
-    return
+    cat<<EOF
+#include "trace.h"
+
+void init_tracepoint_table(void) {
+EOF

Have you looked at module.h? Perhaps that provides a good solution for initializing trace events. It would allow the vl.c changes to be done without an #ifdef.

Quoted 16 lines

tracetool +8 -1

+    simple_event_num=0
+
  }
 
  linetoc_simple()
  {
-    return
+    local name
+    name=$(get_name "$1")
+    cat<<EOF
+init_tracepoint("$name", $simple_event_num);
+EOF
+    simple_event_num=$((simple_event_num + 1))
  }
 

tracetool EOF · line 201

Quoted 5 lines

tracetool +2 -1

  linetoc_end_simple()
  {
-    return
+    cat<<EOF
+return;

Please don't use return at the end of a void function. Coding style.

Quoted 4 lines

tracetool +2 -0

+}
+EOF
...

Quoted 17 lines · Stefan Hajnoczi

Quoted 17 lines

simpletrace.c +15 -0

+}
+
+static Tracepoint* find_tracepoint_by_name(const char *tname)
+{
+    unsigned int i, name_hash;
+
+    if (!tname) {
+        return NULL;
+    }
+
+    name_hash = qemu_hash(tname);
+
+    for (i=0; i<NR_TRACEPOINTS; i++) {
+        if (trace_list[i].hash == name_hash&&
+                       !strncmp(trace_list[i].tp_name, tname,

strlen(tname))) {
+            return&trace_list[i];

Quoted 9 lines

Quoted 3 lines

+        }
+    }
+    return NULL; /* indicates end of list reached without a match */

I don't see the need for hashing.  We don't actually have a hash table and are doing a linear search.  There will be a smallish constant number of trace events and only change_tracepoint_by_name() needs to do a lookup.  There's no need to optimize that.

I was only optimising lookups. Instead of doing a strlen()-size comparison for each tracepoint, we end up doing a constant int-size comparison till there is possibility of hash collision. Strlen()-size lookups isnt really an issure right now, but will be more glaring if qemu ends up having a much larger number of tracepoints.

Quoted 38 lines

Quoted 38 lines

tracetool +0 -0

index 2c73bab..00af205 100755
@@ -123,14 +123,20 @@ linetoc_end_nop()
  linetoh_begin_simple()
  {

     cat<<EOF

tracetool +2 -0

+#include<stdbool.h>
+

 typedef unsigned int TraceEvent;

tracetool +2 -0

+void init_tracepoint_table(void);
+void init_tracepoint(const char *tname, TraceEvent tevent);

 void trace1(TraceEvent event, unsigned long x1);
 void trace2(TraceEvent event, unsigned long x1, unsigned long x2); void trace3(TraceEvent event, unsigned long x1, unsigned long x2, unsigned long x3);
 void trace4(TraceEvent event, unsigned long x1, unsigned long x2, unsigned long x3, unsigned long x4);
 void trace5(TraceEvent event, unsigned long x1, unsigned long x2, unsigned long x3, unsigned long x4, unsigned long x5); void do_info_trace(Monitor *mon);

tracetool +2 -0

+void do_info_all_tracepoints(Monitor *mon);
+void change_tracepoint_state(const char *tname, bool tstate);

 EOF

     simple_event_num=0

tracetool +3 -1

@@ -163,22 +169,38 @@ EOF
 
  linetoh_end_simple()
  {
-    return
+    cat<<EOF
+#define NR_TRACEPOINTS $simple_event_num
+EOF
  }
 

Quoted 12 lines

tracetool EOF · line 183

Quoted 8 lines

tracetool +5 -1

  linetoc_begin_simple()
  {
-    return
+    cat<<EOF
+#include "trace.h"
+
+void init_tracepoint_table(void) {
+EOF

Have you looked at module.h?  Perhaps that provides a good solution for initializing trace events.  It would allow the vl.c changes to be done without an #ifdef.

Thanks for the tip, I'll check.

This is v3 of a set of patches to enable trace visualization & control via the QEMU monitor. It is based on trace infrastructure posted by Stefan :
( http://lists.gnu.org/archive/html/qemu-devel/2010-05/msg02407.html )

This patchset adds monitor commands :
- info trace : to view current contents of the trace buffer
- info tracepoints : to view all available tracepoints and their state.
- tracepoint NAME on|off : to enable/disable the logging of data from tracepoint 'NAME' to on/off.

Changelog :
- Clean-ups from v2, particularly relating to export of tdb_hash()