[Qemu-devel] [PATCH 0/2] simpletrace: add pid field to simpletrace record

[Qemu-devel] [PATCH 0/2] simpletrace: add pid field to simpletrace record

[Stefan Hajnoczi]

This series adds a pid field to the simpletrace record.  This allows
aggregation of simpletrace files as well as host-wide tracing since records can
now be associated with a particular QEMU process.

Stefan Hajnoczi (2):
  trace: add pid field to simpletrace record
  simpletrace: add support for trace record pid field

 scripts/simpletrace.py | 26 +++++++++++++++-----------
 trace/simple.c         |  8 ++++++--
 2 files changed, 21 insertions(+), 13 deletions(-)

-- 
1.9.0

[Qemu-devel] [PATCH 1/2] trace: add pid field to simpletrace record

[Stefan Hajnoczi]

It is useful to know the QEMU process ID when working with traces from
multiple VMs.  Although the trace filename may contain the pid, tools
that aggregate traces or even trace globally need somewhere to record
the pid.

There is a reserved field in the trace event header struct that we can
use.

It is not necessary to bump the simpletrace file format version number
because it has already been incremented for the QEMU 2.1 release cycle
in commit "trace: [simple] Bump up log version number".

Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
---
 trace/simple.c | 8 ++++++--
 1 file changed, 6 insertions(+), 2 deletions(-)

diff --git a/trace/simple.c b/trace/simple.c
index aaa010e..1584bf7 100644
--- a/trace/simple.c
+++ b/trace/simple.c
@@ -75,6 +75,7 @@ uint8_t trace_buf[TRACE_BUF_LEN];
 static volatile gint trace_idx;
 static unsigned int writeout_idx;
 static volatile gint dropped_events;
+static uint32_t trace_pid;
 static FILE *trace_fp;
 static char *trace_file_name;
 
@@ -83,7 +84,7 @@ typedef struct {
     uint64_t event; /*   TraceEventID */
     uint64_t timestamp_ns;
     uint32_t length;   /*    in bytes */
-    uint32_t reserved; /*    unused */
+    uint32_t pid;
     uint64_t arguments[];
 } TraceRecord;
 
@@ -190,7 +191,7 @@ static gpointer writeout_thread(gpointer opaque)
             dropped.rec.event = DROPPED_EVENT_ID,
             dropped.rec.timestamp_ns = get_clock();
             dropped.rec.length = sizeof(TraceRecord) + sizeof(uint64_t),
