* kprobe string @ 2014-07-17 0:51 Brendan Gregg 2014-07-17 4:41 ` David Ahern 0 siblings, 1 reply; 6+ messages in thread From: Brendan Gregg @ 2014-07-17 0:51 UTC (permalink / raw) To: linux-perf-use. G'Day, I'm not sure where else to ask this; I don't think this functionality is in perf_events yet... kprobes is supposed to be able to handle string arguments, but I've not been able to find a single working example. I'm trying (on 3.16): # cd /sys/kernel/debug/tracing # echo 'r:getname getname $retval:string' > kprobe_events -bash: echo: write error: Invalid argument # echo 'p:myprobe do_sys_open %dx:string' > kprobe_events -bash: echo: write error: Invalid argument I'm following the syntax in Documentation/trace/kprobetrace.txt by Masami Hiramatsu, and it is recognizing "string". But I'm getting these errors: # dmesg | tail -4 [98021.813560] string type has no corresponding fetch method. [98021.813564] Parse error at argument[0]. (-22) [98705.956199] string type has no corresponding fetch method. [98705.956203] Parse error at argument[0]. (-22) Anyone seen this work? I'm checking the source... Thanks in advance, Brendan -- http://www.brendangregg.com ^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: kprobe string 2014-07-17 0:51 kprobe string Brendan Gregg @ 2014-07-17 4:41 ` David Ahern 2014-07-17 6:29 ` Brendan Gregg 0 siblings, 1 reply; 6+ messages in thread From: David Ahern @ 2014-07-17 4:41 UTC (permalink / raw) To: Brendan Gregg, linux-perf-use. On 07/16/2014 06:51 PM, Brendan Gregg wrote: > G'Day, > > I'm not sure where else to ask this; I don't think this functionality > is in perf_events yet... > > kprobes is supposed to be able to handle string arguments, but I've > not been able to find a single working example. I'm trying (on 3.16): > > # cd /sys/kernel/debug/tracing > # echo 'r:getname getname $retval:string' > kprobe_events > -bash: echo: write error: Invalid argument > # echo 'p:myprobe do_sys_open %dx:string' > kprobe_events > -bash: echo: write error: Invalid argument > > I'm following the syntax in Documentation/trace/kprobetrace.txt by > Masami Hiramatsu, and it is recognizing "string". But I'm getting > these errors: > > # dmesg | tail -4 > [98021.813560] string type has no corresponding fetch method. > [98021.813564] Parse error at argument[0]. (-22) > [98705.956199] string type has no corresponding fetch method. > [98705.956203] Parse error at argument[0]. (-22) > > Anyone seen this work? I'm checking the source... Thanks in advance, Have you seen this: https://lkml.org/lkml/2014/6/19/698 David ^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: kprobe string 2014-07-17 4:41 ` David Ahern @ 2014-07-17 6:29 ` Brendan Gregg 2014-07-17 7:24 ` Namhyung Kim 0 siblings, 1 reply; 6+ messages in thread From: Brendan Gregg @ 2014-07-17 6:29 UTC (permalink / raw) To: David Ahern; +Cc: linux-perf-use. G'Day David, On Wed, Jul 16, 2014 at 9:41 PM, David Ahern <dsahern@gmail.com> wrote: > > > On 07/16/2014 06:51 PM, Brendan Gregg wrote: >> >> G'Day, >> >> I'm not sure where else to ask this; I don't think this functionality >> is in perf_events yet... >> >> kprobes is supposed to be able to handle string arguments, but I've >> not been able to find a single working example. I'm trying (on 3.16): >> >> # cd /sys/kernel/debug/tracing >> # echo 'r:getname getname $retval:string' > kprobe_events >> -bash: echo: write error: Invalid argument >> # echo 'p:myprobe do_sys_open %dx:string' > kprobe_events >> -bash: echo: write error: Invalid argument >> >> I'm following the syntax in Documentation/trace/kprobetrace.txt by >> Masami Hiramatsu, and it is recognizing "string". But I'm getting >> these errors: >> >> # dmesg | tail -4 >> [98021.813560] string type has no corresponding fetch method. >> [98021.813564] Parse error at argument[0]. (-22) >> [98705.956199] string type has no corresponding fetch method. >> [98705.956203] Parse error at argument[0]. (-22) >> >> Anyone seen this work? I'm checking the source... Thanks in advance, > > > Have you seen this: > https://lkml.org/lkml/2014/6/19/698 > Thanks! (I'm trying to keep up with all the perf messages on lkml, but missed this.) So, perf can already do this?? And it's the same syntax (":string") as kprobes? I just tried it out (on 3.14.5): # perf probe 'getname filename:string' Added new event: [...] # perf record -e probe:getname -a sleep 5 [ perf record: Woken up 1 times to write data ] [ perf record: Captured and wrote 0.234 MB perf.data (~10241 samples) ] # perf script perf 13587 [000] 3576718.127120: probe:getname: (ffffffff811bbd20) filename_string="/home/bgregg-testtest/libexec/perf-core/sleep" perf 13587 [000] 3576718.127142: probe:getname: (ffffffff811bbd20) filename_string="/usr/local/sbin/sleep" perf 13587 [000] 3576718.127151: probe:getname: (ffffffff811bbd20) filename_string="/usr/local/bin/sleep" perf 13587 [000] 3576718.127159: probe:getname: (ffffffff811bbd20) filename_string="/usr/sbin/sleep" perf 13587 [000] 3576718.127170: probe:getname: (ffffffff811bbd20) filename_string="/usr/bin/sleep" perf 13587 [000] 3576718.127180: probe:getname: (ffffffff811bbd20) filename_string="/sbin/sleep" perf 13587 [000] 3576718.127189: probe:getname: (ffffffff811bbd20) filename_string="/bin/sleep" sleep 13587 [000] 3576718.162025: probe:getname: (ffffffff811bbd20) filename_string="/etc/ld.so.cache" sleep 13587 [000] 3576718.162057: probe:getname: (ffffffff811bbd20) filename_string="/lib/x86_64-linux-gnu/libc.so.6" [...] Wow. Ok, so that's one solution! :-) It does need debuginfo, which is a bit of a problem here (the Netflix cloud, where instances are created and destroyed quickly, so they are optimized to be small). I did try just using the return value, which does work without debuginfo, however, the :string modifier doesn't work. Eg, trying: # perf probe 'getname%return $retval:string' Added new event: Failed to write event: Invalid argument Error: Failed to add events. (-1) $retval really is a string (well, it's a struct filename *, where the first member is a char *, so close enough), so perhaps perf could enhanced to allow this, and I'd be able to trace strings without debuginfo. (Unless there's another workaround.) So tools/perf/Documentation/perf-probe.txt does at least explain when :string won't work: "You can specify 'string' type only for the local variable or structure member which is an array of or a pointer to 'char' or 'unsigned char' type." I wonder if kprobes has this restriction as well. thanks, Brendan -- http://www.brendangregg.com ^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: kprobe string 2014-07-17 6:29 ` Brendan Gregg @ 2014-07-17 7:24 ` Namhyung Kim 2014-07-17 8:23 ` Brendan Gregg 0 siblings, 1 reply; 6+ messages in thread From: Namhyung Kim @ 2014-07-17 7:24 UTC (permalink / raw) To: Brendan Gregg; +Cc: David Ahern, linux-perf-use. Hi Brendan, On Wed, 16 Jul 2014 23:29:10 -0700, Brendan Gregg wrote: > G'Day David, > > On Wed, Jul 16, 2014 at 9:41 PM, David Ahern <dsahern@gmail.com> wrote: >> >> >> On 07/16/2014 06:51 PM, Brendan Gregg wrote: >>> >>> G'Day, >>> >>> I'm not sure where else to ask this; I don't think this functionality >>> is in perf_events yet... >>> >>> kprobes is supposed to be able to handle string arguments, but I've >>> not been able to find a single working example. I'm trying (on 3.16): >>> >>> # cd /sys/kernel/debug/tracing >>> # echo 'r:getname getname $retval:string' > kprobe_events >>> -bash: echo: write error: Invalid argument >>> # echo 'p:myprobe do_sys_open %dx:string' > kprobe_events >>> -bash: echo: write error: Invalid argument >>> >>> I'm following the syntax in Documentation/trace/kprobetrace.txt by >>> Masami Hiramatsu, and it is recognizing "string". But I'm getting >>> these errors: >>> >>> # dmesg | tail -4 >>> [98021.813560] string type has no corresponding fetch method. >>> [98021.813564] Parse error at argument[0]. (-22) >>> [98705.956199] string type has no corresponding fetch method. >>> [98705.956203] Parse error at argument[0]. (-22) >>> >>> Anyone seen this work? I'm checking the source... Thanks in advance, >> >> >> Have you seen this: >> https://lkml.org/lkml/2014/6/19/698 >> > > Thanks! (I'm trying to keep up with all the perf messages on lkml, but > missed this.) > > So, perf can already do this?? And it's the same syntax (":string") as kprobes? > > I just tried it out (on 3.14.5): > > # perf probe 'getname filename:string' > Added new event: > [...] > # perf record -e probe:getname -a sleep 5 > [ perf record: Woken up 1 times to write data ] > [ perf record: Captured and wrote 0.234 MB perf.data (~10241 samples) ] > # perf script > perf 13587 [000] 3576718.127120: probe:getname: > (ffffffff811bbd20) > filename_string="/home/bgregg-testtest/libexec/perf-core/sleep" > perf 13587 [000] 3576718.127142: probe:getname: > (ffffffff811bbd20) filename_string="/usr/local/sbin/sleep" > perf 13587 [000] 3576718.127151: probe:getname: > (ffffffff811bbd20) filename_string="/usr/local/bin/sleep" > perf 13587 [000] 3576718.127159: probe:getname: > (ffffffff811bbd20) filename_string="/usr/sbin/sleep" > perf 13587 [000] 3576718.127170: probe:getname: > (ffffffff811bbd20) filename_string="/usr/bin/sleep" > perf 13587 [000] 3576718.127180: probe:getname: > (ffffffff811bbd20) filename_string="/sbin/sleep" > perf 13587 [000] 3576718.127189: probe:getname: > (ffffffff811bbd20) filename_string="/bin/sleep" > sleep 13587 [000] 3576718.162025: probe:getname: > (ffffffff811bbd20) filename_string="/etc/ld.so.cache" > sleep 13587 [000] 3576718.162057: probe:getname: > (ffffffff811bbd20) filename_string="/lib/x86_64-linux-gnu/libc.so.6" > [...] > > Wow. > > Ok, so that's one solution! :-) > > It does need debuginfo, which is a bit of a problem here (the Netflix > cloud, where instances are created and destroyed quickly, so they are > optimized to be small). > > I did try just using the return value, which does work without > debuginfo, however, the :string modifier doesn't work. Eg, trying: > > # perf probe 'getname%return $retval:string' > Added new event: > Failed to write event: Invalid argument > Error: Failed to add events. (-1) > > $retval really is a string (well, it's a struct filename *, where the > first member is a char *, so close enough), so perhaps perf could > enhanced to allow this, and I'd be able to trace strings without > debuginfo. (Unless there's another workaround.) > > So tools/perf/Documentation/perf-probe.txt does at least explain when > :string won't work: "You can specify 'string' type only for the local > variable or structure member which is an array of or a pointer to > 'char' or 'unsigned char' type." I wonder if kprobes has this > restriction as well. Currently, "retval" and "reg" (and some other) fetch methods don't support string type. But I guess it can be easily worked around by using "deref" method. Have you tried something like below (untested)? # perf probe 'getname%return +0($retval):string' Hmm.. maybe below (as you mentioned it's a char * in struct filename *). # perf probe 'getname%return +0(+0($retval)):string' Thanks, Namhyung ^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: kprobe string 2014-07-17 7:24 ` Namhyung Kim @ 2014-07-17 8:23 ` Brendan Gregg 2014-07-21 1:20 ` Brendan Gregg 0 siblings, 1 reply; 6+ messages in thread From: Brendan Gregg @ 2014-07-17 8:23 UTC (permalink / raw) To: Namhyung Kim; +Cc: David Ahern, linux-perf-use. G'Day Namhyung, On Thu, Jul 17, 2014 at 12:24 AM, Namhyung Kim <namhyung@kernel.org> wrote: > Hi Brendan, > > On Wed, 16 Jul 2014 23:29:10 -0700, Brendan Gregg wrote: >> G'Day David, >> >> On Wed, Jul 16, 2014 at 9:41 PM, David Ahern <dsahern@gmail.com> wrote: >>> >>> >>> On 07/16/2014 06:51 PM, Brendan Gregg wrote: >>>> >>>> G'Day, >>>> >>>> I'm not sure where else to ask this; I don't think this functionality >>>> is in perf_events yet... >>>> >>>> kprobes is supposed to be able to handle string arguments, but I've >>>> not been able to find a single working example. I'm trying (on 3.16): >>>> [...] >> Ok, so that's one solution! :-) >> >> It does need debuginfo, which is a bit of a problem here (the Netflix >> cloud, where instances are created and destroyed quickly, so they are >> optimized to be small). >> >> I did try just using the return value, which does work without >> debuginfo, however, the :string modifier doesn't work. Eg, trying: >> >> # perf probe 'getname%return $retval:string' >> Added new event: >> Failed to write event: Invalid argument >> Error: Failed to add events. (-1) >> >> $retval really is a string (well, it's a struct filename *, where the >> first member is a char *, so close enough), so perhaps perf could >> enhanced to allow this, and I'd be able to trace strings without >> debuginfo. (Unless there's another workaround.) >> >> So tools/perf/Documentation/perf-probe.txt does at least explain when >> :string won't work: "You can specify 'string' type only for the local >> variable or structure member which is an array of or a pointer to >> 'char' or 'unsigned char' type." I wonder if kprobes has this >> restriction as well. > > Currently, "retval" and "reg" (and some other) fetch methods don't support string > type. But I guess it can be easily worked around by using "deref" method. > Have you tried something like below (untested)? > > # perf probe 'getname%return +0($retval):string' > > Hmm.. maybe below (as you mentioned it's a char * in struct filename *). > > # perf probe 'getname%return +0(+0($retval)):string' > Excellent, thanks! And this is also working syntax for kprobes! Here's 3.2, when getname() returned a char *: # echo 'r:myprobe getname +0($retval):string' > kprobe_events # echo 1 > events/kprobes/enable # tail trace postgres-2421 [000] 1507756.012578: myprobe: (do_sys_open+0xc3/0x240 <- getname) arg1="global/pg_filenode.map" postgres-2421 [000] 1507756.012629: myprobe: (do_sys_open+0xc3/0x240 <- getname) arg1="global/pg_internal.init" postgres-2421 [000] 1507756.013443: myprobe: (do_sys_open+0xc3/0x240 <- getname) arg1="base/16384/PG_VERSION" postgres-2421 [000] 1507756.013507: myprobe: (do_sys_open+0xc3/0x240 <- getname) arg1="base/16384/pg_filenode.map" [...] # echo 0 > events/kprobes/enable And 3.16, where getname() is the struct filename *: # echo 'r:myprobe getname +0(+0($retval)):string' > kprobe_events # echo 1 > events/kprobes/myprobe/enable # tail trace supervise-1684 [001] d... 6157863.184014: myprobe: (user_path_parent+0x2e/0x80 <- getname) arg1="supervise/status.new" supervise-1684 [001] d... 6157863.184016: myprobe: (user_path_parent+0x2e/0x80 <- getname) arg1="supervise/status" supervise-1694 [000] d... 6157863.184016: myprobe: (user_path_parent+0x2e/0x80 <- getname) arg1="supervise/status" supervise-16964 [001] d... 6157863.184242: myprobe: (SyS_execve+0x20/0x40 <- getname) arg1="./run" [...] # echo 0 > events/kprobes/myprobe/enable Wow... So now I know perf can do this, and, I have working examples of kprobes via ftrace if needed (I am trying to use perf first, due to the way it buffers, error handling, and concurrent usage). Thanks! Brendan -- http://www.brendangregg.com ^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: kprobe string 2014-07-17 8:23 ` Brendan Gregg @ 2014-07-21 1:20 ` Brendan Gregg 0 siblings, 0 replies; 6+ messages in thread From: Brendan Gregg @ 2014-07-21 1:20 UTC (permalink / raw) To: Namhyung Kim; +Cc: David Ahern, linux-perf-use. On Thu, Jul 17, 2014 at 1:23 AM, Brendan Gregg <brendan.d.gregg@gmail.com> wrote: > G'Day Namhyung, [...] > Wow... So now I know perf can do this, and, I have working examples of > kprobes via ftrace if needed (I am trying to use perf first, due to > the way it buffers, error handling, and concurrent usage). > To follow up: I ended up using kprobes, as I wanted to match on the calling function (the "(xxx <- yyy)" part), which wasn't showing symbols for perf_events, but was for ftrace. The outcome is a (hacky) Linux port of my popular opensnoop tool, based on Linux ftrace: # ./opensnoop Tracing open()s. Ctrl-C to end. COMM PID FD FILE opensnoop 5881 0x3 <...> 5900 0x3 /etc/ld.so.cache opensnoop 5899 0x3 /etc/ld.so.cache opensnoop 5899 0x3 /lib/x86_64-linux-gnu/libm.so.6 <...> 5900 0x3 /lib/x86_64-linux-gnu/libc.so.6 opensnoop 5899 0x3 /lib/x86_64-linux-gnu/libc.so.6 <...> 5900 0x3 /usr/lib/locale/locale-archive <...> 5900 0x3 trace_pipe ls 5915 0x3 /etc/ld.so.cache ls 5915 0x3 /lib/x86_64-linux-gnu/libselinux.so.1 ls 5915 0x3 /lib/x86_64-linux-gnu/librt.so.1 ls 5915 0x3 /lib/x86_64-linux-gnu/libacl.so.1 ls 5915 0x3 /lib/x86_64-linux-gnu/libc.so.6 ls 5915 0x3 /lib/x86_64-linux-gnu/libdl.so.2 ls 5915 0x3 /lib/x86_64-linux-gnu/libpthread.so.0 ls 5915 0x3 /lib/x86_64-linux-gnu/libattr.so.1 ls 5915 0x3 /proc/filesystems ls 5915 0x3 /usr/lib/locale/locale-archive supervise 1690 0x9 supervise/status.new supervise 1681 0x9 supervise/status.new supervise 1690 0x9 supervise/status.new supervise 1681 0x9 supervise/status.new [...] This works by caching the getname() result, and reading it for sys_exit_open. It works in my large environment of 3.2 servers, without debuginfo, since I'm just using $retval:string. If debuginfo is available I can improve opensnoop a bit by using just the syscall tracepoints, and tracing filenames using "filename:string" on sys_enter_open, but this adds a lot of lag to wait for a debuginfo install when wanting to debug an issue (and having debuginfo installed on all our servers isn't really practical). I couldn't find entry argument versions of $retval, eg, $arg1, $arg2, etc. Such a thing would let me use the syscall open tracepoint with $arg2:string, without debuginfo, so I could avoid dynamic tracing of getname(), and therefore improving stability a bit. I was trying to hack this up using %ax, %bx, etc, but I think that's also brittle... opensnoop supports various options: # ./opensnoop -h USAGE: opensnoop [-htx] [-d secs] [-f file] [-p PID] [-n name] -d seconds # trace duration, and use buffers -f file # match filename (partials ok) -n name # process name to match on I/O issue -p PID # PID to match on I/O issue -t # include time (seconds) -x # only show failed opens -h # this usage message eg, opensnoop # watch open()s live (unbuffered) opensnoop -d 1 # trace 1 sec (buffered) opensnoop -f conf # trace filenames containing "conf" opensnoop -p 181 # trace I/O issued by PID 181 only It's on github: https://github.com/brendangregg/perf-tools Brendan -- http://www.brendangregg.com ^ permalink raw reply [flat|nested] 6+ messages in thread
end of thread, other threads:[~2014-07-21 1:20 UTC | newest] Thread overview: 6+ messages (download: mbox.gz follow: Atom feed -- links below jump to the message on this page -- 2014-07-17 0:51 kprobe string Brendan Gregg 2014-07-17 4:41 ` David Ahern 2014-07-17 6:29 ` Brendan Gregg 2014-07-17 7:24 ` Namhyung Kim 2014-07-17 8:23 ` Brendan Gregg 2014-07-21 1:20 ` Brendan Gregg
This is a public inbox, see mirroring instructions for how to clone and mirror all data and code used for this inbox; as well as URLs for NNTP newsgroup(s).