[Qemu-devel] [PATCH 3/7] trace: Add simple built-in tracing backend

[Stefan Hajnoczi <stefanha@linux.vnet.ibm.com>]

This patch adds a simple tracer which produces binary trace files and is
built into QEMU.  The main purpose of this patch is to show how new
tracing backends can be added to tracetool.

To try out the simple backend:

./configure --trace-backend=simple
make

After running QEMU you can pretty-print the trace:

./simpletrace.py trace-events /tmp/trace.log

Signed-off-by: Stefan Hajnoczi <stefanha@linux.vnet.ibm.com>
---
I intend for this tracing backend to be replaced by something based on Prerna's
work.  For now it is useful for basic tracing.

v2:
 * Make simpletrace.py parse trace-events instead of generating Python

 .gitignore     |    1 +
 Makefile.objs  |    3 ++
 configure      |    2 +-
 simpletrace.c  |   64 ++++++++++++++++++++++++++++++++++++++++++++++
 simpletrace.py |   53 ++++++++++++++++++++++++++++++++++++++
 tracetool      |   78 +++++++++++++++++++++++++++++++++++++++++++++++++++++--
 6 files changed, 197 insertions(+), 4 deletions(-)
 create mode 100644 simpletrace.c
 create mode 100755 simpletrace.py

diff --git a/.gitignore b/.gitignore
index 4644557..5128452 100644
--- a/.gitignore
+++ b/.gitignore
@@ -39,6 +39,7 @@ qemu-monitor.texi
 *.log
 *.pdf
 *.pg
+*.pyc
 *.toc
 *.tp
 *.vr
diff --git a/Makefile.objs b/Makefile.objs
index 20e709e..7cb40ac 100644
--- a/Makefile.objs
+++ b/Makefile.objs
@@ -255,6 +255,9 @@ libdis-$(CONFIG_SPARC_DIS) += sparc-dis.o
 # trace
 
 trace-obj-y = trace.o
+ifeq ($(TRACE_BACKEND),simple)
+trace-obj-y += simpletrace.o
+endif
 
 vl.o: QEMU_CFLAGS+=$(GPROF_CFLAGS)
 
diff --git a/configure b/configure
index e94e113..7d2c69b 100755
--- a/configure
+++ b/configure
@@ -829,7 +829,7 @@ echo "  --enable-docs            enable documentation build"
 echo "  --disable-docs           disable documentation build"
 echo "  --disable-vhost-net      disable vhost-net acceleration support"
 echo "  --enable-vhost-net       enable vhost-net acceleration support"
-echo "  --trace-backend=B        Trace backend nop"
+echo "  --trace-backend=B        Trace backend nop simple"
 echo ""
 echo "NOTE: The object files are built at the place where configure is launched"
 exit 1
