From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1753970AbbBYVto (ORCPT ); Wed, 25 Feb 2015 16:49:44 -0500 Received: from mx1.redhat.com ([209.132.183.28]:35768 "EHLO mx1.redhat.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1753947AbbBYVtm (ORCPT ); Wed, 25 Feb 2015 16:49:42 -0500 Date: Wed, 25 Feb 2015 16:23:44 -0300 From: Arnaldo Carvalho de Melo To: Jiri Olsa Cc: 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: <20150225192344.GH18705@kernel.org> References: <1424470628-5969-1-git-send-email-jolsa@kernel.org> <1424470628-5969-6-git-send-email-jolsa@kernel.org> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: <1424470628-5969-6-git-send-email-jolsa@kernel.org> X-Url: http://acmel.wordpress.com User-Agent: Mutt/1.5.23 (2014-03-12) Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org 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: - 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]$