Re: Intel PT not work on 4.5.0-rc
From: Arnaldo Carvalho de Melo
Date: Tue Mar 01 2016 - 14:12:38 EST
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