From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1754166AbbCBPct (ORCPT ); Mon, 2 Mar 2015 10:32:49 -0500 Received: from mx1.redhat.com ([209.132.183.28]:46514 "EHLO mx1.redhat.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1752159AbbCBPcs (ORCPT ); Mon, 2 Mar 2015 10:32:48 -0500 Date: Mon, 2 Mar 2015 12:32:20 -0300 From: Arnaldo Carvalho de Melo To: Jiri Olsa Cc: Jiri Olsa , linux-kernel@vger.kernel.org, Sebastian Andrzej Siewior , David Ahern , Frederic Weisbecker , Jeremie Galarneau , Namhyung Kim , Paul Mackerras , Peter Zijlstra , Tom Zanussi , Wang Nan Subject: Re: [PATCH 05/11] perf data: Add tracepoint events fields CTF conversion support Message-ID: <20150302153220.GD6723@redhat.com> References: <1424470628-5969-1-git-send-email-jolsa@kernel.org> <1424470628-5969-6-git-send-email-jolsa@kernel.org> <20150225192344.GH18705@kernel.org> <20150301132043.GA17097@krava.redhat.com> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: <20150301132043.GA17097@krava.redhat.com> X-Url: http://acmel.wordpress.com User-Agent: Mutt/1.5.20 (2009-12-10) Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org 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 > > > 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 } > > > > > > 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 } > ...