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

[Arnaldo Carvalho de Melo]

Em Sun, Mar 01, 2015 at 02:20:43PM +0100, Jiri Olsa escreveu:
> On Wed, Feb 25, 2015 at 04:23:44PM -0300, Arnaldo Carvalho de Melo wrote:
> > 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:
> 
> hum, i just tried and can't reproduce this one.. anychance of mixed
> babeltrace installations? How did you install babeltrace sources?

I will recheck
 
> I assume this was some standard Fedora latest something system right?

This was on RHEL7
 
> jirka
> 
> 
> git HEAD:
> 
> [root@krava perf]# git log --oneline | head -3
> 9534f89 perf data: Add tracepoint events fields CTF conversion support
> bb848d1 perf stat: Report unsupported events properly
> ffdfa43 perf tools: Compare JOBS to 0 after grep
> 
> test:
> 
> [root@krava perf]# LD_LIBRARY_PATH=/opt/libbabeltrace/lib/ ./perf trace record usleep 1
> [ perf record: Woken up 1 times to write data ]
> [ perf record: Captured and wrote 0.023 MB perf.data (88 samples) ]
> [root@krava perf]# LD_LIBRARY_PATH=/opt/libbabeltrace/lib/ ./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) ]
> [root@krava perf]# babeltrace ./ctf-data/
> [10:04:03.320544407] (+?.?????????) raw_syscalls:sys_exit: { }, { perf_ip = 0xFFFFFFFF810235AC, perf_tid = 23899, perf_pid = 23899, perf_id = 82, perf_cpu = 3, perf_period = 1, common_type = 75, common_flags = 0, common_preempt_count = 0, common_pid = 23899, id = 59, ret = 0 }
> [10:04:03.320568054] (+0.000023647) raw_syscalls:sys_enter: { }, { perf_ip = 0xFFFFFFFF81023420, perf_tid = 23899, perf_pid = 23899, perf_id = 78, perf_cpu = 3, perf_period = 1, common_type = 76, common_flags = 0, common_preempt_count = 0, common_pid = 23899, id = 12, args = [ [0] = 0x0, [1] = 0x0, [2] = 0x0, [3] = 0x0, [4] = 0x37F, [5] = 0x64 ] }
> [10:04:03.320568993] (+0.000000939) raw_syscalls:sys_exit: { }, { perf_ip = 0xFFFFFFFF810235AC, perf_tid = 23899, perf_pid = 23899, perf_id = 82, perf_cpu = 3, perf_period = 1, common_type = 75, common_flags = 0, common_preempt_count = 0, common_pid = 23899, id = 12, ret = 24440832 }
> ...
--
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/