[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]
[Qemu-devel] [PULL v2 10/20] trace: emit name <-> ID mapping in simpletr
From: |
Stefan Hajnoczi |
Subject: |
[Qemu-devel] [PULL v2 10/20] trace: emit name <-> ID mapping in simpletrace header |
Date: |
Wed, 12 Oct 2016 10:47:28 +0200 |
From: "Daniel P. Berrange" <address@hidden>
Currently simpletrace assumes that events are given IDs
starting from 0, based on the order in which they appear
in the trace-events file, with no gaps. When the
trace-events file is split up, this assumption becomes
problematic.
To deal with this, extend the simpletrace format so that
it outputs a table of event name <-> ID mappings. That
will allow QEMU to assign arbitrary IDs to events without
breaking simpletrace parsing.
The v3 simple trace format was
FILE HEADER
EVENT TRACE RECORD 0
EVENT TRACE RECORD 1
...
EVENT TRACE RECORD N
The v4 simple trace format is now
FILE HEADER
EVENT MAPPING RECORD 0
EVENT MAPPING RECORD 1
...
EVENT MAPPING RECORD M
EVENT TRACE RECORD RECORD 0
EVENT TRACE RECORD RECORD 1
...
EVENT TRACE RECORD N
Although this shows all the mapping records being emitted
upfront, this is not required by the format. While the main
simpletrace backend will emit all mappings at startup,
the systemtap simpletrace.stp script will emit the mappings
at first use. eg
FILE HEADER
...
EVENT MAPPING RECORD 0
EVENT TRACE RECORD RECORD 0
EVENT TRACE RECORD RECORD 1
EVENT MAPPING RECORD 1
EVENT TRACE RECORD RECORD 2
...
EVENT TRACE RECORD N
This is more space efficient given that most trace records
only include a subset of events.
In modifying the systemtap simpletrace code, a 'begin' probe
was added to emit the trace event header, so you no longer
need to add '--no-header' when running simpletrace.py for
systemtap generated trace files.
Signed-off-by: Daniel P. Berrange <address@hidden>
Message-id: address@hidden
Signed-off-by: Stefan Hajnoczi <address@hidden>
---
scripts/simpletrace.py | 50 ++++++++++++++++++++--------
scripts/tracetool/format/simpletrace_stap.py | 24 +++++++++++--
trace/simple.c | 33 ++++++++++++++++--
3 files changed, 89 insertions(+), 18 deletions(-)
diff --git a/scripts/simpletrace.py b/scripts/simpletrace.py
index 3916c6d..f40467a 100755
--- a/scripts/simpletrace.py
+++ b/scripts/simpletrace.py
@@ -19,6 +19,9 @@ header_event_id = 0xffffffffffffffff
header_magic = 0xf2b177cb0aa429b4
dropped_event_id = 0xfffffffffffffffe
+record_type_mapping = 0
+record_type_event = 1
+
log_header_fmt = '=QQQ'
rec_header_fmt = '=QQII'
@@ -30,14 +33,16 @@ def read_header(fobj, hfmt):
return None
return struct.unpack(hfmt, hdr)
-def get_record(edict, rechdr, fobj):
- """Deserialize a trace record from a file into a tuple (event_num,
timestamp, pid, arg1, ..., arg6)."""
+def get_record(edict, idtoname, rechdr, fobj):
+ """Deserialize a trace record from a file into a tuple
+ (name, timestamp, pid, arg1, ..., arg6)."""
if rechdr is None:
return None
- rec = (rechdr[0], rechdr[1], rechdr[3])
if rechdr[0] != dropped_event_id:
event_id = rechdr[0]
- event = edict[event_id]
+ name = idtoname[event_id]
+ rec = (name, rechdr[1], rechdr[3])
+ event = edict[name]
for type, name in event.args:
if is_string(type):
l = fobj.read(4)
@@ -48,15 +53,22 @@ def get_record(edict, rechdr, fobj):
(value,) = struct.unpack('=Q', fobj.read(8))
rec = rec + (value,)
else:
+ rec = ("dropped", rechdr[1], rechdr[3])
(value,) = struct.unpack('=Q', fobj.read(8))
rec = rec + (value,)
return rec
+def get_mapping(fobj):
+ (event_id, ) = struct.unpack('=Q', fobj.read(8))
+ (len, ) = struct.unpack('=L', fobj.read(4))
+ name = fobj.read(len)
-def read_record(edict, fobj):
+ return (event_id, name)
+
+def read_record(edict, idtoname, fobj):
"""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
+ return get_record(edict, idtoname, rechdr, fobj)
def read_trace_header(fobj):
"""Read and verify trace file header"""
@@ -67,20 +79,30 @@ def read_trace_header(fobj):
raise ValueError('Not a valid trace file!')
log_version = header[2]
- if log_version not in [0, 2, 3]:
+ if log_version not in [0, 2, 3, 4]:
raise ValueError('Unknown version of tracelog format!')
- if log_version != 3:
+ if log_version != 4:
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)."""
+ idtoname = {
+ dropped_event_id: "dropped"
+ }
while True:
- rec = read_record(edict, fobj)
- if rec is None:
+ t = fobj.read(8)
+ if len(t) == 0:
break
- yield rec
+ (rectype, ) = struct.unpack('=Q', t)
+ if rectype == record_type_mapping:
+ event_id, name = get_mapping(fobj)
+ idtoname[event_id] = name
+ else:
+ rec = read_record(edict, idtoname, fobj)
+
+ yield rec
class Analyzer(object):
"""A trace file analyzer which processes trace records.
@@ -115,10 +137,10 @@ def process(events, log, analyzer, read_header=True):
read_trace_header(log)
dropped_event = Event.build("Dropped_Event(uint64_t num_events_dropped)")
- edict = {dropped_event_id: dropped_event}
+ edict = {"dropped": dropped_event}
- for num, event in enumerate(events):
- edict[num] = event
+ for event in events:
+ edict[event.name] = event
def build_fn(analyzer, event):
if isinstance(event, str):
diff --git a/scripts/tracetool/format/simpletrace_stap.py
b/scripts/tracetool/format/simpletrace_stap.py
index 7e44bc1..ac3580f 100644
--- a/scripts/tracetool/format/simpletrace_stap.py
+++ b/scripts/tracetool/format/simpletrace_stap.py
@@ -21,6 +21,25 @@ from tracetool.format.stap import stap_escape
def generate(events, backend):
out('/* This file is autogenerated by tracetool, do not edit. */',
+ '',
+ 'global event_name_to_id_map',
+ 'global event_next_id',
+ 'function simple_trace_map_event(name)',
+ '',
+ '{',
+ ' if (!([name] in event_name_to_id_map)) {',
+ ' event_name_to_id_map[name] = event_next_id',
+ ' name_len = strlen(name)',
+ ' printf("%%8b%%8b%%4b%%.*s", 0, ',
+ ' event_next_id, name_len, name_len, name)',
+ ' event_next_id = event_next_id + 1',
+ ' }',
+ ' return event_name_to_id_map[name]',
+ '}',
+ 'probe begin',
+ '{',
+ ' printf("%%8b%%8b%%8b", 0xffffffffffffffff, 0xf2b177cb0aa429b4,
4)',
+ '}',
'')
for event_id, e in enumerate(events):
@@ -29,6 +48,7 @@ def generate(events, backend):
out('probe %(probeprefix)s.simpletrace.%(name)s =
%(probeprefix)s.%(name)s ?',
'{',
+ ' id = simple_trace_map_event("%(name)s")',
probeprefix=probeprefix(),
name=e.name)
@@ -48,7 +68,7 @@ def generate(events, backend):
sizestr = ' + '.join(sizes)
# Generate format string and value pairs for record header and
arguments
- fields = [('8b', str(event_id)),
+ fields = [('8b', 'id'),
('8b', 'gettimeofday_ns()'),
('4b', sizestr),
('4b', 'pid()')]
@@ -63,7 +83,7 @@ def generate(events, backend):
# 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)',
+ out(' printf("%%8b%%%(fmt_str)s", 1, %(arg_str)s)',
fmt_str=fmt_str, arg_str=arg_str)
out('}')
diff --git a/trace/simple.c b/trace/simple.c
index 2ec32e1..b263622 100644
--- a/trace/simple.c
+++ b/trace/simple.c
@@ -24,7 +24,7 @@
#define HEADER_MAGIC 0xf2b177cb0aa429b4ULL
/** Trace file version number, bump if format changes */
-#define HEADER_VERSION 3
+#define HEADER_VERSION 4
/** Records were dropped event ID */
#define DROPPED_EVENT_ID (~(uint64_t)0 - 1)
@@ -56,6 +56,9 @@ static uint32_t trace_pid;
static FILE *trace_fp;
static char *trace_file_name;
+#define TRACE_RECORD_TYPE_MAPPING 0
+#define TRACE_RECORD_TYPE_EVENT 1
+
/* * Trace buffer entry */
typedef struct {
uint64_t event; /* event ID value */
@@ -160,6 +163,7 @@ static gpointer writeout_thread(gpointer opaque)
unsigned int idx = 0;
int dropped_count;
size_t unused __attribute__ ((unused));
+ uint64_t type = TRACE_RECORD_TYPE_EVENT;
for (;;) {
wait_for_trace_records_available();
@@ -174,10 +178,12 @@ static gpointer writeout_thread(gpointer opaque)
} while (!g_atomic_int_compare_and_exchange(&dropped_events,
dropped_count, 0));
dropped.rec.arguments[0] = dropped_count;
+ unused = fwrite(&type, sizeof(type), 1, trace_fp);
unused = fwrite(&dropped.rec, dropped.rec.length, 1, trace_fp);
}
while (get_trace_record(idx, &recordptr)) {
+ unused = fwrite(&type, sizeof(type), 1, trace_fp);
unused = fwrite(recordptr, recordptr->length, 1, trace_fp);
writeout_idx += recordptr->length;
free(recordptr); /* don't use g_free, can deadlock when traced */
@@ -273,6 +279,28 @@ void trace_record_finish(TraceBufferRecord *rec)
}
}
+static int st_write_event_mapping(void)
+{
+ uint64_t type = TRACE_RECORD_TYPE_MAPPING;
+ TraceEventIter iter;
+ TraceEvent *ev;
+
+ trace_event_iter_init(&iter, NULL);
+ while ((ev = trace_event_iter_next(&iter)) != NULL) {
+ uint64_t id = trace_event_get_id(ev);
+ const char *name = trace_event_get_name(ev);
+ uint32_t len = strlen(name);
+ if (fwrite(&type, sizeof(type), 1, trace_fp) != 1 ||
+ fwrite(&id, sizeof(id), 1, trace_fp) != 1 ||
+ fwrite(&len, sizeof(len), 1, trace_fp) != 1 ||
+ fwrite(name, len, 1, trace_fp) != 1) {
+ return -1;
+ }
+ }
+
+ return 0;
+}
+
void st_set_trace_file_enabled(bool enable)
{
if (enable == !!trace_fp) {
@@ -297,7 +325,8 @@ void st_set_trace_file_enabled(bool enable)
return;
}
- if (fwrite(&header, sizeof header, 1, trace_fp) != 1) {
+ if (fwrite(&header, sizeof header, 1, trace_fp) != 1 ||
+ st_write_event_mapping() < 0) {
fclose(trace_fp);
trace_fp = NULL;
return;
--
2.7.4
- [Qemu-devel] [PULL v2 00/20] Tracing patches, Stefan Hajnoczi, 2016/10/12
- [Qemu-devel] [PULL v2 01/20] trace: move colo trace events to net/ sub-directory, Stefan Hajnoczi, 2016/10/12
- [Qemu-devel] [PULL v2 04/20] trace: remove some now unused functions, Stefan Hajnoczi, 2016/10/12
- [Qemu-devel] [PULL v2 02/20] trace: add trace event iterator APIs, Stefan Hajnoczi, 2016/10/12
- [Qemu-devel] [PULL v2 03/20] trace: convert code to use event iterators, Stefan Hajnoczi, 2016/10/12
- [Qemu-devel] [PULL v2 05/20] trace: remove global 'uint16 dstate[]' array, Stefan Hajnoczi, 2016/10/12
- [Qemu-devel] [PULL v2 06/20] trace: remove duplicate control.h includes in generated-tracers.h, Stefan Hajnoczi, 2016/10/12
- [Qemu-devel] [PULL v2 07/20] trace: break circular dependency in event-internal.h, Stefan Hajnoczi, 2016/10/12
- [Qemu-devel] [PULL v2 08/20] trace: give each trace event a named TraceEvent struct, Stefan Hajnoczi, 2016/10/12
- [Qemu-devel] [PULL v2 09/20] trace: remove the TraceEventID and TraceEventVCPUID enums, Stefan Hajnoczi, 2016/10/12
- [Qemu-devel] [PULL v2 10/20] trace: emit name <-> ID mapping in simpletrace header,
Stefan Hajnoczi <=
- [Qemu-devel] [PULL v2 11/20] trace: don't abort qemu if ftrace can't be initialized, Stefan Hajnoczi, 2016/10/12
- [Qemu-devel] [PULL v2 12/20] trace: provide mechanism for registering trace events, Stefan Hajnoczi, 2016/10/12
- [Qemu-devel] [PULL v2 13/20] trace: dynamically allocate trace_dstate in CPUState, Stefan Hajnoczi, 2016/10/12
- [Qemu-devel] [PULL v2 14/20] trace: dynamically allocate event IDs at runtime, Stefan Hajnoczi, 2016/10/12
- [Qemu-devel] [PULL v2 15/20] trace: get rid of generated-events.h/generated-events.c, Stefan Hajnoczi, 2016/10/12
- [Qemu-devel] [PULL v2 16/20] trace: rename _read_events to read_events, Stefan Hajnoczi, 2016/10/12
- [Qemu-devel] [PULL v2 17/20] trace: push reading of events up a level to tracetool main, Stefan Hajnoczi, 2016/10/12
- [Qemu-devel] [PULL v2 18/20] trace: pass trace-events to tracetool as a positional param, Stefan Hajnoczi, 2016/10/12
- [Qemu-devel] [PULL v2 20/20] trace: Add missing execution mode of guest events, Stefan Hajnoczi, 2016/10/12
- [Qemu-devel] [PULL v2 19/20] trace: introduce a formal group name for trace events, Stefan Hajnoczi, 2016/10/12