Re: [PATCH 05/11] perf data: Add tracepoint events fields CTF conversion support

From: Arnaldo Carvalho de Melo
Date: Wed Feb 25 2015 - 16:49:48 EST


Em Fri, Feb 20, 2015 at 11:17:02PM +0100, Jiri Olsa escreveu:
> From: Sebastian Andrzej Siewior <bigeasy@xxxxxxxxxxxxx>
> Adding support to convert tracepoint event fields into CTF
> event fields.

> We parse each tracepoint event for CTF conversion and add
> tracepoint fields as regular CTF event fields, so they
> appear in babeltrace output like:

> $ babeltrace ./ctf-data/
> ...
> [09:02:00.950703057] (+?.?????????) sched:sched_stat_runtime: { }, { perf_ip = ... SNIP ... common_type = 298, common_flags = 1, \
> common_preempt_count = 0, common_pid = 31813, comm = "perf", pid = 31813, runtime = 458800, vruntime = 52059858071 }
> ...

Processed the previous patches, everything ok:

[acme@ssdandy linux]$ ls -la perf.data
ls: cannot access perf.data: No such file or directory
[acme@ssdandy linux]$ trace record usleep 1
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.029 MB perf.data (88 samples) ]
[acme@ssdandy linux]$ ls -la perf.data
-rw-------. 1 acme acme 5399896 Fev 25 16:19 perf.data
[acme@ssdandy linux]$ perf evlist
raw_syscalls:sys_enter
raw_syscalls:sys_exit
[acme@ssdandy linux]$ perf evlist -v
raw_syscalls:sys_enter: sample_freq=1, type: 2, config: 75, size: 104, sample_type: IP|TID|TIME|ID|CPU|PERIOD|RAW, read_format: ID, disabled: 1, inherit: 1, mmap: 1, mmap2: 1, comm: 1, comm_exec: 1, enable_on_exec: 1, task: 1, sample_id_all: 1, exclude_guest: 1
raw_syscalls:sys_exit: sample_freq=1, type: 2, config: 74, size: 104, sample_type: IP|TID|TIME|ID|CPU|PERIOD|RAW, read_format: ID, disabled: 1, inherit: 1, enable_on_exec: 1, sample_id_all: 1, exclude_guest: 1
[acme@ssdandy linux]$ perf data convert --to-ctf=./ctf-data/
[ perf data convert: Converted 'perf.data' into CTF data './ctf-data/' ]
[ perf data convert: Converted and wrote 0.009 MB (88 samples) ]
[acme@ssdandy linux]$ babeltrace ./ctf-data/
[23:48:47.557933780] (+?.?????????) raw_syscalls:sys_exit: { }, { perf_ip = 0xFFFFFFFF81020FBA, perf_tid = 5093, perf_pid = 5093, perf_id = 1512, perf_cpu = 3, perf_period = 1 }
[23:48:47.557957461] (+0.000023681) raw_syscalls:sys_enter: { }, { perf_ip = 0xFFFFFFFF81020EA6, perf_tid = 5093, perf_pid = 5093, perf_id = 1504, perf_cpu = 3, perf_period = 1 }
[23:48:47.557958406] (+0.000000945) raw_syscalls:sys_exit: { }, { perf_ip = 0xFFFFFFFF81020FBA, perf_tid = 5093, perf_pid = 5093, perf_id = 1512, perf_cpu = 3, perf_period = 1 }
[23:48:47.557973567] (+0.000015161) raw_syscalls:sys_enter: { }, { perf_ip = 0xFFFFFFFF81020EA6, perf_tid = 5093, perf_pid = 5093, perf_id = 1504, perf_cpu = 3, perf_period = 1 }
[23:48:47.557976047] (+0.000002480) raw_syscalls:sys_exit: { }, { perf_ip = 0xFFFFFFFF81020FBA, perf_tid = 5093, perf_pid = 5093, perf_id = 1512, perf_cpu = 3, perf_period = 1 }
[23:48:47.557985774] (+0.000009727) raw_syscalls:sys_enter: { }, { perf_ip = 0xFFFFFFFF81020EA6, perf_tid = 5093, perf_pid = 5093, perf_id = 1504, perf_cpu = 3, perf_period = 1 }
[23:48:47.557990826] (+0.000005052) raw_syscalls:sys_exit: { }, { perf_ip = 0xFFFFFFFF81020FBA, perf_tid = 5093, perf_pid = 5093, perf_id = 1512, perf_cpu = 3, perf_period = 1 }
<SNIP>

But then I apply this patch (convert tracepoint events fields into CTF event fields) and:

[acme@ssdandy linux]$ perf data convert --to-ctf=./ctf-data/
[ perf data convert: Converted 'perf.data' into CTF data './ctf-data/' ]
[ perf data convert: Converted and wrote 0.009 MB (88 samples) ]
[acme@ssdandy linux]$ babeltrace ./ctf-data/
[error] Packet size (18446744073709551615 bits) is larger than remaining file size (262144 bits).
[error] Stream index creation error.
[error] Open file stream error.
[warning] [Context] Cannot open_trace of format ctf at path ./ctf-data.
[warning] [Context] cannot open trace "./ctf-data" from ./ctf-data/ for reading.
[error] Cannot open any trace for reading.

[error] opening trace "./ctf-data/" for reading.

[error] none of the specified trace paths could be opened.

[acme@ssdandy linux]$

It stops working.

