[Qemu-devel] [PATCH v2 0/4] trace: add simpletrace-stap format to generate binary trace

[Qemu-devel] [PATCH v2 0/4] trace: add simpletrace-stap format to generate binary trace

[Stefan Hajnoczi]

v2:
 * I realized that v1 was not complete enough after feedback from Lluís and
   Frank Ch. Eigler, so here is a v2 after all.
 * Add Makefile target for simpletrace .stp file [Lluís]
 * Generate SystemTap probe aliases so users can select a subset of probes to
   enable [Frank Ch. Eigler]
 * Delete --no-header from sys.argv[] so further command-line parsing works

SystemTap is a popular tracing solution on Fedora and RHEL.  It does not have
its own trace file format, instead stap scripts have the freedom to output data
in whatever format is most appropriate.

QEMU supports the simpletrace binary format for built-in tracing that comes
with QEMU.  Since we need a format for persisting SystemTap traces and a binary
format has performance advantages, let's output simpletrace-compatible data.

This patch adds a new stap file that is autogenerated from trace-events.  The
following example shows how to use SystemTap and analyze the resulting trace
file with simpletrace.py:

  $ ./configure --enable-trace-backend=dtrace ... && make
  $ sudo stap x86_64-softmmu/qemu-system-x86_64-simpletrace.stp >trace
  ...run QEMU in another shell...
  ^C
  $ scripts/simpletrace.py --no-header trace-events trace

One new concept here is the simpletrace.py --no-header option.  SystemTap
supports flight-recorder mode where trace records are written into a ring
buffer.  The ring buffer can be dumped at any time so it is useful to skip the
simpletrace header check.

Stefan Hajnoczi (4):
  trace: extract stap_escape() function for reuse
  trace: add tracetool simpletrace_stap format
  simpletrace: add simpletrace.py --no-header option
  trace: install simpletrace SystemTap tapset

 Makefile.target                              | 10 +++-
 scripts/simpletrace.py                       | 24 +++++++---
 scripts/tracetool/format/simpletrace_stap.py | 71 ++++++++++++++++++++++++++++
 scripts/tracetool/format/stap.py             | 11 +++--
 4 files changed, 105 insertions(+), 11 deletions(-)
 create mode 100644 scripts/tracetool/format/simpletrace_stap.py

-- 
1.9.3

[Qemu-devel] [PATCH v2 1/4] trace: extract stap_escape() function for reuse

[Stefan Hajnoczi]

SystemTap reserved words sometimes conflict with QEMU variable names.
We escape them to prevent conflicts.

Move escaping into its own function so the next patch can reuse it.

Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
---
 scripts/tracetool/format/stap.py | 11 ++++++++---
 1 file changed, 8 insertions(+), 3 deletions(-)

diff --git a/scripts/tracetool/format/stap.py b/scripts/tracetool/format/stap.py
index e24abf7..9e780f1 100644
--- a/scripts/tracetool/format/stap.py
+++ b/scripts/tracetool/format/stap.py
@@ -27,6 +27,13 @@ RESERVED_WORDS = (
     )
 
 
+def stap_escape(identifier):
+    # Append underscore to reserved keywords
+    if identifier in RESERVED_WORDS:
+        return identifier + '_'
+    return identifier
+
+
 def generate(events, backend):
     events = [e for e in events
               if "disable" not in e.properties]
@@ -45,9 +52,7 @@ def generate(events, backend):
         i = 1
         if len(e.args) > 0:
             for name in e.args.names():
-                # Append underscore to reserved keywords
-                if name in RESERVED_WORDS:
-                    name += '_'
+                name = stap_escape(name)
                 out('  %s = $arg%d;' % (name, i))
                 i += 1
 
-- 
1.9.3

[Qemu-devel] [PATCH v2 2/4] trace: add tracetool simpletrace_stap format

[Stefan Hajnoczi]

This new tracetool "format" generates a SystemTap .stp file that outputs
simpletrace binary trace data.

In contrast to simpletrace or ftrace, SystemTap does not define its own
trace format.  All output from SystemTap is generated by .stp files.
This patch lets us generate a .stp file that outputs in the simpletrace
binary format.

