[Top][All Lists]
[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]
Re: [Qemu-devel] [PATCH 07/14] trace: Add simple built-in tracing backen
From: |
Blue Swirl |
Subject: |
Re: [Qemu-devel] [PATCH 07/14] trace: Add simple built-in tracing backend |
Date: |
Thu, 12 Aug 2010 17:56:57 +0000 |
On Thu, Aug 12, 2010 at 10:36 AM, Stefan Hajnoczi
<address@hidden> 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 <address@hidden>
>
> 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 <address@hidden>.
>
> Signed-off-by: Prerna Saxena <address@hidden>
> Signed-off-by: Stefan Hajnoczi <address@hidden>
> ---
> .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
>
>
>
- [Qemu-devel] [PATCH 00/14] trace: Add static tracing to QEMU, Stefan Hajnoczi, 2010/08/12
- [Qemu-devel] [PATCH 13/14] trace: Add LTTng Userspace Tracer backend, Stefan Hajnoczi, 2010/08/12
- [Qemu-devel] [PATCH 12/14] trace: Add trace file name command-line option, Stefan Hajnoczi, 2010/08/12
- [Qemu-devel] [PATCH 07/14] trace: Add simple built-in tracing backend, Stefan Hajnoczi, 2010/08/12
- Re: [Qemu-devel] [PATCH 07/14] trace: Add simple built-in tracing backend,
Blue Swirl <=
- [Qemu-devel] [PATCH 14/14] trace: Add user documentation, Stefan Hajnoczi, 2010/08/12
- [Qemu-devel] [PATCH 03/14] trace: Trace virtio-blk, multiwrite, and paio_submit, Stefan Hajnoczi, 2010/08/12
- [Qemu-devel] [PATCH 08/14] trace: Support for dynamically enabling/disabling trace events., Stefan Hajnoczi, 2010/08/12
- [Qemu-devel] [PATCH 11/14] trace: Add trace-file command to open/close/flush trace file, Stefan Hajnoczi, 2010/08/12
- [Qemu-devel] [PATCH 01/14] trace: Add trace-events file for declaring trace events, Stefan Hajnoczi, 2010/08/12