On Thu, Aug 12, 2010 at 10:36 AM, Stefan Hajnoczi <stefa...@linux.vnet.ibm.com> wrote: > This patch adds a simple tracer which produces binary trace files. 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 > > The output of simpletrace.py looks like this: > > qemu_realloc 0.699 ptr=0x24363f0 size=0x3 newptr=0x24363f0 > qemu_free 0.768 ptr=0x24363f0 > ^ ^---- timestamp delta (us) > |____ trace event name > > Signed-off-by: Stefan Hajnoczi <stefa...@linux.vnet.ibm.com> > > trace: Make trace record fields 64-bit > > Explicitly use 64-bit fields in trace records so that timestamps and > magic numbers work for 32-bit host builds. > > Includes fixes from Prerna Saxena <pre...@linux.vnet.ibm.com>. > > Signed-off-by: Prerna Saxena <pre...@linux.vnet.ibm.com> > Signed-off-by: Stefan Hajnoczi <stefa...@linux.vnet.ibm.com> > --- > .gitignore | 1 + > Makefile | 2 + > Makefile.objs | 3 + > configure | 2 +- > simpletrace.c | 127 > ++++++++++++++++++++++++++++++++++++++++++++++++++++++++ > simpletrace.h | 26 +++++++++++ > simpletrace.py | 96 ++++++++++++++++++++++++++++++++++++++++++ > tracetool | 82 ++++++++++++++++++++++++++++++++++-- > 8 files changed, 333 insertions(+), 6 deletions(-) > create mode 100644 simpletrace.c > create mode 100644 simpletrace.h > create mode 100755 simpletrace.py > > diff --git a/.gitignore b/.gitignore > index f3f2bb7..72bff98 100644 > --- a/.gitignore > +++ b/.gitignore > @@ -42,6 +42,7 @@ QMP/qmp-commands.txt > *.log > *.pdf > *.pg > +*.pyc > *.toc > *.tp > *.vr > diff --git a/Makefile b/Makefile > index 3c5e6a0..ab91d42 100644 > --- a/Makefile > +++ b/Makefile > @@ -112,6 +112,8 @@ trace.c: $(SRC_PATH)/trace-events config-host.mak > > trace.o: trace.c $(GENERATED_HEADERS) > > +simpletrace.o: simpletrace.c $(GENERATED_HEADERS) > + > ###################################################################### > > qemu-img.o: qemu-img-cmds.h > diff --git a/Makefile.objs b/Makefile.objs > index c61332d..3ef6d80 100644 > --- a/Makefile.objs > +++ b/Makefile.objs > @@ -269,6 +269,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 d3648b2..62dd10d 100755 > --- a/configure > +++ b/configure > @@ -898,7 +898,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..a6afc51 > --- /dev/null > +++ b/simpletrace.c > @@ -0,0 +1,127 @@ > +/* > + * Simple trace backend > + * > + * Copyright IBM, Corp. 2010 > + * > + * This work is licensed under the terms of the GNU GPL, version 2. See > + * the COPYING file in the top-level directory. > + * > + */ > + > +#include <stdlib.h> > +#include <stdint.h> > +#include <stdio.h> > +#include "trace.h" > + > +/** Trace file header event ID */ > +#define HEADER_EVENT_ID (~(uint64_t)0) /* avoids conflicting with > TraceEventIDs */ > + > +/** Trace file magic number */ > +#define HEADER_MAGIC 0xf2b177cb0aa429b4ULL > + > +/** Trace file version number, bump if format changes */ > +#define HEADER_VERSION 0 > + > +/** Trace buffer entry */ > +typedef struct { > + uint64_t event; > + uint64_t timestamp_ns; > + uint64_t x1; > + uint64_t x2; > + uint64_t x3; > + uint64_t x4; > + uint64_t 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 bool write_header(FILE *fp) > +{ > + TraceRecord header = {
This should be 'static const'. > + .event = HEADER_EVENT_ID, > + .timestamp_ns = HEADER_MAGIC, > + .x1 = HEADER_VERSION, > + }; > + > + return fwrite(&header, sizeof header, 1, fp) == 1; > +} > + > +static void flush_trace_buffer(void) > +{ > + if (!trace_fp) { > + trace_fp = fopen("/tmp/trace.log", "w"); > + if (trace_fp) { > + write_header(trace_fp); > + atexit(flush_trace_buffer); > + } > + } > + if (trace_fp) { > + size_t unused; /* for when fwrite(3) is declared warn_unused_result > */ > + unused = fwrite(trace_buf, trace_idx * sizeof(trace_buf[0]), 1, > trace_fp); > + } > + > + /* Discard written trace records */ > + trace_idx = 0; > +} > + > +static void trace(TraceEventID event, unsigned long x1, > + unsigned long x2, unsigned long x3, > + unsigned long x4, unsigned long x5) > +{ > + TraceRecord *rec = &trace_buf[trace_idx]; > + struct timespec ts; > + > + /* TODO Windows? It would be good to use qemu-timer here but that isn't > + * linked into qemu-tools. Also we should avoid recursion in the tracing > + * code, therefore it is useful to be self-contained. > + */ > + clock_gettime(CLOCK_MONOTONIC, &ts); > + > + rec->event = event; > + rec->timestamp_ns = ts.tv_sec * 1000000000LL + ts.tv_nsec; > + rec->x1 = x1; > + rec->x2 = x2; > + rec->x3 = x3; > + rec->x4 = x4; > + rec->x5 = x5; > + > + if (++trace_idx == TRACE_BUF_LEN) { > + flush_trace_buffer(); > + } > +} > + > +void trace0(TraceEventID event) > +{ > + trace(event, 0, 0, 0, 0, 0); > +} > + > +void trace1(TraceEventID event, uint64_t x1) > +{ > + trace(event, x1, 0, 0, 0, 0); > +} > + > +void trace2(TraceEventID event, uint64_t x1, uint64_t x2) > +{ > + trace(event, x1, x2, 0, 0, 0); > +} > + > +void trace3(TraceEventID event, uint64_t x1, uint64_t x2, uint64_t x3) > +{ > + trace(event, x1, x2, x3, 0, 0); > +} > + > +void trace4(TraceEventID event, uint64_t x1, uint64_t x2, uint64_t x3, > uint64_t x4) > +{ > + trace(event, x1, x2, x3, x4, 0); > +} > + > +void trace5(TraceEventID event, uint64_t x1, uint64_t x2, uint64_t x3, > uint64_t x4, uint64_t x5) > +{ > + trace(event, x1, x2, x3, x4, x5); > +} > diff --git a/simpletrace.h b/simpletrace.h > new file mode 100644 > index 0000000..e4e9759 > --- /dev/null > +++ b/simpletrace.h > @@ -0,0 +1,26 @@ > +/* > + * Simple trace backend > + * > + * Copyright IBM, Corp. 2010 > + * > + * This work is licensed under the terms of the GNU GPL, version 2. See > + * the COPYING file in the top-level directory. > + * > + */ > + > +#ifndef SIMPLETRACE_H > +#define SIMPLETRACE_H > + > +#include <stdbool.h> Why? > +#include <stdint.h> > + > +typedef uint64_t TraceEventID; > + > +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); > + > +#endif /* SIMPLETRACE_H */ > diff --git a/simpletrace.py b/simpletrace.py > new file mode 100755 > index 0000000..fdf0eb5 > --- /dev/null > +++ b/simpletrace.py > @@ -0,0 +1,96 @@ > +#!/usr/bin/env python > +# > +# Pretty-printer for simple trace backend binary trace files > +# > +# Copyright IBM, Corp. 2010 > +# > +# This work is licensed under the terms of the GNU GPL, version 2. See > +# the COPYING file in the top-level directory. > +# > +# For help see docs/tracing.txt > + > +import sys > +import struct > +import re > + > +header_event_id = 0xffffffffffffffff > +header_magic = 0xf2b177cb0aa429b4 > +header_version = 0 > + > +trace_fmt = '=QQQQQQQ' > +trace_len = struct.calcsize(trace_fmt) > +event_re = > re.compile(r'(disable\s+)?([a-zA-Z0-9_]+)\(([^)]*)\)\s+"([^"]*)"') > + > +def err(msg): > + sys.stderr.write(msg + '\n') > + sys.exit(1) > + > +def parse_events(fobj): > + """Parse a trace-events file.""" > + > + def get_argnames(args): > + """Extract argument names from a parameter list.""" > + 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): > + """Deserialize a trace record from a file.""" > + s = fobj.read(trace_len) > + if len(s) != trace_len: > + return None > + return struct.unpack(trace_fmt, s) > + > +def read_trace_file(fobj): > + """Deserialize trace records from a file.""" > + header = read_record(fobj) > + if header is None or \ > + header[0] != header_event_id or \ > + header[1] != header_magic or \ > + header[2] != header_version: > + err('not a trace file or incompatible version') > + > + while True: > + rec = read_record(fobj) > + if rec is None: > + break > + > + yield rec > + > +class Formatter(object): > + def __init__(self, events): > + self.events = events > + self.last_timestamp = None > + > + def format_record(self, rec): > + if self.last_timestamp is None: > + self.last_timestamp = rec[1] > + delta_ns = rec[1] - self.last_timestamp > + self.last_timestamp = rec[1] > + > + event = self.events[rec[0]] > + fields = [event[0], '%0.3f' % (delta_ns / 1000.0)] > + for i in xrange(1, len(event)): > + fields.append('%s=0x%x' % (event[i], rec[i + 1])) > + return ' '.join(fields) > + > +if len(sys.argv) != 3: > + err('usage: %s <trace-events> <trace-file>' % sys.argv[0]) > + > +events = parse_events(open(sys.argv[1], 'r')) > +formatter = Formatter(events) > +for rec in read_trace_file(open(sys.argv[2], 'rb')): > + print formatter.format_record(rec) > diff --git a/tracetool b/tracetool > index 86b6446..66df685 100755 > --- a/tracetool > +++ b/tracetool > @@ -13,11 +13,12 @@ set -f > 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 > @@ -56,16 +57,27 @@ get_argnames() > name=${field%,} > test "$field" = "$name" && continue > > - echo -n "$name, " > + printf "%s" "$name, " > done > > # Last argument name > if [ "$nfields" -gt 1 ] > then > - echo -n "$name" > + printf "%s" "$name" > fi > } > > +# 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() > { > @@ -115,6 +127,66 @@ linetoc_end_nop() > return > } > > +linetoh_begin_simple() > +{ > + cat <<EOF > +#include "simpletrace.h" > +EOF > + > + simple_event_num=0 > +} > + > +cast_args_to_uint64_t() > +{ > + local arg > + for arg in $(get_argnames "$1"); do > + printf "%s" "(uint64_t)(uintptr_t)$arg" > + done > +} > + > +linetoh_simple() > +{ > + local name args argc trace_args > + name=$(get_name "$1") > + args=$(get_args "$1") > + argc=$(get_argc "$1") > + > + trace_args="$simple_event_num" > + if [ "$argc" -gt 0 ] > + then > + trace_args="$trace_args, $(cast_args_to_uint64_t "$1")" > + fi > + > + cat <<EOF > +static inline void trace_$name($args) > +{ > + trace$argc($trace_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() > { > @@ -160,7 +232,7 @@ tracetoc() > > # Choose backend > case "$1" in > -"--nop") backend="${1#--}" ;; > +"--nop" | "--simple") backend="${1#--}" ;; > *) usage ;; > esac > shift > -- > 1.7.1 > > >