Patchwork [08/14] trace: Support for dynamically enabling/disabling trace events.

login
register
mail settings
Submitter Stefan Hajnoczi
Date Aug. 12, 2010, 10:36 a.m.
Message ID <1281609395-17621-9-git-send-email-stefanha@linux.vnet.ibm.com>
Download mbox | patch
Permalink /patch/61590/
State New
Headers show

Comments

Stefan Hajnoczi - Aug. 12, 2010, 10:36 a.m.
From: Prerna Saxena <prerna@linux.vnet.ibm.com>

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

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

By default, all trace-events are disabled. One can enable desired trace-events
via the monitor.

Signed-off-by: Prerna Saxena <prerna@linux.vnet.ibm.com>
Signed-off-by: Stefan Hajnoczi <stefanha@linux.vnet.ibm.com>

trace: Monitor command 'info trace'

Monitor command 'info trace' to display contents of trace buffer

Signed-off-by: Prerna Saxena <prerna@linux.vnet.ibm.com>
Signed-off-by: Stefan Hajnoczi <stefanha@linux.vnet.ibm.com>

trace: Remove monitor.h dependency from simpletrace

User-mode targets don't have a monitor so the simple trace backend
currently does not build on those targets.  This patch abstracts the
monitor printing interface so there is no direct coupling between
simpletrace and the monitor.

Signed-off-by: Stefan Hajnoczi <stefanha@linux.vnet.ibm.com>
---
 configure       |    3 +++
 monitor.c       |   40 ++++++++++++++++++++++++++++++++++++++++
 qemu-monitor.hx |   25 +++++++++++++++++++++++++
 simpletrace.c   |   52 ++++++++++++++++++++++++++++++++++++++++++++++++++++
 simpletrace.h   |    9 +++++++++
 tracetool       |   24 ++++++++++++++++++++----
 6 files changed, 149 insertions(+), 4 deletions(-)
