From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1754141AbcCATMe (ORCPT ); Tue, 1 Mar 2016 14:12:34 -0500 Received: from mail.kernel.org ([198.145.29.136]:58529 "EHLO mail.kernel.org" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1753062AbcCATMc (ORCPT ); Tue, 1 Mar 2016 14:12:32 -0500 Date: Tue, 1 Mar 2016 16:12:27 -0300 From: Arnaldo Carvalho de Melo To: Adrian Hunter Cc: Jiri Olsa , Wang Nan , Alexander Shishkin , Ingo Molnar , David Ahern , Namhyung Kim , Andi Kleen , Linux Kernel Mailing List Subject: Re: Intel PT not work on 4.5.0-rc Message-ID: <20160301191227.GE3604@kernel.org> References: <20160225142105.GL8720@kernel.org> <56CF7952.2030904@intel.com> <56D5B801.6020107@intel.com> <20160301155921.GE3170@kernel.org> <20160301182035.GA3604@kernel.org> <20160301182455.GB3604@kernel.org> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: <20160301182455.GB3604@kernel.org> X-Url: http://acmel.wordpress.com User-Agent: Mutt/1.5.24 (2015-08-30) Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Em Tue, Mar 01, 2016 at 03:24:55PM -0300, Arnaldo Carvalho de Melo escreveu: > Em Tue, Mar 01, 2016 at 03:20:35PM -0300, Arnaldo Carvalho de Melo escreveu: > > Em Tue, Mar 01, 2016 at 12:59:21PM -0300, Arnaldo Carvalho de Melo escreveu: > > > Anyway, 'strace' shows the 4 pairs of mmaps, but it still doesn't work, rebooting: > > > > After I reboot, all works: > > > > [root@jouet ~]# perf record -e intel_pt//u -a sleep 0.001 > > [ perf record: Woken up 1 times to write data ] > > [ perf record: Captured and wrote 1.119 MB perf.data ] > > [root@jouet ~]# perf script | head -10 > > perf 3797 [002] 8136.590828: 1 branches:u: 0 [unknown] ([unknown]) => 7fcb3f240707 __GI___ioctl (/usr/lib64/libc-2.22.so) > > perf 3797 [002] 8136.590828: 1 branches:u: 7fcb3f24070f __GI___ioctl (/usr/lib64/libc-2.22.so) => 497e56 perf_evsel__enable (/home/acme/bin/perf) > > perf 3797 [002] 8136.590828: 1 branches:u: 497e58 perf_evsel__enable (/home/acme/bin/perf) => 497e20 perf_evsel__enable (/home/acme/bin/perf) > > perf 3797 [002] 8136.590828: 1 branches:u: 497e27 perf_evsel__enable (/home/acme/bin/perf) => 497e80 perf_evsel__enable (/home/acme/bin/perf) > > perf 3797 [002] 8136.590828: 1 branches:u: 497e87 perf_evsel__enable (/home/acme/bin/perf) => 497e14 perf_evsel__enable (/home/acme/bin/perf) > > perf 3797 [002] 8136.590828: 1 branches:u: 497e1b perf_evsel__enable (/home/acme/bin/perf) => 497e29 perf_evsel__enable (/home/acme/bin/perf) > > perf 3797 [002] 8136.590828: 1 branches:u: 497e51 perf_evsel__enable (/home/acme/bin/perf) => 421d00 ioctl@plt (/home/acme/bin/perf) > > perf 3797 [002] 8136.590828: 1 branches:u: 421d00 ioctl@plt (/home/acme/bin/perf) => 7fcb3f240700 __GI___ioctl (/usr/lib64/libc-2.22.so) > > perf 3797 [002] 8136.590828: 1 branches:u: 7fcb3f240705 __GI___ioctl (/usr/lib64/libc-2.22.so) => 0 [unknown] ([unknown]) > > perf 3797 [002] 8136.590834: 1 branches:u: 0 [unknown] ([unknown]) => 7fcb3f240707 __GI___ioctl (/usr/lib64/libc-2.22.so) > > [root@jouet ~]# > > [root@jouet ~]# perf report -D | tail -20 > > . 0020: 00 00 00 00 00 00 00 00 07 14 b9 72 66 07 00 00 ...........rf... > > . 0030: 03 00 00 00 00 00 00 00 1e 00 00 00 00 00 00 00 ................ > > > > 3 8136592790535 0x11e688 [0x40]: PERF_RECORD_AUX offset: 0x28 size: 0x28 flags: 0 [] So, it stopped working again, the other thing I did besides suspend/resumes was to start a KVM instance, and as soon as I have no kvm instances running, it works, as soon as I start one, it stops: ot@jouet ~]# perf record -e intel_pt//u sleep 0.001 2>&1 [ perf record: Woken up 1 times to write data ] [ perf record: Captured and wrote 0.021 MB perf.data ] [root@jouet ~]# perf script [root@jouet ~]# virsh list Id Name State ---------------------------------------------------- 2 rhel6.sandy running [root@jouet ~]# virsh shutdown rhel6.sandy Domain rhel6.sandy is being shutdown [root@jouet ~]# virsh list Id Name State ---------------------------------------------------- [root@jouet ~]# perf record -e intel_pt//u sleep 0.001 2>&1 [ perf record: Woken up 1 times to write data ] [ perf record: Captured and wrote 0.041 MB perf.data ] [root@jouet ~]# perf script sleep 12079 [003] 10799.018032: 1 branches:u: 0 [unknown] ([unknown]) => 7fb83b967c80 _start (/usr/lib64/ld-2.22.s sleep 12079 [003] 10799.018032: 1 branches:u: 7fb83b967c80 _start (/usr/lib64/ld-2.22.so) => 0 [unknown] ([unknown sleep 12079 [003] 10799.018036: 1 branches:u: 0 [unknown] ([unknown]) => 7fb83b967c80 _start (/usr/lib64/ld-2.22.s sleep 12079 [003] 10799.018036: 1 branches:u: 7fb83b967c83 _start (/usr/lib64/ld-2.22.so) => 7fb83b96b860 _dl_start (/usr/lib sleep 12079 [003] 10799.018036: 1 branches:u: 7fb83b96b886 _dl_start (/usr/lib64/ld-2.22.so) => 0 [unknown] ([unkn sleep 12079 [003] 10799.018038: 1 branches:u: 0 [unknown] ([unknown]) => 7fb83b96b886 _dl_start (/usr/lib64/ld-2.2 sleep 12079 [003] 10799.018038: 1 branches:u: 7fb83b96b8f1 _dl_start (/usr/lib64/ld-2.22.so) => 7fb83b96b90f _dl_start (/usr/ sleep 12079 [003] 10799.018038: 1 branches:u: 7fb83b96b913 _dl_start (/usr/lib64/ld-2.22.so) => 7fb83b96b8f8 _dl_start (/usr/ sleep 12079 [003] 10799.018038: 1 branches:u: 7fb83b96b913 _dl_start (/usr/lib64/ld-2.22.so) => 7fb83b96b8f8 _dl_start (/usr/ sleep 12079 [003] 10799.018038: 1 branches:u: 7fb83b96b91f _dl_start (/usr/lib64/ld-2.22.so) => 7fb83b96bae8 _dl_start (/usr/ sleep 12079 [003] 10799.018038: 1 branches:u: 7fb83b96baf0 _dl_start (/usr/lib64/ld-2.22.so) => 7fb83b96bb10 _dl_start (/usr/ sleep 12079 [003] 10799.018038: 1 branches:u: 7fb83b96bb1a _dl_start (/usr/lib64/ld-2.22.so) => 7fb83b96bb30 _dl_start (/usr/ sleep 12079 [003] 10799.018038: 1 branches:u: 7fb83b96bb47 _dl_start (/usr/lib64/ld-2.22.so) => 7fb83b96b903 _dl_start (/usr/ sleep 12079 [003] 10799.018038: 1 branches:u: 7fb83b96b913 _dl_start (/usr/lib64/ld-2.22.so) => 7fb83b96b8f8 _dl_start (/usr/ sleep 12079 [003] 10799.018038: 1 branches:u: 7fb83b96b913 _dl_start (/usr/lib64/ld-2.22.so) => 7fb83b96b8f8 _dl_start (/usr/ sleep 12079 [003] 10799.018038: 1 branches:u: 7fb83b96b913 _dl_start (/usr/lib64/ld-2.22.so) => 7fb83b96b8f8 _dl_start (/usr/ So, just before hitting send again, lemme try once more, yeah, repeatable, so please try intel_pt on a machine where KVM is running. Is this a known limitation? This is the first machine where I run KVM + intel_pt, a Broadwell class notebook (t450s), in the past I tested intel_pt on remore, test lab machines, where I think there weren't virtual machines running. For completeness: [root@jouet ~]# virsh list Id Name State ---------------------------------------------------- [root@jouet ~]# perf record -e intel_pt//u sleep 0.001 [ perf record: Woken up 1 times to write data ] [ perf record: Captured and wrote 0.040 MB perf.data ] [root@jouet ~]# perf script | head -5 sleep 12186 [000] 11184.786838: 1 branches:u: 0 [unknown] ([unknown]) => 7f800affec80 _start (/usr/lib64/ld-2.22.so) sleep 12186 [000] 11184.786838: 1 branches:u: 7f800affec80 _start (/usr/lib64/ld-2.22.so) => 0 [unknown] ([unknown]) sleep 12186 [000] 11184.786840: 1 branches:u: 0 [unknown] ([unknown]) => 7f800affec80 _start (/usr/lib64/ld-2.22.so) sleep 12186 [000] 11184.786840: 1 branches:u: 7f800affec83 _start (/usr/lib64/ld-2.22.so) => 7f800b002860 _dl_start (/usr/lib64/ld-2.22.so) sleep 12186 [000] 11184.786840: 1 branches:u: 7f800b002860 _dl_start (/usr/lib64/ld-2.22.so) => 0 [unknown] ([unknown]) [root@jouet ~]# [root@jouet ~]# perf report -D | tail -20 . 0010: 99 2f 00 00 99 2f 00 00 a0 47 55 29 2c 0a 00 00 ./.../...GU),... . 0020: 03 00 00 00 00 00 00 00 87 21 00 00 00 00 00 00 .........!...... 3 11184788293536 0xa3e0 [0x30]: PERF_RECORD_SWITCH_CPU_WIDE IN prev pid/tid: 0/0 Aggregated stats: (excludes AUX area (e.g. instruction trace) decoded / synthesized events) TOTAL events: 171 MMAP events: 124 COMM events: 2 EXIT events: 1 MMAP2 events: 4 AUX events: 2 ITRACE_START events: 1 SWITCH_CPU_WIDE events: 34 FINISHED_ROUND events: 1 AUXTRACE_INFO events: 1 AUXTRACE events: 1 intel_pt//u stats: dummy:u stats: dummy:u stats: [root@jouet ~]# virsh start rhel6.sandy Domain rhel6.sandy started [root@jouet ~]# perf record -e intel_pt//u sleep 0.001 [ perf record: Woken up 1 times to write data ] [ perf record: Captured and wrote 0.020 MB perf.data ] [root@jouet ~]# perf script | head -5 [root@jouet ~]# perf report -D | tail -20 . ... raw event: size 48 bytes . 0000: 0f 00 00 00 00 00 30 00 59 30 00 00 59 30 00 00 ......0.Y0..Y0.. . 0010: 00 00 00 00 00 00 00 00 a2 f6 f7 02 32 0a 00 00 ............2... . 0020: 00 00 00 00 00 00 00 00 98 21 00 00 00 00 00 00 .........!...... 0 11209914447522 0x4d98 [0x30]: PERF_RECORD_SWITCH_CPU_WIDE IN prev pid/tid: 12377/12377 Aggregated stats: (excludes AUX area (e.g. instruction trace) decoded / synthesized events) TOTAL events: 180 MMAP events: 124 COMM events: 2 EXIT events: 1 MMAP2 events: 4 ITRACE_START events: 1 SWITCH_CPU_WIDE events: 44 FINISHED_ROUND events: 3 AUXTRACE_INFO events: 1 intel_pt//u stats: dummy:u stats: dummy:u stats: [root@jouet ~]# - Arnaldo