This makes it possible to reuse simpletrace.py to analyze traces
recorded using SystemTap.  The simpletrace binary format is especially
useful for long-running traces like flight-recorder mode where string
formatting can be expensive.

Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
---
 scripts/tracetool/format/simpletrace_stap.py | 71 ++++++++++++++++++++++++++++
 1 file changed, 71 insertions(+)
 create mode 100644 scripts/tracetool/format/simpletrace_stap.py

diff --git a/scripts/tracetool/format/simpletrace_stap.py b/scripts/tracetool/format/simpletrace_stap.py
new file mode 100644
index 0000000..7e44bc1
--- /dev/null
+++ b/scripts/tracetool/format/simpletrace_stap.py
@@ -0,0 +1,71 @@
+#!/usr/bin/env python
+# -*- coding: utf-8 -*-
+
+"""
+Generate .stp file that outputs simpletrace binary traces (DTrace with SystemTAP only).
+"""
+
+__author__     = "Stefan Hajnoczi <redhat.com>"
+__copyright__  = "Copyright (C) 2014, Red Hat, Inc."
+__license__    = "GPL version 2 or (at your option) any later version"
+
+__maintainer__ = "Stefan Hajnoczi"
+__email__      = "stefanha@redhat.com"
+
+
+from tracetool import out
+from tracetool.backend.dtrace import binary, probeprefix
+from tracetool.backend.simple import is_string
+from tracetool.format.stap import stap_escape
+
+
+def generate(events, backend):
+    out('/* This file is autogenerated by tracetool, do not edit. */',
+        '')
+
+    for event_id, e in enumerate(events):
+        if 'disable' in e.properties:
+            continue
+
+        out('probe %(probeprefix)s.simpletrace.%(name)s = %(probeprefix)s.%(name)s ?',
+            '{',
+            probeprefix=probeprefix(),
+            name=e.name)
+
+        # Calculate record size
+        sizes = ['24'] # sizeof(TraceRecord)
+        for type_, name in e.args:
+            name = stap_escape(name)
+            if is_string(type_):
+                out('    try {',
+                    '        arg%(name)s_str = %(name)s ? user_string_n(%(name)s, 512) : "<null>"',
+                    '    } catch {}',
+                    '    arg%(name)s_len = strlen(arg%(name)s_str)',
+                    name=name)
+                sizes.append('4 + arg%s_len' % name)
+            else:
+                sizes.append('8')
+        sizestr = ' + '.join(sizes)
+
+        # Generate format string and value pairs for record header and arguments
+        fields = [('8b', str(event_id)),
+                  ('8b', 'gettimeofday_ns()'),
+                  ('4b', sizestr),
+                  ('4b', 'pid()')]
+        for type_, name in e.args:
+            name = stap_escape(name)
+            if is_string(type_):
+                fields.extend([('4b', 'arg%s_len' % name),
+                               ('.*s', 'arg%s_len, arg%s_str' % (name, name))])
+            else:
+                fields.append(('8b', name))
+
+        # Emit the entire record in a single SystemTap printf()
+        fmt_str = '%'.join(fmt for fmt, _ in fields)
+        arg_str = ', '.join(arg for _, arg in fields)
+        out('    printf("%%%(fmt_str)s", %(arg_str)s)',
+            fmt_str=fmt_str, arg_str=arg_str)
+
+        out('}')
+
+    out()
-- 
1.9.3

[Qemu-devel] [PATCH v2 3/4] simpletrace: add simpletrace.py --no-header option

[Stefan Hajnoczi]

It can be useful to read simpletrace files that have no header.  For
example, a ring buffer may not have a header record but can still be
processed if the user is sure the file format version is compatible.

  $ scripts/simpletrace.py --no-header trace-events trace-file

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

