* perf user SDT markers
@ 2015-04-12 2:13 Brendan Gregg
2015-04-12 20:05 ` Brendan Gregg
0 siblings, 1 reply; 5+ messages in thread
From: Brendan Gregg @ 2015-04-12 2:13 UTC (permalink / raw)
To: linux-perf-use., hemant
G'Day,
I was just trying Hemant Kumar's user SDT patch
(http://lwn.net/Articles/618956/); anyone else tried it recently? I
applied it to 4.0.0-rc6, and it creates instrumentation, but doesn't
record the probes.
This works (it finds the Node.js probes):
# ./perf sdt-cache --dump
/home/bgregg-testtest/node-standard/out/Release/node:
%node:net__server__connection
%node:net__stream__end
%node:net__socket__read
%node:net__socket__write
%node:http__server__request
%node:http__server__response
%node:http__client__request
%node:http__client__response
%node:gc__done
%node:gc__start
But I can't "perf list" or record them:
# ./perf record -e '%node:http__server__request' -aR
invalid or unsupported event: '%node:http__server__request'
Run 'perf list' for a list of valid events
[...]
stap works:
# /root/systemtap-2.8/bin/stap -e 'probe
process("/home/bgregg-testtest/node-standard/out/Release/node").mark("http__server__request")
{ println("hit"); }'
hit
hit
Brendan
^ permalink raw reply [flat|nested] 5+ messages in thread* Re: perf user SDT markers 2015-04-12 2:13 perf user SDT markers Brendan Gregg @ 2015-04-12 20:05 ` Brendan Gregg 2015-04-13 9:27 ` Hemant Kumar 0 siblings, 1 reply; 5+ messages in thread From: Brendan Gregg @ 2015-04-12 20:05 UTC (permalink / raw) To: linux-perf-use., hemant On Sat, Apr 11, 2015 at 7:13 PM, Brendan Gregg <brendan.d.gregg@gmail.com> wrote: > G'Day, > > I was just trying Hemant Kumar's user SDT patch > (http://lwn.net/Articles/618956/); anyone else tried it recently? I > applied it to 4.0.0-rc6, and it creates instrumentation, but doesn't > record the probes. > > This works (it finds the Node.js probes): > > # ./perf sdt-cache --dump > /home/bgregg-testtest/node-standard/out/Release/node: > %node:net__server__connection > %node:net__stream__end > %node:net__socket__read > %node:net__socket__write > %node:http__server__request > %node:http__server__response > %node:http__client__request > %node:http__client__response > %node:gc__done > %node:gc__start > > But I can't "perf list" or record them: > > # ./perf record -e '%node:http__server__request' -aR > invalid or unsupported event: '%node:http__server__request' > Run 'perf list' for a list of valid events > [...] > > stap works: > > # /root/systemtap-2.8/bin/stap -e 'probe > process("/home/bgregg-testtest/node-standard/out/Release/node").mark("http__server__request") > { println("hit"); }' > hit > hit > > Brendan Some more digging... So a simple C program with a DTRACE_PROBE1() works, where the marker ends up being "%tick:loop": # ./perf record -e '%tick:loop' -a -g [...] ^C [ perf record: Woken up 1 times to write data ] [ perf record: Captured and wrote 0.334 MB perf.data (2 samples) ] But the %node markers don't work (eg, "%node:gc__start"). Maybe the presence of underscores is breaking it? By adding some debug statements, I dug this message out of yyparse(), which was failing: yyparse() yymsgbuf: syntax error, unexpected PE_NAME, expecting $end Brendan ^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: perf user SDT markers 2015-04-12 20:05 ` Brendan Gregg @ 2015-04-13 9:27 ` Hemant Kumar 2015-04-13 17:19 ` Brendan Gregg 0 siblings, 1 reply; 5+ messages in thread From: Hemant Kumar @ 2015-04-13 9:27 UTC (permalink / raw) To: Brendan Gregg; +Cc: linux-perf-use. Hi Brendan, On 04/13/2015 01:35 AM, Brendan Gregg wrote: > On Sat, Apr 11, 2015 at 7:13 PM, Brendan Gregg > <brendan.d.gregg@gmail.com> wrote: >> G'Day, >> >> I was just trying Hemant Kumar's user SDT patch >> (http://lwn.net/Articles/618956/); anyone else tried it recently? I >> applied it to 4.0.0-rc6, and it creates instrumentation, but doesn't >> record the probes. >> >> This works (it finds the Node.js probes): >> >> # ./perf sdt-cache --dump >> /home/bgregg-testtest/node-standard/out/Release/node: >> %node:net__server__connection >> %node:net__stream__end >> %node:net__socket__read >> %node:net__socket__write >> %node:http__server__request >> %node:http__server__response >> %node:http__client__request >> %node:http__client__response >> %node:gc__done >> %node:gc__start >> >> But I can't "perf list" or record them: >> >> # ./perf record -e '%node:http__server__request' -aR >> invalid or unsupported event: '%node:http__server__request' >> Run 'perf list' for a list of valid events >> [...] >> >> stap works: >> >> # /root/systemtap-2.8/bin/stap -e 'probe >> process("/home/bgregg-testtest/node-standard/out/Release/node").mark("http__server__request") >> { println("hit"); }' >> hit >> hit >> >> Brendan > Some more digging... So a simple C program with a DTRACE_PROBE1() > works, where the marker ends up being "%tick:loop": > > # ./perf record -e '%tick:loop' -a -g > [...] > ^C > [ perf record: Woken up 1 times to write data ] > [ perf record: Captured and wrote 0.334 MB perf.data (2 samples) ] > > But the %node markers don't work (eg, "%node:gc__start"). Maybe the > presence of underscores is breaking it? By adding some debug > statements, I dug this message out of yyparse(), which was failing: > > yyparse() yymsgbuf: syntax error, unexpected PE_NAME, expecting $end I rebased and tried the patches with perf for the latest tip: # ./perf sdt-cache --add /lib64/libc.so.6 8 events added for /lib64/libc.so.6 # ./perf sdt-cache --dump /usr/lib64/libc-2.16.so: %libc:setjmp %libc:longjmp %libc:longjmp_target %libc:lll_futex_wake %libc:lll_lock_wait_private %libc:longjmp %libc:longjmp_target %libc:lll_futex_wake # ./perf record -e %libc:longjmp_target -aR sleep 1 [ perf record: Woken up 1 times to write data ] [ perf record: Captured and wrote 0.286 MB perf.data ] Its able to probe and record on %libc:longjmp_target with an underscore. Also, can you please point me to the node.js with SDT markers you are using and can you dump me the readelf -n /path/to/node.js o/p? -- Thanks, Hemant Kumar ^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: perf user SDT markers 2015-04-13 9:27 ` Hemant Kumar @ 2015-04-13 17:19 ` Brendan Gregg 2015-04-14 10:25 ` Hemant Kumar 0 siblings, 1 reply; 5+ messages in thread From: Brendan Gregg @ 2015-04-13 17:19 UTC (permalink / raw) To: Hemant Kumar; +Cc: linux-perf-use. G'Day Hemant, Thanks for testing; here's how I compiled node.js: # apt-get install -y systemtap-sdt-dev # provides "dtrace" # git clone --depth 1 https://github.com/joyent/node # cd node # ./configure --with-dtrace # make node readelf: # readelf -n node Notes at offset 0x00000254 with length 0x00000020: Owner Data size Description GNU 0x00000010 NT_GNU_ABI_TAG (ABI version tag) OS: Linux, ABI: 2.6.24 Notes at offset 0x00000274 with length 0x00000024: Owner Data size Description GNU 0x00000014 NT_GNU_BUILD_ID (unique build ID bitstring) Build ID: 85dd5ef00ffde124f220b94c8a2b552d9274a89f Notes at offset 0x00c45fd8 with length 0x000004e4: Owner Data size Description stapsdt 0x0000003c NT_STAPSDT (SystemTap probe descriptors) Provider: node Name: gc__start Location: 0x0000000000bf7894, Base: 0x0000000000f252de, Semaphore: 0x0000000001245fa8 Arguments: 4@%esi 4@%edx 8@%rdi stapsdt 0x0000003a NT_STAPSDT (SystemTap probe descriptors) Provider: node Name: gcstart Location: 0x0000000000bf7895, Base: 0x0000000000f252de, Semaphore: 0x0000000001245faa Arguments: 4@%esi 4@%edx 8@%rdi stapsdt 0x0000003b NT_STAPSDT (SystemTap probe descriptors) Provider: node Name: gc__done Location: 0x0000000000bf78a4, Base: 0x0000000000f252de, Semaphore: 0x0000000001245fac Arguments: 4@%esi 4@%edx 8@%rdi stapsdt 0x0000005c NT_STAPSDT (SystemTap probe descriptors) [...etc...] (the "gcstart" probe is one I added to test the underscore theory.) Here's also the event files: # ls /sys/kernel/debug/tracing/events/node/ enable gc__start_11 gc__start_2 gcstart_5 http__server__request filter gcstart_1_1 gcstart_2 gc__start_6 http__server__request_1 gcstart gc__start_12 gc__start_3 gcstart_6 http__server__request_2 gc__start gc__start_13 gcstart_3 gc__start_7 http__server__request_3 gc__start_1 gc__start_14 gc__start_4 gcstart_7 http__server__request_4 gcstart_1 gc__start_15 gcstart_4 gc__start_8 net__server__connection gc__start_10 gc__start_16 gc__start_5 gc__start_9 net__server__connection_1 This is after several iterations of --add and --del. Something seems to be going wrong there. Thanks, Brendan On Mon, Apr 13, 2015 at 2:27 AM, Hemant Kumar <hemant@linux.vnet.ibm.com> wrote: > Hi Brendan, > > > On 04/13/2015 01:35 AM, Brendan Gregg wrote: >> >> On Sat, Apr 11, 2015 at 7:13 PM, Brendan Gregg >> <brendan.d.gregg@gmail.com> wrote: >>> >>> G'Day, >>> >>> I was just trying Hemant Kumar's user SDT patch >>> (http://lwn.net/Articles/618956/); anyone else tried it recently? I >>> applied it to 4.0.0-rc6, and it creates instrumentation, but doesn't >>> record the probes. >>> >>> This works (it finds the Node.js probes): >>> >>> # ./perf sdt-cache --dump >>> /home/bgregg-testtest/node-standard/out/Release/node: >>> %node:net__server__connection >>> %node:net__stream__end >>> %node:net__socket__read >>> %node:net__socket__write >>> %node:http__server__request >>> %node:http__server__response >>> %node:http__client__request >>> %node:http__client__response >>> %node:gc__done >>> %node:gc__start >>> >>> But I can't "perf list" or record them: >>> >>> # ./perf record -e '%node:http__server__request' -aR >>> invalid or unsupported event: '%node:http__server__request' >>> Run 'perf list' for a list of valid events >>> [...] >>> >>> stap works: >>> >>> # /root/systemtap-2.8/bin/stap -e 'probe >>> >>> process("/home/bgregg-testtest/node-standard/out/Release/node").mark("http__server__request") >>> { println("hit"); }' >>> hit >>> hit >>> >>> Brendan >> >> Some more digging... So a simple C program with a DTRACE_PROBE1() >> works, where the marker ends up being "%tick:loop": >> >> # ./perf record -e '%tick:loop' -a -g >> [...] >> ^C >> [ perf record: Woken up 1 times to write data ] >> [ perf record: Captured and wrote 0.334 MB perf.data (2 samples) ] >> >> But the %node markers don't work (eg, "%node:gc__start"). Maybe the >> presence of underscores is breaking it? By adding some debug >> statements, I dug this message out of yyparse(), which was failing: >> >> yyparse() yymsgbuf: syntax error, unexpected PE_NAME, expecting $end > > > I rebased and tried the patches with perf for the latest tip: > > # ./perf sdt-cache --add /lib64/libc.so.6 > 8 events added for /lib64/libc.so.6 > > # ./perf sdt-cache --dump > /usr/lib64/libc-2.16.so: > %libc:setjmp > %libc:longjmp > %libc:longjmp_target > %libc:lll_futex_wake > %libc:lll_lock_wait_private > %libc:longjmp > %libc:longjmp_target > %libc:lll_futex_wake > > > # ./perf record -e %libc:longjmp_target -aR sleep 1 > [ perf record: Woken up 1 times to write data ] > [ perf record: Captured and wrote 0.286 MB perf.data ] > > Its able to probe and record on %libc:longjmp_target with an underscore. > > Also, can you please point me to the node.js with SDT markers you are using > and can you dump me the readelf -n /path/to/node.js o/p? > > -- > Thanks, > Hemant Kumar > ^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: perf user SDT markers 2015-04-13 17:19 ` Brendan Gregg @ 2015-04-14 10:25 ` Hemant Kumar 0 siblings, 0 replies; 5+ messages in thread From: Hemant Kumar @ 2015-04-14 10:25 UTC (permalink / raw) To: Brendan Gregg; +Cc: linux-perf-use. Hi Brendan, Thanks for the data. On 04/13/2015 10:49 PM, Brendan Gregg wrote: > G'Day Hemant, > > Thanks for testing; here's how I compiled node.js: > > # apt-get install -y systemtap-sdt-dev # provides "dtrace" > # git clone --depth 1 https://github.com/joyent/node > # cd node > # ./configure --with-dtrace > # make Thanks, I was able to see the error in my case too. Will look into this as to why its failing to record on these using perf record -e "%node:gc__done", even after it creates an entry into the uprobe_events file : # cat /sys/kernel/debug/tracing/uprobe_events p:node/gc__done /home/hemant/node/out/Release/node:0x000000000081d354 > node readelf: > > # readelf -n node > > Notes at offset 0x00000254 with length 0x00000020: > Owner Data size Description > GNU 0x00000010 NT_GNU_ABI_TAG (ABI version tag) > OS: Linux, ABI: 2.6.24 > > Notes at offset 0x00000274 with length 0x00000024: > Owner Data size Description > GNU 0x00000014 NT_GNU_BUILD_ID (unique build ID bitstring) > Build ID: 85dd5ef00ffde124f220b94c8a2b552d9274a89f > > Notes at offset 0x00c45fd8 with length 0x000004e4: > Owner Data size Description > stapsdt 0x0000003c NT_STAPSDT (SystemTap probe descriptors) > Provider: node > Name: gc__start > Location: 0x0000000000bf7894, Base: 0x0000000000f252de, Semaphore: > 0x0000000001245fa8 > Arguments: 4@%esi 4@%edx 8@%rdi > stapsdt 0x0000003a NT_STAPSDT (SystemTap probe descriptors) > Provider: node > Name: gcstart > Location: 0x0000000000bf7895, Base: 0x0000000000f252de, Semaphore: > 0x0000000001245faa > Arguments: 4@%esi 4@%edx 8@%rdi > stapsdt 0x0000003b NT_STAPSDT (SystemTap probe descriptors) > Provider: node > Name: gc__done > Location: 0x0000000000bf78a4, Base: 0x0000000000f252de, Semaphore: > 0x0000000001245fac > Arguments: 4@%esi 4@%edx 8@%rdi > stapsdt 0x0000005c NT_STAPSDT (SystemTap probe descriptors) > [...etc...] > > (the "gcstart" probe is one I added to test the underscore theory.) On a separate issue, all the SDT markers here are using semaphore. And there is no support for markers with semaphores currently. Here is some old discussion on this: https://sourceware.org/ml/systemtap/2013-q3/msg00236.html We need to discuss this issue in more detail and find out a way to support those too. So, even if the error wasn't being shown with the current patchset, perf wouldn't record any hit on the markers. > Here's also the event files: > > # ls /sys/kernel/debug/tracing/events/node/ > enable gc__start_11 gc__start_2 gcstart_5 http__server__request > filter gcstart_1_1 gcstart_2 gc__start_6 http__server__request_1 > gcstart gc__start_12 gc__start_3 gcstart_6 http__server__request_2 > gc__start gc__start_13 gcstart_3 gc__start_7 http__server__request_3 > gc__start_1 gc__start_14 gc__start_4 gcstart_7 http__server__request_4 > gcstart_1 gc__start_15 gcstart_4 gc__start_8 net__server__connection > gc__start_10 gc__start_16 gc__start_5 gc__start_9 net__server__connection_1 > > This is after several iterations of --add and --del. Something seems > to be going wrong there. Thanks, This is because perf is able to make an entry into the uprobe_events file, but since its throwing an error just after this, its not deleting that entry from the uprobe_events (which will delete the corresponding events from /sys/kernel/debug/tracing/events/node too). Will certainly look into this. > [SNIP] > -- > To unsubscribe from this list: send the line "unsubscribe linux-perf-users" in > the body of a message to majordomo@vger.kernel.org > More majordomo info at http://vger.kernel.org/majordomo-info.html > -- Thanks, Hemant Kumar ^ permalink raw reply [flat|nested] 5+ messages in thread
end of thread, other threads:[~2015-04-14 10:26 UTC | newest] Thread overview: 5+ messages (download: mbox.gz / follow: Atom feed) -- links below jump to the message on this page -- 2015-04-12 2:13 perf user SDT markers Brendan Gregg 2015-04-12 20:05 ` Brendan Gregg 2015-04-13 9:27 ` Hemant Kumar 2015-04-13 17:19 ` Brendan Gregg 2015-04-14 10:25 ` Hemant Kumar
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.