Blue Swirl - Aug. 12, 2010, 6:02 p.m.
On Thu, Aug 12, 2010 at 10:36 AM, Stefan Hajnoczi
<stefanha@linux.vnet.ibm.com> wrote:
> From: Prerna Saxena <prerna@linux.vnet.ibm.com>
>
> This patch adds support for dynamically enabling/disabling of trace events.
> This is done by internally maintaining each trace event's state, and
> permitting logging of data from a trace event only if it is in an
> 'active' state.
>
> Monitor commands added :
> 1) info trace-events            : to view all available trace events and
>                                  their state.
> 2) trace-event NAME on|off      : to enable/disable data logging from a
>                                  given trace event.
>                                  Eg, trace-event paio_submit off
>                                        disables logging of data when
>                                        paio_submit is hit.
>
> By default, all trace-events are disabled. One can enable desired trace-events
> via the monitor.
>
> Signed-off-by: Prerna Saxena <prerna@linux.vnet.ibm.com>
> Signed-off-by: Stefan Hajnoczi <stefanha@linux.vnet.ibm.com>
>
> trace: Monitor command 'info trace'
>
> Monitor command 'info trace' to display contents of trace buffer
>
> Signed-off-by: Prerna Saxena <prerna@linux.vnet.ibm.com>
> Signed-off-by: Stefan Hajnoczi <stefanha@linux.vnet.ibm.com>
>
> trace: Remove monitor.h dependency from simpletrace
>
> User-mode targets don't have a monitor so the simple trace backend
> currently does not build on those targets.  This patch abstracts the
> monitor printing interface so there is no direct coupling between
> simpletrace and the monitor.
>
> Signed-off-by: Stefan Hajnoczi <stefanha@linux.vnet.ibm.com>
> ---
>  configure       |    3 +++
>  monitor.c       |   40 ++++++++++++++++++++++++++++++++++++++++
>  qemu-monitor.hx |   25 +++++++++++++++++++++++++
>  simpletrace.c   |   52 ++++++++++++++++++++++++++++++++++++++++++++++++++++
>  simpletrace.h   |    9 +++++++++
>  tracetool       |   24 ++++++++++++++++++++----
>  6 files changed, 149 insertions(+), 4 deletions(-)
>
> diff --git a/configure b/configure
> index 62dd10d..830e49e 100755
> --- a/configure
> +++ b/configure
> @@ -2466,6 +2466,9 @@ bsd)
>  esac
>
>  echo "TRACE_BACKEND=$trace_backend" >> $config_host_mak
> +if test "$trace_backend" = "simple"; then
> +  echo "CONFIG_SIMPLE_TRACE=y" >> $config_host_mak
> +fi
>  echo "TOOLS=$tools" >> $config_host_mak
>  echo "ROMS=$roms" >> $config_host_mak
>  echo "MAKE=$make" >> $config_host_mak
> diff --git a/monitor.c b/monitor.c
> index c313d5a..4f1639d 100644
> --- a/monitor.c
> +++ b/monitor.c
> @@ -56,6 +56,9 @@
>  #include "json-parser.h"
>  #include "osdep.h"
>  #include "exec-all.h"
> +#ifdef CONFIG_SIMPLE_TRACE
> +#include "trace.h"
> +#endif
>
>  //#define DEBUG
>  //#define DEBUG_COMPLETION
> @@ -539,6 +542,15 @@ static void do_help_cmd(Monitor *mon, const QDict *qdict)
>     help_cmd(mon, qdict_get_try_str(qdict, "name"));
>  }
>
> +#ifdef CONFIG_SIMPLE_TRACE
> +static void do_change_trace_event_state(Monitor *mon, const QDict *qdict)
> +{
> +    const char *tp_name = qdict_get_str(qdict, "name");
> +    bool new_state = qdict_get_bool(qdict, "option");
> +    st_change_trace_event_state(tp_name, new_state);
> +}
> +#endif
> +
>  static void user_monitor_complete(void *opaque, QObject *ret_data)
>  {
>     MonitorCompletionData *data = (MonitorCompletionData *)opaque;
> @@ -923,6 +935,18 @@ static void do_info_cpu_stats(Monitor *mon)
>  }
>  #endif
>
> +#if defined(CONFIG_SIMPLE_TRACE)
> +static void do_info_trace(Monitor *mon)
> +{
> +    st_print_trace((FILE *)mon, &monitor_fprintf);

The cast is ugly. Is there no other way than passing falsified types?

> +}
> +
> +static void do_info_trace_events(Monitor *mon)
> +{
> +    st_print_trace_events((FILE *)mon, &monitor_fprintf);
> +}
> +#endif
> +
>  /**
>  * do_quit(): Quit QEMU execution
>  */
> @@ -2579,6 +2603,22 @@ static const mon_cmd_t info_cmds[] = {
>         .help       = "show roms",
>         .mhandler.info = do_info_roms,
>     },
> +#if defined(CONFIG_SIMPLE_TRACE)
> +    {
> +        .name       = "trace",
> +        .args_type  = "",
> +        .params     = "",
> +        .help       = "show current contents of trace buffer",
> +        .mhandler.info = do_info_trace,
> +    },
> +    {
> +        .name       = "trace-events",
> +        .args_type  = "",
> +        .params     = "",
> +        .help       = "show available trace-events & their state",
> +        .mhandler.info = do_info_trace_events,
> +    },
> +#endif
>     {
>         .name       = NULL,
>     },
> diff --git a/qemu-monitor.hx b/qemu-monitor.hx
> index 2af3de6..a9f4221 100644
> --- a/qemu-monitor.hx
> +++ b/qemu-monitor.hx
> @@ -259,6 +259,22 @@ STEXI
>  Output logs to @var{filename}.
>  ETEXI
>
> +#ifdef CONFIG_SIMPLE_TRACE
> +    {
> +        .name       = "trace-event",
> +        .args_type  = "name:s,option:b",
> +        .params     = "name on|off",
> +        .help       = "changes status of a specific trace event",
> +        .mhandler.cmd = do_change_trace_event_state,
> +    },
> +
> +STEXI
> +@item trace-event
> +@findex trace-event
> +changes status of a trace event
> +ETEXI
> +#endif
> +
>     {
>         .name       = "log",
>         .args_type  = "items:s",
> @@ -2495,6 +2511,15 @@ show roms
>  @end table
>  ETEXI
>
> +#ifdef CONFIG_SIMPLE_TRACE
> +STEXI
> +@item info trace
> +show contents of trace buffer
> +@item info trace-events
> +show available trace events and their state
> +ETEXI
> +#endif
> +
>  HXCOMM DO NOT add new commands after 'info', move your addition before it!
>
>  STEXI
> diff --git a/simpletrace.c b/simpletrace.c
> index a6afc51..311fa44 100644
> --- a/simpletrace.c
> +++ b/simpletrace.c
> @@ -11,6 +11,7 @@
>  #include <stdlib.h>
>  #include <stdint.h>
>  #include <stdio.h>
> +#include <time.h>

The changes below don't seem to require this addition.

>  #include "trace.h"
>
>  /** Trace file header event ID */
> @@ -83,6 +84,10 @@ static void trace(TraceEventID event, unsigned long x1,
>      */
>     clock_gettime(CLOCK_MONOTONIC, &ts);
>
> +    if (!trace_list[event].state) {
> +        return;
> +    }
> +
>     rec->event = event;
>     rec->timestamp_ns = ts.tv_sec * 1000000000LL + ts.tv_nsec;
>     rec->x1 = x1;
> @@ -125,3 +130,50 @@ void trace5(TraceEventID event, uint64_t x1, uint64_t x2, uint64_t x3, uint64_t
>  {
>     trace(event, x1, x2, x3, x4, x5);
>  }
> +
> +void st_print_trace(FILE *stream, int (*stream_printf)(FILE *stream, const char *fmt, ...))
> +{
> +    unsigned int i;
> +
> +    for (i = 0; i < trace_idx; i++) {
> +        stream_printf(stream, "Event %lu : %lx %lx %lx %lx %lx\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);
> +    }
> +}
> +
> +void st_print_trace_events(FILE *stream, int (*stream_printf)(FILE *stream, const char *fmt, ...))
> +{
> +    unsigned int i;
> +
> +    for (i = 0; i < NR_TRACE_EVENTS; i++) {
> +        stream_printf(stream, "%s [Event ID %u] : state %u\n",
> +                      trace_list[i].tp_name, i, trace_list[i].state);
> +    }
> +}
> +
> +static TraceEvent* find_trace_event_by_name(const char *tname)
> +{
> +    unsigned int i;
> +
> +    if (!tname) {
> +        return NULL;
> +    }
> +
> +    for (i = 0; i < NR_TRACE_EVENTS; i++) {
> +        if (!strcmp(trace_list[i].tp_name, tname)) {
> +            return &trace_list[i];
> +        }
> +    }
> +    return NULL; /* indicates end of list reached without a match */
> +}
> +
> +void st_change_trace_event_state(const char *tname, bool tstate)
> +{
> +    TraceEvent *tp;
> +
> +    tp = find_trace_event_by_name(tname);
> +    if (tp) {
> +        tp->state = tstate;
> +    }
> +}
> diff --git a/simpletrace.h b/simpletrace.h
> index e4e9759..ee30ae9 100644
> --- a/simpletrace.h
> +++ b/simpletrace.h
> @@ -13,14 +13,23 @@
>
>  #include <stdbool.h>
>  #include <stdint.h>
> +#include <stdio.h>
>
>  typedef uint64_t TraceEventID;
>
> +typedef struct {
> +    const char *tp_name;
> +    bool state;
> +} TraceEvent;
> +
>  void trace0(TraceEventID event);
>  void trace1(TraceEventID event, uint64_t x1);
>  void trace2(TraceEventID event, uint64_t x1, uint64_t x2);
>  void trace3(TraceEventID event, uint64_t x1, uint64_t x2, uint64_t x3);
>  void trace4(TraceEventID event, uint64_t x1, uint64_t x2, uint64_t x3, uint64_t x4);
>  void trace5(TraceEventID event, uint64_t x1, uint64_t x2, uint64_t x3, uint64_t x4, uint64_t x5);
> +void st_print_trace(FILE *stream, int (*stream_printf)(FILE *stream, const char *fmt, ...));
> +void st_print_trace_events(FILE *stream, int (*stream_printf)(FILE *stream, const char *fmt, ...));
> +void st_change_trace_event_state(const char *tname, bool tstate);
>
>  #endif /* SIMPLETRACE_H */
> diff --git a/tracetool b/tracetool
> index 66df685..30dc812 100755
> --- a/tracetool
> +++ b/tracetool
> @@ -169,22 +169,38 @@ EOF
>
>  linetoh_end_simple()
>  {
> -    return
> +    cat <<EOF
> +#define NR_TRACE_EVENTS $simple_event_num
> +extern TraceEvent trace_list[NR_TRACE_EVENTS];
> +EOF
>  }
>
>  linetoc_begin_simple()
>  {
> -    return
> +    cat <<EOF
> +#include "trace.h"
> +
> +TraceEvent trace_list[] = {
> +EOF
> +    simple_event_num=0
> +
>  }
>
>  linetoc_simple()
>  {
> -    return
> +    local name
> +    name=$(get_name "$1")
> +    cat <<EOF
> +{.tp_name = "$name", .state=0},
> +EOF
> +    simple_event_num=$((simple_event_num + 1))
>  }
>
>  linetoc_end_simple()
>  {
> -    return
> +    cat <<EOF
> +};
> +EOF
>  }
>
>  # Process stdin by calling begin, line, and end functions for the backend
> --
> 1.7.1
>
>
>
Stefan Hajnoczi - Aug. 13, 2010, 1:34 p.m.
On Thu, Aug 12, 2010 at 7:02 PM, Blue Swirl <blauwirbel@gmail.com> wrote:
> On Thu, Aug 12, 2010 at 10:36 AM, Stefan Hajnoczi
> <stefanha@linux.vnet.ibm.com> wrote:
>> From: Prerna Saxena <prerna@linux.vnet.ibm.com>
>> +#if defined(CONFIG_SIMPLE_TRACE)
>> +static void do_info_trace(Monitor *mon)
>> +{
>> +    st_print_trace((FILE *)mon, &monitor_fprintf);
>
> The cast is ugly. Is there no other way than passing falsified types?

Yes.  This approach is the solution that monitor.c currently uses for
decoupling subsystem code from monitor code:

static void do_info_registers(Monitor *mon)
{
    CPUState *env;
    env = mon_get_cpu();
#ifdef TARGET_I386
    cpu_dump_state(env, (FILE *)mon, monitor_fprintf,
                   X86_DUMP_FPU);
#else
    cpu_dump_state(env, (FILE *)mon, monitor_fprintf,
                   0);
#endif
}

...and others do it in order to avoid telling subsystems about
Monitor.  There are 4 other places in monitor.c before this patch that
use this technique.  I suggest leaving it and if someone implements a
better approach, a search-replace will update monitor.c in one patch.

>> diff --git a/simpletrace.c b/simpletrace.c
>> index a6afc51..311fa44 100644
>> --- a/simpletrace.c
>> +++ b/simpletrace.c
>> @@ -11,6 +11,7 @@
>>  #include <stdlib.h>
>>  #include <stdint.h>
>>  #include <stdio.h>
>> +#include <time.h>
>
> The changes below don't seem to require this addition.

You are right, this is a rebase/squash issue.  Sorry, will fix in v2.

Stefan

Patch

diff --git a/configure b/configure
index 62dd10d..830e49e 100755
--- a/configure
+++ b/configure
@@ -2466,6 +2466,9 @@  bsd)
 esac
 
 echo "TRACE_BACKEND=$trace_backend" >> $config_host_mak
+if test "$trace_backend" = "simple"; then
+  echo "CONFIG_SIMPLE_TRACE=y" >> $config_host_mak
+fi
 echo "TOOLS=$tools" >> $config_host_mak
 echo "ROMS=$roms" >> $config_host_mak
 echo "MAKE=$make" >> $config_host_mak
diff --git a/monitor.c b/monitor.c
index c313d5a..4f1639d 100644
--- a/monitor.c
+++ b/monitor.c
@@ -56,6 +56,9 @@ 
 #include "json-parser.h"
 #include "osdep.h"
 #include "exec-all.h"
+#ifdef CONFIG_SIMPLE_TRACE
+#include "trace.h"
+#endif
 
 //#define DEBUG
 //#define DEBUG_COMPLETION
@@ -539,6 +542,15 @@  static void do_help_cmd(Monitor *mon, const QDict *qdict)
     help_cmd(mon, qdict_get_try_str(qdict, "name"));
 }
 
+#ifdef CONFIG_SIMPLE_TRACE
+static void do_change_trace_event_state(Monitor *mon, const QDict *qdict)
+{
+    const char *tp_name = qdict_get_str(qdict, "name");
+    bool new_state = qdict_get_bool(qdict, "option");
+    st_change_trace_event_state(tp_name, new_state);
+}
+#endif
+
 static void user_monitor_complete(void *opaque, QObject *ret_data)
 {
     MonitorCompletionData *data = (MonitorCompletionData *)opaque; 
@@ -923,6 +935,18 @@  static void do_info_cpu_stats(Monitor *mon)
 }
 #endif
 
+#if defined(CONFIG_SIMPLE_TRACE)
+static void do_info_trace(Monitor *mon)
+{
+    st_print_trace((FILE *)mon, &monitor_fprintf);
+}
+
+static void do_info_trace_events(Monitor *mon)
+{
+    st_print_trace_events((FILE *)mon, &monitor_fprintf);
+}
+#endif
+
 /**
  * do_quit(): Quit QEMU execution
  */
@@ -2579,6 +2603,22 @@  static const mon_cmd_t info_cmds[] = {
         .help       = "show roms",
         .mhandler.info = do_info_roms,
     },
+#if defined(CONFIG_SIMPLE_TRACE)
+    {
+        .name       = "trace",
+        .args_type  = "",
+        .params     = "",
+        .help       = "show current contents of trace buffer",
+        .mhandler.info = do_info_trace,
+    },
+    {
+        .name       = "trace-events",
+        .args_type  = "",
+        .params     = "",
+        .help       = "show available trace-events & their state",
+        .mhandler.info = do_info_trace_events,
+    },
+#endif
     {
         .name       = NULL,
     },
diff --git a/qemu-monitor.hx b/qemu-monitor.hx
index 2af3de6..a9f4221 100644
--- a/qemu-monitor.hx
+++ b/qemu-monitor.hx
@@ -259,6 +259,22 @@  STEXI
 Output logs to @var{filename}.
 ETEXI
 
+#ifdef CONFIG_SIMPLE_TRACE
+    {
+        .name       = "trace-event",
+        .args_type  = "name:s,option:b",
+        .params     = "name on|off",
+        .help       = "changes status of a specific trace event",
+        .mhandler.cmd = do_change_trace_event_state,
+    },
+
+STEXI
+@item trace-event
+@findex trace-event
+changes status of a trace event
+ETEXI
+#endif
+
     {
         .name       = "log",
         .args_type  = "items:s",
@@ -2495,6 +2511,15 @@  show roms
 @end table
 ETEXI
 
+#ifdef CONFIG_SIMPLE_TRACE
+STEXI
+@item info trace
+show contents of trace buffer
+@item info trace-events
+show available trace events and their state
+ETEXI
+#endif
+
 HXCOMM DO NOT add new commands after 'info', move your addition before it!
 
 STEXI
diff --git a/simpletrace.c b/simpletrace.c
index a6afc51..311fa44 100644
--- a/simpletrace.c
+++ b/simpletrace.c
@@ -11,6 +11,7 @@ 
 #include <stdlib.h>
 #include <stdint.h>
 #include <stdio.h>
+#include <time.h>
 #include "trace.h"
 
 /** Trace file header event ID */
@@ -83,6 +84,10 @@  static void trace(TraceEventID event, unsigned long x1,
      */
     clock_gettime(CLOCK_MONOTONIC, &ts);
 
+    if (!trace_list[event].state) {
+        return;
+    }
+
     rec->event = event;
     rec->timestamp_ns = ts.tv_sec * 1000000000LL + ts.tv_nsec;
     rec->x1 = x1;
@@ -125,3 +130,50 @@  void trace5(TraceEventID event, uint64_t x1, uint64_t x2, uint64_t x3, uint64_t
 {
     trace(event, x1, x2, x3, x4, x5);
 }
+
+void st_print_trace(FILE *stream, int (*stream_printf)(FILE *stream, const char *fmt, ...))
+{
+    unsigned int i;
+
+    for (i = 0; i < trace_idx; i++) {
+        stream_printf(stream, "Event %lu : %lx %lx %lx %lx %lx\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);
+    }
+}
+
+void st_print_trace_events(FILE *stream, int (*stream_printf)(FILE *stream, const char *fmt, ...))
+{
+    unsigned int i;
+
+    for (i = 0; i < NR_TRACE_EVENTS; i++) {
+        stream_printf(stream, "%s [Event ID %u] : state %u\n",
+                      trace_list[i].tp_name, i, trace_list[i].state);
+    }
+}
+
+static TraceEvent* find_trace_event_by_name(const char *tname)
+{
+    unsigned int i;
+
+    if (!tname) {
+        return NULL;
+    }
+
+    for (i = 0; i < NR_TRACE_EVENTS; i++) {
+        if (!strcmp(trace_list[i].tp_name, tname)) {
+            return &trace_list[i];
+        }
+    }
+    return NULL; /* indicates end of list reached without a match */
+}
+
+void st_change_trace_event_state(const char *tname, bool tstate)
+{
+    TraceEvent *tp;
+
+    tp = find_trace_event_by_name(tname);
+    if (tp) {
+        tp->state = tstate;
+    }
+}
diff --git a/simpletrace.h b/simpletrace.h
index e4e9759..ee30ae9 100644
--- a/simpletrace.h
+++ b/simpletrace.h
@@ -13,14 +13,23 @@ 
 
 #include <stdbool.h>
 #include <stdint.h>
+#include <stdio.h>
 
 typedef uint64_t TraceEventID;
 
+typedef struct {
+    const char *tp_name;
+    bool state;
+} TraceEvent;
+
 void trace0(TraceEventID event);
 void trace1(TraceEventID event, uint64_t x1);
 void trace2(TraceEventID event, uint64_t x1, uint64_t x2);
 void trace3(TraceEventID event, uint64_t x1, uint64_t x2, uint64_t x3);
 void trace4(TraceEventID event, uint64_t x1, uint64_t x2, uint64_t x3, uint64_t x4);
 void trace5(TraceEventID event, uint64_t x1, uint64_t x2, uint64_t x3, uint64_t x4, uint64_t x5);
+void st_print_trace(FILE *stream, int (*stream_printf)(FILE *stream, const char *fmt, ...));
+void st_print_trace_events(FILE *stream, int (*stream_printf)(FILE *stream, const char *fmt, ...));
+void st_change_trace_event_state(const char *tname, bool tstate);
 
 #endif /* SIMPLETRACE_H */
diff --git a/tracetool b/tracetool
index 66df685..30dc812 100755
--- a/tracetool
+++ b/tracetool
@@ -169,22 +169,38 @@  EOF
 
 linetoh_end_simple()
 {
-    return
+    cat <<EOF
+#define NR_TRACE_EVENTS $simple_event_num
+extern TraceEvent trace_list[NR_TRACE_EVENTS];
+EOF
 }
 
 linetoc_begin_simple()
 {
-    return
+    cat <<EOF
+#include "trace.h"
+
+TraceEvent trace_list[] = {
+EOF
+    simple_event_num=0
+
 }
 
 linetoc_simple()
 {
-    return
+    local name
+    name=$(get_name "$1")
+    cat <<EOF
+{.tp_name = "$name", .state=0},
+EOF
+    simple_event_num=$((simple_event_num + 1))
 }
 
 linetoc_end_simple()
 {
-    return
+    cat <<EOF
+};
+EOF
 }
 
 # Process stdin by calling begin, line, and end functions for the backend