diff --git a/scripts/simpletrace.py b/scripts/simpletrace.py
index 1aa9460..3916c6d 100755
--- a/scripts/simpletrace.py
+++ b/scripts/simpletrace.py
@@ -58,8 +58,8 @@ def read_record(edict, fobj):
     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, pid, arg1, ..., arg6)."""
+def read_trace_header(fobj):
+    """Read and verify trace file header"""
     header = read_header(fobj, log_header_fmt)
     if header is None or \
        header[0] != header_event_id or \
@@ -73,6 +73,8 @@ def read_trace_file(edict, fobj):
         raise ValueError('Log format %d not supported with this QEMU release!'
                          % log_version)
 
+def read_trace_records(edict, fobj):
+    """Deserialize trace records from a file, yielding record tuples (event_num, timestamp, pid, arg1, ..., arg6)."""
     while True:
         rec = read_record(edict, fobj)
         if rec is None:
@@ -102,13 +104,16 @@ class Analyzer(object):
         """Called at the end of the trace."""
         pass
 
-def process(events, log, analyzer):
+def process(events, log, analyzer, read_header=True):
     """Invoke an analyzer on each event in a log."""
     if isinstance(events, str):
         events = _read_events(open(events, 'r'))
     if isinstance(log, str):
         log = open(log, 'rb')
 
+    if read_header:
+        read_trace_header(log)
+
     dropped_event = Event.build("Dropped_Event(uint64_t num_events_dropped)")
     edict = {dropped_event_id: dropped_event}
 
@@ -137,7 +142,7 @@ def process(events, log, analyzer):
 
     analyzer.begin()
     fn_cache = {}
-    for rec in read_trace_file(edict, log):
+    for rec in read_trace_records(edict, log):
         event_num = rec[0]
         event = edict[event_num]
         if event_num not in fn_cache:
@@ -152,12 +157,17 @@ def run(analyzer):
     advanced scripts will want to call process() instead."""
     import sys
 
-    if len(sys.argv) != 3:
-        sys.stderr.write('usage: %s <trace-events> <trace-file>\n' % sys.argv[0])
+    read_header = True
+    if len(sys.argv) == 4 and sys.argv[1] == '--no-header':
+        read_header = False
+        del sys.argv[1]
+    elif len(sys.argv) != 3:
+        sys.stderr.write('usage: %s [--no-header] <trace-events> ' \
+                         '<trace-file>\n' % sys.argv[0])
         sys.exit(1)
 
     events = _read_events(open(sys.argv[1], 'r'))
-    process(events, sys.argv[2], analyzer)
+    process(events, sys.argv[2], analyzer, read_header=read_header)
 
 if __name__ == '__main__':
     class Formatter(Analyzer):
-- 
1.9.3

[Qemu-devel] [PATCH v2 4/4] trace: install simpletrace SystemTap tapset

[Stefan Hajnoczi]

The simpletrace SystemTap tapset outputs simpletrace binary traces for
SystemTap probes.  This is useful because SystemTap has no default way
to format or store traces.  The simpletrace SystemTap tapset provides an
easy way to store traces.

The simpletrace.py tool or custom Python scripts using the
simpletrace.py API can analyze SystemTap these traces:

  $ ./configure --enable-trace-backends=dtrace ...
  $ make && make install
  $ stap -e 'probe qemu.system.x86_64.simpletrace.* {}' \
         -c qemu-system-x86_64 >/tmp/trace.out
  $ scripts/simpletrace.py --no-header trace-events /tmp/trace.out
  g_malloc 4.531 pid=15519 size=0xb ptr=0x7f8639c10470
  g_malloc 3.264 pid=15519 size=0x300 ptr=0x7f8639c10490
  g_free 5.155 pid=15519 ptr=0x7f8639c0f7b0

Note that, unlike qemu-system-x86_64.stp and
qemu-system-x86_64.stp-installed, only one file is needed since the
simpletrace SystemTap tapset does not reference the QEMU binary by path.
Therefore it doesn't matter whether the QEMU binary is installed or not.

Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
---
 Makefile.target | 10 +++++++++-
 1 file changed, 9 insertions(+), 1 deletion(-)

diff --git a/Makefile.target b/Makefile.target
index fc5827c..ec7f1b8 100644
--- a/Makefile.target
+++ b/Makefile.target
@@ -38,7 +38,7 @@ config-target.h: config-target.h-timestamp
 config-target.h-timestamp: config-target.mak
 
 ifdef CONFIG_TRACE_SYSTEMTAP
-stap: $(QEMU_PROG).stp-installed $(QEMU_PROG).stp
+stap: $(QEMU_PROG).stp-installed $(QEMU_PROG).stp $(QEMU_PROG)-simpletrace.stp
 
 ifdef CONFIG_USER_ONLY
 TARGET_TYPE=user
