* Intel PT not work on 4.5.0-rc
@ 2016-02-25 14:21 Arnaldo Carvalho de Melo
2016-02-25 21:59 ` Adrian Hunter
0 siblings, 1 reply; 7+ messages in thread
From: Arnaldo Carvalho de Melo @ 2016-02-25 14:21 UTC (permalink / raw)
To: Adrian Hunter
Cc: Jiri Olsa, Wang Nan, Alexander Shishkin, Ingo Molnar, David Ahern,
Namhyung Kim, Linux Kernel Mailing List
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?
[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
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 ~]#
^ permalink raw reply [flat|nested] 7+ messages in thread* Re: Intel PT not work on 4.5.0-rc 2016-02-25 14:21 Intel PT not work on 4.5.0-rc Arnaldo Carvalho de Melo @ 2016-02-25 21:59 ` Adrian Hunter 2016-03-01 15:40 ` Adrian Hunter 0 siblings, 1 reply; 7+ messages in thread From: Adrian Hunter @ 2016-02-25 21:59 UTC (permalink / raw) To: Arnaldo Carvalho de Melo Cc: Jiri Olsa, Wang Nan, Alexander Shishkin, Ingo Molnar, David Ahern, Namhyung Kim, Linux Kernel Mailing List 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. > > [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 ~]# > ^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: Intel PT not work on 4.5.0-rc 2016-02-25 21:59 ` Adrian Hunter @ 2016-03-01 15:40 ` Adrian Hunter 2016-03-01 15:59 ` Arnaldo Carvalho de Melo 0 siblings, 1 reply; 7+ messages in thread From: Adrian Hunter @ 2016-03-01 15:40 UTC (permalink / raw) To: Arnaldo Carvalho de Melo Cc: Jiri Olsa, Wang Nan, Alexander Shishkin, Ingo Molnar, David Ahern, Namhyung Kim, Linux Kernel Mailing List 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 ~]# >> > ^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: Intel PT not work on 4.5.0-rc 2016-03-01 15:40 ` Adrian Hunter @ 2016-03-01 15:59 ` Arnaldo Carvalho de Melo 2016-03-01 18:20 ` Arnaldo Carvalho de Melo 0 siblings, 1 reply; 7+ messages in thread From: Arnaldo Carvalho de Melo @ 2016-03-01 15:59 UTC (permalink / raw) To: Adrian Hunter Cc: Jiri Olsa, Wang Nan, Alexander Shishkin, Ingo Molnar, David Ahern, Namhyung Kim, Linux Kernel Mailing List Em Tue, Mar 01, 2016 at 05:40:49PM +0200, Adrian Hunter escreveu: > 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 linux]# perf trace --no-inherit -e mmap perf record -e intel_pt//u -a sleep 0.001 2>&1 | grep SHARED 25.797 ( 0.067 ms): mmap(len: 528384, prot: READ|WRITE, flags: SHARED, fd: 3<anon_inode:[perf_event]>) = 0x7f0250418000 26.168 ( 0.367 ms): mmap(len: 4194304, prot: READ|WRITE, flags: SHARED, fd: 3<anon_inode:[perf_event]>, off: 528384) = 0x7f024c47b000 26.264 ( 0.076 ms): mmap(len: 528384, prot: READ|WRITE, flags: SHARED, fd: 4<anon_inode:[perf_event]>) = 0x7f0250397000 26.631 ( 0.364 ms): mmap(len: 4194304, prot: READ|WRITE, flags: SHARED, fd: 4<anon_inode:[perf_event]>, off: 528384) = 0x7f024c07b000 26.723 ( 0.081 ms): mmap(len: 528384, prot: READ|WRITE, flags: SHARED, fd: 5<anon_inode:[perf_event]>) = 0x7f0250316000 27.094 ( 0.365 ms): mmap(len: 4194304, prot: READ|WRITE, flags: SHARED, fd: 5<anon_inode:[perf_event]>, off: 528384) = 0x7f024bc7b000 27.203 ( 0.099 ms): mmap(len: 528384, prot: READ|WRITE, flags: SHARED, fd: 7<anon_inode:[perf_event]>) = 0x7f024bbfa000 Binary file (standard input) matches [root@jouet linux]# It somehow misses one mmap :-/ Will check where is the problem, haven't see any THROTTLE or LOST events :-\ Anyway, 'strace' shows the 4 pairs of mmaps, but it still doesn't work, rebooting: [root@jouet linux]# strace -e mmap perf record -e intel_pt//u -a sleep 0.001 2>&1 | grep SHARED mmap(NULL, 528384, PROT_READ|PROT_WRITE, MAP_SHARED, 3, 0) = 0x7fc3f8818000 mmap(NULL, 4194304, PROT_READ|PROT_WRITE, MAP_SHARED, 3, 0x81000) = 0x7fc3f487b000 mmap(NULL, 528384, PROT_READ|PROT_WRITE, MAP_SHARED, 4, 0) = 0x7fc3f8797000 mmap(NULL, 4194304, PROT_READ|PROT_WRITE, MAP_SHARED, 4, 0x81000) = 0x7fc3f447b000 mmap(NULL, 528384, PROT_READ|PROT_WRITE, MAP_SHARED, 5, 0) = 0x7fc3f8716000 mmap(NULL, 4194304, PROT_READ|PROT_WRITE, MAP_SHARED, 5, 0x81000) = 0x7fc3f407b000 mmap(NULL, 528384, PROT_READ|PROT_WRITE, MAP_SHARED, 7, 0) = 0x7fc3f3ffa000 mmap(NULL, 4194304, PROT_READ|PROT_WRITE, MAP_SHARED, 7, 0x81000) = 0x7fc3f3bfa000 Binary file (standard input) matches [root@jouet linux]# perf script [root@jouet linux]# > > > > >> > >> [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 ~]# > >> > > ^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: Intel PT not work on 4.5.0-rc 2016-03-01 15:59 ` Arnaldo Carvalho de Melo @ 2016-03-01 18:20 ` Arnaldo Carvalho de Melo 2016-03-01 18:24 ` Arnaldo Carvalho de Melo 0 siblings, 1 reply; 7+ messages in thread From: Arnaldo Carvalho de Melo @ 2016-03-01 18:20 UTC (permalink / raw) To: Adrian Hunter Cc: Jiri Olsa, Wang Nan, Alexander Shishkin, Ingo Molnar, David Ahern, Namhyung Kim, Linux Kernel Mailing List 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 [] Aggregated stats: (excludes AUX area (e.g. instruction trace) decoded / synthesized events) TOTAL events: 8859 MMAP events: 120 COMM events: 509 EXIT events: 1 FORK events: 507 MMAP2 events: 7673 AUX events: 8 ITRACE_START events: 4 SWITCH_CPU_WIDE events: 26 FINISHED_ROUND events: 2 AUXTRACE_INFO events: 1 AUXTRACE events: 8 intel_pt//u stats: dummy:u stats: [root@jouet ~]# Trying a suspend/resume now... - Arnaldo ^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: Intel PT not work on 4.5.0-rc 2016-03-01 18:20 ` Arnaldo Carvalho de Melo @ 2016-03-01 18:24 ` Arnaldo Carvalho de Melo 2016-03-01 19:12 ` Arnaldo Carvalho de Melo 0 siblings, 1 reply; 7+ messages in thread From: Arnaldo Carvalho de Melo @ 2016-03-01 18:24 UTC (permalink / raw) To: Adrian Hunter Cc: Jiri Olsa, Wang Nan, Alexander Shishkin, Ingo Molnar, David Ahern, Namhyung Kim, Linux Kernel Mailing List 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 [] > > Aggregated stats: (excludes AUX area (e.g. instruction trace) decoded / synthesized events) > TOTAL events: 8859 > MMAP events: 120 > COMM events: 509 > EXIT events: 1 > FORK events: 507 > MMAP2 events: 7673 > AUX events: 8 > ITRACE_START events: 4 > SWITCH_CPU_WIDE events: 26 > FINISHED_ROUND events: 2 > AUXTRACE_INFO events: 1 > AUXTRACE events: 8 > intel_pt//u stats: > dummy:u stats: > [root@jouet ~]# > > Trying a suspend/resume now... Scrap that theory, it still works after two suspend/resume cycles :-\ - ARnaldo ^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: Intel PT not work on 4.5.0-rc 2016-03-01 18:24 ` Arnaldo Carvalho de Melo @ 2016-03-01 19:12 ` Arnaldo Carvalho de Melo 0 siblings, 0 replies; 7+ messages in thread From: Arnaldo Carvalho de Melo @ 2016-03-01 19:12 UTC (permalink / raw) To: Adrian Hunter Cc: Jiri Olsa, Wang Nan, Alexander Shishkin, Ingo Molnar, David Ahern, Namhyung Kim, Andi Kleen, Linux Kernel Mailing List 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 ^ permalink raw reply [flat|nested] 7+ messages in thread
end of thread, other threads:[~2016-03-01 19:12 UTC | newest] Thread overview: 7+ messages (download: mbox.gz follow: Atom feed -- links below jump to the message on this page -- 2016-02-25 14:21 Intel PT not work on 4.5.0-rc Arnaldo Carvalho de Melo 2016-02-25 21:59 ` Adrian Hunter 2016-03-01 15:40 ` Adrian Hunter 2016-03-01 15:59 ` Arnaldo Carvalho de Melo 2016-03-01 18:20 ` Arnaldo Carvalho de Melo 2016-03-01 18:24 ` Arnaldo Carvalho de Melo 2016-03-01 19:12 ` Arnaldo Carvalho de Melo
This is an external index of several public inboxes, see mirroring instructions on how to clone and mirror all data and code used by this external index.