[acme@ssdandy linux]$ ls -la ctf-data/
total 44
drwxrwx---. 2 acme acme 41 Fev 25 16:12 .
drwxrwxr-x. 28 acme acme 4096 Fev 25 16:19 ..
-rw-rw----. 1 acme acme 4666 Fev 25 16:21 metadata
-rw-rw----. 1 acme acme 32768 Fev 25 16:21 perf_stream_0
[acme@ssdandy linux]$

Can you try to reproduce this? The ctf-data/metadata file is below:

- Arnaldo

[acme@ssdandy linux]$ cat ctf-data/metadata
/* CTF 1.8 */

trace {
major = 1;
minor = 8;
uuid = "8b5ba0f6-f29f-4adc-bf12-1fc8e9afec5f";
byte_order = le;
packet.header := struct {
integer { size = 32; align = 8; signed = false; encoding = none; base = decimal; byte_order = le; } magic;
integer { size = 8; align = 8; signed = false; encoding = none; base = decimal; byte_order = le; } uuid[16];
integer { size = 32; align = 8; signed = false; encoding = none; base = decimal; byte_order = le; } stream_id;
} align(8);
};

env {
host = "ssdandy.ghostprotocols.net";
sysname = "Linux";
release = "3.10.0-210.el7.x86_64";
version = "3.19.rc7.gd15174";
machine = "x86_64";
domain = "kernel";
tracer_name = "perf";
};

clock {
name = perf_clock;
uuid = "b2bfe13f-06ed-4ef6-a3cd-fb0f28c6c608";
description = "perf clock";
freq = 1000000000;
precision = 10;
offset_s = 0;
offset = 0;
absolute = FALSE;
};

stream {
id = 0;
event.header := struct {
integer { size = 32; align = 8; signed = false; encoding = none; base = decimal; byte_order = le; } id;
integer { size = 64; align = 8; signed = false; encoding = none; base = decimal; byte_order = le; map = clock.perf_clock.value; } timestamp;
} align(8);

packet.context := struct {
integer { size = 64; align = 8; signed = false; encoding = none; base = decimal; byte_order = le; } timestamp_begin;
integer { size = 64; align = 8; signed = false; encoding = none; base = decimal; byte_order = le; } timestamp_end;
integer { size = 64; align = 8; signed = false; encoding = none; base = decimal; byte_order = le; } content_size;
integer { size = 64; align = 8; signed = false; encoding = none; base = decimal; byte_order = le; } packet_size;
integer { size = 64; align = 8; signed = false; encoding = none; base = decimal; byte_order = le; } events_discarded;
} align(8);
};

event {
name = "raw_syscalls:sys_enter";
id = 0;
stream_id = 0;
fields := struct {
integer { size = 64; align = 1; signed = false; encoding = none; base = hexadecimal; byte_order = le; } perf_ip;
integer { size = 32; align = 1; signed = true; encoding = none; base = decimal; byte_order = le; } perf_tid;
integer { size = 32; align = 1; signed = true; encoding = none; base = decimal; byte_order = le; } perf_pid;
integer { size = 64; align = 1; signed = false; encoding = none; base = decimal; byte_order = le; } perf_id;
integer { size = 32; align = 1; signed = false; encoding = none; base = decimal; byte_order = le; } perf_cpu;
integer { size = 64; align = 1; signed = false; encoding = none; base = decimal; byte_order = le; } perf_period;
integer { size = 32; align = 1; signed = false; encoding = none; base = decimal; byte_order = le; } common_type;
integer { size = 32; align = 1; signed = false; encoding = none; base = decimal; byte_order = le; } common_flags;
integer { size = 32; align = 1; signed = false; encoding = none; base = decimal; byte_order = le; } common_preempt_count;
integer { size = 32; align = 1; signed = true; encoding = none; base = decimal; byte_order = le; } common_pid;
integer { size = 64; align = 1; signed = true; encoding = none; base = decimal; byte_order = le; } id;
string { encoding = UTF8; } args;
} align(8);
};

event {
name = "raw_syscalls:sys_exit";
id = 1;
stream_id = 0;
fields := struct {
integer { size = 64; align = 1; signed = false; encoding = none; base = hexadecimal; byte_order = le; } perf_ip;
integer { size = 32; align = 1; signed = true; encoding = none; base = decimal; byte_order = le; } perf_tid;
integer { size = 32; align = 1; signed = true; encoding = none; base = decimal; byte_order = le; } perf_pid;
integer { size = 64; align = 1; signed = false; encoding = none; base = decimal; byte_order = le; } perf_id;
integer { size = 32; align = 1; signed = false; encoding = none; base = decimal; byte_order = le; } perf_cpu;
integer { size = 64; align = 1; signed = false; encoding = none; base = decimal; byte_order = le; } perf_period;
integer { size = 32; align = 1; signed = false; encoding = none; base = decimal; byte_order = le; } common_type;
integer { size = 32; align = 1; signed = false; encoding = none; base = decimal; byte_order = le; } common_flags;
integer { size = 32; align = 1; signed = false; encoding = none; base = decimal; byte_order = le; } common_preempt_count;
integer { size = 32; align = 1; signed = true; encoding = none; base = decimal; byte_order = le; } common_pid;
integer { size = 64; align = 1; signed = true; encoding = none; base = decimal; byte_order = le; } id;
integer { size = 64; align = 1; signed = true; encoding = none; base = decimal; byte_order = le; } ret;
} align(1);
};

[acme@ssdandy linux]$
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/