@@ -64,6 +64,13 @@ $(QEMU_PROG).stp: $(SRC_PATH)/trace-events
 		--target-type=$(TARGET_TYPE) \
 		< $< > $@,"  GEN   $(TARGET_DIR)$(QEMU_PROG).stp")
 
+$(QEMU_PROG)-simpletrace.stp: $(SRC_PATH)/trace-events
+	$(call quiet-command,$(TRACETOOL) \
+		--format=simpletrace-stap \
+		--backends=$(TRACE_BACKENDS) \
+		--probe-prefix=qemu.$(TARGET_TYPE).$(TARGET_NAME) \
+		< $< > $@,"  GEN   $(TARGET_DIR)$(QEMU_PROG)-simpletrace.stp")
+
 else
 stap:
 endif
@@ -198,6 +205,7 @@ endif
 ifdef CONFIG_TRACE_SYSTEMTAP
 	$(INSTALL_DIR) "$(DESTDIR)$(qemu_datadir)/../systemtap/tapset"
 	$(INSTALL_DATA) $(QEMU_PROG).stp-installed "$(DESTDIR)$(qemu_datadir)/../systemtap/tapset/$(QEMU_PROG).stp"
+	$(INSTALL_DATA) $(QEMU_PROG)-simpletrace.stp "$(DESTDIR)$(qemu_datadir)/../systemtap/tapset/$(QEMU_PROG)-simpletrace.stp"
 endif
 
 GENERATED_HEADERS += config-target.h
-- 
1.9.3

Re: [Qemu-devel] [PATCH v2 0/4] trace: add simpletrace-stap format to generate binary trace

[Stefan Hajnoczi]

[-- Attachment #1: Type: text/plain, Size: 2352 bytes --]

On Sun, Jun 22, 2014 at 09:46:03PM +0800, Stefan Hajnoczi wrote:
> v2:
>  * I realized that v1 was not complete enough after feedback from Lluís and
>    Frank Ch. Eigler, so here is a v2 after all.
>  * Add Makefile target for simpletrace .stp file [Lluís]
>  * Generate SystemTap probe aliases so users can select a subset of probes to
>    enable [Frank Ch. Eigler]
>  * Delete --no-header from sys.argv[] so further command-line parsing works
> 
> SystemTap is a popular tracing solution on Fedora and RHEL.  It does not have
> its own trace file format, instead stap scripts have the freedom to output data
> in whatever format is most appropriate.
> 
> QEMU supports the simpletrace binary format for built-in tracing that comes
> with QEMU.  Since we need a format for persisting SystemTap traces and a binary
> format has performance advantages, let's output simpletrace-compatible data.
> 
> This patch adds a new stap file that is autogenerated from trace-events.  The
> following example shows how to use SystemTap and analyze the resulting trace
> file with simpletrace.py:
> 
>   $ ./configure --enable-trace-backend=dtrace ... && make
>   $ sudo stap x86_64-softmmu/qemu-system-x86_64-simpletrace.stp >trace
>   ...run QEMU in another shell...
>   ^C
>   $ scripts/simpletrace.py --no-header trace-events trace
> 
> One new concept here is the simpletrace.py --no-header option.  SystemTap
> supports flight-recorder mode where trace records are written into a ring
> buffer.  The ring buffer can be dumped at any time so it is useful to skip the
> simpletrace header check.
> 
> Stefan Hajnoczi (4):
>   trace: extract stap_escape() function for reuse
>   trace: add tracetool simpletrace_stap format
>   simpletrace: add simpletrace.py --no-header option
>   trace: install simpletrace SystemTap tapset
> 
>  Makefile.target                              | 10 +++-
>  scripts/simpletrace.py                       | 24 +++++++---
>  scripts/tracetool/format/simpletrace_stap.py | 71 ++++++++++++++++++++++++++++
>  scripts/tracetool/format/stap.py             | 11 +++--
>  4 files changed, 105 insertions(+), 11 deletions(-)
>  create mode 100644 scripts/tracetool/format/simpletrace_stap.py

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

Stefan

[-- Attachment #2: Type: application/pgp-signature, Size: 473 bytes --]