diff --git a/simpletrace.c b/simpletrace.c
new file mode 100644
index 0000000..2fec4d3
--- /dev/null
+++ b/simpletrace.c
@@ -0,0 +1,64 @@
+#include <stdlib.h>
+#include <stdio.h>
+#include "trace.h"
+
+typedef struct {
+    unsigned long event;
+    unsigned long x1;
+    unsigned long x2;
+    unsigned long x3;
+    unsigned long x4;
+    unsigned long x5;
+} TraceRecord;
+
+enum {
+    TRACE_BUF_LEN = 64 * 1024 / sizeof(TraceRecord),
+};
+
+static TraceRecord trace_buf[TRACE_BUF_LEN];
+static unsigned int trace_idx;
+static FILE *trace_fp;
+
+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];
+    rec->event = event;
+    rec->x1 = x1;
+    rec->x2 = x2;
+    rec->x3 = x3;
+    rec->x4 = x4;
+    rec->x5 = x5;
+
+    if (++trace_idx == TRACE_BUF_LEN) {
+        trace_idx = 0;
+
+        if (!trace_fp) {
+            trace_fp = fopen("/tmp/trace.log", "w");
+        }
+        if (trace_fp) {
+            size_t result = fwrite(trace_buf, sizeof trace_buf, 1, trace_fp);
+            result = result;
+        }
+    }
+}
+
+void trace1(TraceEvent event, unsigned long x1) {
+    trace(event, x1, 0, 0, 0, 0);
+}
+
+void trace2(TraceEvent event, unsigned long x1, unsigned long x2) {
+    trace(event, x1, x2, 0, 0, 0);
+}
+
+void trace3(TraceEvent event, unsigned long x1, unsigned long x2, unsigned long x3) {
+    trace(event, x1, x2, x3, 0, 0);
+}
+
+void trace4(TraceEvent event, unsigned long x1, unsigned long x2, unsigned long x3, unsigned long x4) {
+    trace(event, x1, x2, x3, x4, 0);
+}
+
+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);
+}
diff --git a/simpletrace.py b/simpletrace.py
new file mode 100755
index 0000000..d6631ba
--- /dev/null
+++ b/simpletrace.py
@@ -0,0 +1,53 @@
+#!/usr/bin/env python
+import sys
+import struct
+import re
+
+trace_fmt = 'LLLLLL'
+trace_len = struct.calcsize(trace_fmt)
+event_re  = re.compile(r'(disable\s+)?([a-zA-Z0-9_]+)\(([^)]*)\)\s+"([^"]*)"')
+
+def parse_events(fobj):
+    def get_argnames(args):
+        return tuple(arg.split()[-1].lstrip('*') for arg in args.split(','))
+
+    events = {}
+    event_num = 0
+    for line in fobj:
+        m = event_re.match(line.strip())
+        if m is None:
+            continue
+
+        disable, name, args, fmt = m.groups()
+        if disable:
+            continue
+
+        events[event_num] = (name,) + get_argnames(args)
+        event_num += 1
+    return events
+
+def read_record(fobj):
+    s = fobj.read(trace_len)
+    if len(s) != trace_len:
+        return None
+    return struct.unpack(trace_fmt, s)
+
+def format_record(events, rec):
+    event = events[rec[0]]
+    fields = [event[0]]
+    for i in xrange(1, len(event)):
+        fields.append('%s=0x%x' % (event[i], rec[i]))
+    return ' '.join(fields)
+
+if len(sys.argv) != 3:
+    sys.stderr.write('usage: %s <trace-events> <trace-file>\n' % sys.argv[0])
+    sys.exit(1)
+
+events = parse_events(open(sys.argv[1], 'r'))
+f = open(sys.argv[2], 'rb')
+while True:
+    rec = read_record(f)
+    if rec is None:
+        break
+
+    print format_record(events, rec)
diff --git a/tracetool b/tracetool
index 53d3612..f094ddc 100755
--- a/tracetool
+++ b/tracetool
@@ -3,11 +3,12 @@
 usage()
 {
     cat >&2 <<EOF
-usage: $0 --nop [-h | -c]
+usage: $0 [--nop | --simple] [-h | -c]
 Generate tracing code for a file on stdin.
 
 Backends:
-  --nop Tracing disabled
+  --nop     Tracing disabled
+  --simple  Simple built-in backend
 
 Output formats:
   -h    Generate .h file
@@ -48,6 +49,17 @@ get_argnames()
     echo -n "$name"
 }
 
+# Get the number of arguments to a trace event
+get_argc()
+{
+    local name argc
+    argc=0
+    for name in $(get_argnames "$1"); do
+        argc=$((argc + 1))
+    done
+    echo $argc
+}
+
 # Get the format string for a trace event
 get_fmt()
 {
@@ -107,6 +119,66 @@ linetoc_end_nop()
     return
 }
 
+linetoh_begin_simple()
+{
+    cat <<EOF
+typedef unsigned int TraceEvent;
+
+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);
+EOF
+
+    simple_event_num=0
+}
+
+cast_args_to_ulong()
+{
+    local arg
+    for arg in $(get_argnames "$1"); do
+        echo -n "(unsigned long)$arg"
+    done
+}
+
+linetoh_simple()
+{
+    local name args argc ulong_args
+    name=$(get_name "$1")
+    args=$(get_args "$1")
+    argc=$(get_argc "$1")
+    ulong_args=$(cast_args_to_ulong "$1")
+
+    cat <<EOF
+static inline void trace_$name($args) {
+    trace$argc($simple_event_num, $ulong_args);
+}
+EOF
+
+    simple_event_num=$((simple_event_num + 1))
+}
+
+linetoh_end_simple()
+{
+    return
+}
+
+linetoc_begin_simple()
+{
+    return
+}
+
+linetoc_simple()
+{
+    return
+}
+
+linetoc_end_simple()
+{
+    return
+}
+
 # Process stdin by calling begin, line, and end functions for the backend
 convert()
 {
@@ -156,7 +228,7 @@ tracetoc()
 
 # Choose backend
 case "$1" in
-"--nop") backend="${1#--}" ;;
+"--nop" | "--simple") backend="${1#--}" ;;
 *) usage ;;
 esac
 shift
-- 
1.7.1