-            dropped.rec.reserved = 0;
+            dropped.rec.pid = trace_pid;
             do {
                 dropped_count = g_atomic_int_get(&dropped_events);
             } while (!g_atomic_int_compare_and_exchange(&dropped_events,
@@ -249,6 +250,7 @@ int trace_record_start(TraceBufferRecord *rec, TraceEventID event, size_t datasi
     rec_off = write_to_buffer(rec_off, &event_u64, sizeof(event_u64));
     rec_off = write_to_buffer(rec_off, &timestamp_ns, sizeof(timestamp_ns));
     rec_off = write_to_buffer(rec_off, &rec_len, sizeof(rec_len));
+    rec_off = write_to_buffer(rec_off, &trace_pid, sizeof(trace_pid));
 
     rec->tbuf_idx = idx;
     rec->rec_off  = (idx + sizeof(TraceRecord)) % TRACE_BUF_LEN;
@@ -414,6 +416,8 @@ bool trace_backend_init(const char *events, const char *file)
 {
     GThread *thread;
 
+    trace_pid = getpid();
+
 #if !GLIB_CHECK_VERSION(2, 31, 0)
     trace_available_cond = g_cond_new();
     trace_empty_cond = g_cond_new();
-- 
1.9.0

[Qemu-devel] [PATCH 2/2] simpletrace: add support for trace record pid field

[Stefan Hajnoczi]

Extract the pid field from the trace record and print it.

Change the trace record tuple from:
  (event_num, timestamp, arg1, ..., arg6)
to:
  (event_num, timestamp, pid, arg1, ..., arg6)

Trace event methods now support 3 prototypes:
1. <event-name>(arg1, arg2, arg3)
2. <event-name>(timestamp, arg1, arg2, arg3)
3. <event-name>(timestamp, pid, arg1, arg2, arg3)

Existing script continue to work without changes, they only know about
prototypes 1 and 2.

Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
---
 scripts/simpletrace.py | 26 +++++++++++++++-----------
 1 file changed, 15 insertions(+), 11 deletions(-)

diff --git a/scripts/simpletrace.py b/scripts/simpletrace.py
index 8bbcb42..e1b97d4 100755
--- a/scripts/simpletrace.py
+++ b/scripts/simpletrace.py
@@ -31,10 +31,10 @@ def read_header(fobj, hfmt):
     return struct.unpack(hfmt, hdr)
 
 def get_record(edict, rechdr, fobj):
-    """Deserialize a trace record from a file into a tuple (event_num, timestamp, arg1, ..., arg6)."""
+    """Deserialize a trace record from a file into a tuple (event_num, timestamp, pid, arg1, ..., arg6)."""
     if rechdr is None:
         return None
-    rec = (rechdr[0], rechdr[1])
+    rec = (rechdr[0], rechdr[1], rechdr[3])
     if rechdr[0] != dropped_event_id:
         event_id = rechdr[0]
         event = edict[event_id]
@@ -54,12 +54,12 @@ def get_record(edict, rechdr, fobj):
 
 
 def read_record(edict, fobj):
-    """Deserialize a trace record from a file into a tuple (event_num, timestamp, arg1, ..., arg6)."""
+    """Deserialize a trace record from a file into a tuple (event_num, timestamp, pid, arg1, ..., arg6)."""
     rechdr = read_header(fobj, rec_header_fmt)
     return get_record(edict, rechdr, fobj) # return tuple of record elements
 
 def read_trace_file(edict, fobj):
-    """Deserialize trace records from a file, yielding record tuples (event_num, timestamp, arg1, ..., arg6)."""
+    """Deserialize trace records from a file, yielding record tuples (event_num, timestamp, pid, arg1, ..., arg6)."""
     header = read_header(fobj, log_header_fmt)
     if header is None or \
        header[0] != header_event_id or \
@@ -131,10 +131,13 @@ def process(events, log, analyzer):
         fn_argcount = len(inspect.getargspec(fn)[0]) - 1
         if fn_argcount == event_argcount + 1:
             # Include timestamp as first argument
-            return lambda _, rec: fn(*rec[1:2 + event_argcount])
+            return lambda _, rec: fn(*((rec[1:2],) + rec[3:3 + event_argcount]))
+        elif fn_argcount == event_argcount + 2:
+            # Include timestamp and pid
+            return lambda _, rec: fn(*rec[1:3 + event_argcount])
         else:
-            # Just arguments, no timestamp
-            return lambda _, rec: fn(*rec[2:2 + event_argcount])
+            # Just arguments, no timestamp or pid
+            return lambda _, rec: fn(*rec[3:3 + event_argcount])
 
     analyzer.begin()
     fn_cache = {}
@@ -166,19 +169,20 @@ if __name__ == '__main__':
             self.last_timestamp = None
 
         def catchall(self, event, rec):
-            i = 1
             timestamp = rec[1]
             if self.last_timestamp is None:
                 self.last_timestamp = timestamp
             delta_ns = timestamp - self.last_timestamp
             self.last_timestamp = timestamp
 
-            fields = [event.name, '%0.3f' % (delta_ns / 1000.0)]
+            fields = [event.name, '%0.3f' % (delta_ns / 1000.0),
+                      'pid=%d' % rec[2]]
+            i = 3
             for type, name in event.args:
                 if is_string(type):
-                    fields.append('%s=%s' % (name, rec[i + 1]))
+                    fields.append('%s=%s' % (name, rec[i]))
                 else:
-                    fields.append('%s=0x%x' % (name, rec[i + 1]))
+                    fields.append('%s=0x%x' % (name, rec[i]))
                 i += 1
             print ' '.join(fields)
 
-- 
1.9.0

Re: [Qemu-devel] [PATCH 0/2] simpletrace: add pid field to simpletrace record

[Stefan Hajnoczi]

On Wed, May 07, 2014 at 07:24:09PM +0200, Stefan Hajnoczi wrote:
> This series adds a pid field to the simpletrace record.  This allows
> aggregation of simpletrace files as well as host-wide tracing since records can
> now be associated with a particular QEMU process.
> 
> Stefan Hajnoczi (2):
>   trace: add pid field to simpletrace record
>   simpletrace: add support for trace record pid field
> 
>  scripts/simpletrace.py | 26 +++++++++++++++-----------
>  trace/simple.c         |  8 ++++++--
>  2 files changed, 21 insertions(+), 13 deletions(-)

Applied to my tracing tree:
https://github.com/stefanha/qemu/commits/tracing

Stefan