From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1754499AbcCAPo1 (ORCPT ); Tue, 1 Mar 2016 10:44:27 -0500 Received: from mga09.intel.com ([134.134.136.24]:31604 "EHLO mga09.intel.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1754051AbcCAPo0 (ORCPT ); Tue, 1 Mar 2016 10:44:26 -0500 X-ExtLoop1: 1 X-IronPort-AV: E=Sophos;i="5.22,523,1449561600"; d="scan'208";a="661891854" Subject: Re: Intel PT not work on 4.5.0-rc To: Arnaldo Carvalho de Melo References: <20160225142105.GL8720@kernel.org> <56CF7952.2030904@intel.com> Cc: Jiri Olsa , Wang Nan , Alexander Shishkin , Ingo Molnar , David Ahern , Namhyung Kim , Linux Kernel Mailing List From: Adrian Hunter Organization: Intel Finland Oy, Registered Address: PL 281, 00181 Helsinki, Business Identity Code: 0357606 - 4, Domiciled in Helsinki Message-ID: <56D5B801.6020107@intel.com> Date: Tue, 1 Mar 2016 17:40:49 +0200 User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:38.0) Gecko/20100101 Thunderbird/38.5.1 MIME-Version: 1.0 In-Reply-To: <56CF7952.2030904@intel.com> Content-Type: text/plain; charset=windows-1252 Content-Transfer-Encoding: 7bit Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org On 25/02/16 23:59, Adrian Hunter wrote: > On 25/02/2016 4:21 p.m., Arnaldo Carvalho de Melo wrote: >> Hi Adrian, >> >> While fixing a problem I introducing in parsing 'intel_pt//', >> i.e. the empty '//' part, which is fixed in my perf/core by now, I tried >> using intel_pt with 4.5.0-rc4 and couldn't get any trace :-\ >> >> Talking with Jiri he tried it on his side, also a Broadwell >> machine, and it worked, same tooling (acme/perf/core) but with a fedora >> kernel, 4.3.5-200.fc22.x86_64. >> >> Later I'll try switching to the kernel Jiri is using to see if it works >> for me with that one. >> >> I'm busy now and this Broadwell machine is my main workstation, >> can you check if you reproduce this problem? > > I am on vacation until some time next week. I will try to look at > it before then but might not manage it. Checked it now and was not able to reproduce. Was this happening every time, or did it just happen once? One possible explanation is that the AUX area mmaps fail or don't happen and that is somehow not reported as an error. One way to check that is: # strace perf record -e intel_pt//u -a sleep 0.001 2>&1 | grep mmap | grep MAP_SHARED mmap(NULL, 528384, PROT_READ|PROT_WRITE, MAP_SHARED, 3, 0) = 0x7f6627239000 mmap(NULL, 4194304, PROT_READ|PROT_WRITE, MAP_SHARED, 3, 0x81000) = 0x7f6623927000 mmap(NULL, 528384, PROT_READ|PROT_WRITE, MAP_SHARED, 4, 0) = 0x7f66271b8000 mmap(NULL, 4194304, PROT_READ|PROT_WRITE, MAP_SHARED, 4, 0x81000) = 0x7f6623527000 mmap(NULL, 528384, PROT_READ|PROT_WRITE, MAP_SHARED, 5, 0) = 0x7f6627137000 mmap(NULL, 4194304, PROT_READ|PROT_WRITE, MAP_SHARED, 5, 0x81000) = 0x7f6623127000 mmap(NULL, 528384, PROT_READ|PROT_WRITE, MAP_SHARED, 7, 0) = 0x7f66230a6000 mmap(NULL, 4194304, PROT_READ|PROT_WRITE, MAP_SHARED, 7, 0x81000) = 0x7f6622ca6000 That shows the normal events buffer (512KiB + 1 page) and the AUX area buffer (4MiB) for each of 4 cpus. > >> >> [root@jouet ~]# perf --version >> perf version 4.5.rc4.gbb109a >> [root@jouet ~]# perf record -e intel_pt//u -a sleep 10 >> [ perf record: Woken up 1 times to write data ] >> [ perf record: Captured and wrote 1.767 MB perf.data ] >> [root@jouet ~]# perf evlist -v >> intel_pt//u: type: 7, size: 112, config: 0x400, { sample_period, >> sample_freq }: 1, sample_type: IP|TID|TIME|CPU|IDENTIFIER, read_format: >> ID, disabled: 1, inherit: 1, exclude_kernel: 1, exclude_hv: 1, >> sample_id_all: 1 >> dummy:u: type: 1, size: 112, config: 0x9, { sample_period, sample_freq }: >> 1, sample_type: IP|TID|TIME|CPU|IDENTIFIER, read_format: ID, disabled: 1, >> inherit: 1, exclude_kernel: 1, exclude_hv: 1, mmap: 1, comm: 1, task: 1, >> sample_id_all: 1, mmap2: 1, comm_exec: 1, context_switch: 1 >> [root@jouet ~]# perf script >> [root@jouet ~]# >> >> From 'perf report -D' >> >> 0x1a8 [0x88]: event: 70 >> . >> . ... raw event: size 136 bytes >> . 0000: 46 00 00 00 00 00 88 00 01 00 00 00 00 00 00 00 F............... >> . 0010: 07 00 00 00 00 00 00 00 1f 00 00 00 00 00 00 00 ................ >> . 0020: 14 01 58 31 00 00 00 00 69 84 20 d9 d5 3b 00 00 ..X1....i. ..;.. >> . 0030: 01 00 00 00 00 00 00 00 00 04 00 00 00 00 00 00 ................ >> . 0040: 00 08 00 00 00 00 00 00 03 00 00 00 00 00 00 00 ................ >> . 0050: 00 00 00 00 00 00 00 00 01 00 00 00 00 00 00 00 ................ >> . 0060: 00 02 00 00 00 00 00 00 00 c0 03 00 00 00 00 00 ................ >> . 0070: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................ >> . 0080: 02 00 00 00 00 00 00 00 ........ >> >> 0x1a8 [0x88]: PERF_RECORD_AUXTRACE_INFO type: 1 >> PMU Type 7 >> Time Shift 31 >> Time Muliplier 827851028 >> Time Zero 65789656859753 >> Cap Time Zero 1 >> TSC bit 0x400 >> NoRETComp bit 0x800 >> Have sched_switch 3 >> Snapshot mode 0 >> Per-cpu maps 1 >> MTC bit 0x200 >> TSC:CTC numerator 0 >> TSC:CTC denominator 0 >> CYC bit 0x2 >> >> [root@jouet ~]# perf report -D | tail -13 >> Aggregated stats: (excludes AUX area (e.g. instruction trace) decoded / >> synthesized events) >> TOTAL events: 21753 >> MMAP events: 130 >> COMM events: 596 >> EXIT events: 2 >> FORK events: 594 >> MMAP2 events: 8541 > > There ought to be AUX events here, so it looks like no data has been captured, > so a problem with recording. > >> ITRACE_START events: 4 >> SWITCH_CPU_WIDE events: 11882 >> FINISHED_ROUND events: 3 >> AUXTRACE_INFO events: 1 >> intel_pt//u stats: >> dummy:u stats: >> [root@jouet ~]# >> >