* Can't set statement probe in self-built linux-4.4 @ 2016-06-30 7:58 Chris Dunlop 2016-06-30 14:58 ` Frank Ch. Eigler 0 siblings, 1 reply; 14+ messages in thread From: Chris Dunlop @ 2016-06-30 7:58 UTC (permalink / raw) To: systemtap Hi, I can't seem to set statement probes in a self-built linux-4.4. What can be going wrong? I'm using stap 3.1, gcc 4.9.2, and have SYSTEMTAP_RELEASE set to my build dir: ---------------------------------------------------------------------- $ stap --version Systemtap translator/driver (version 3.1/0.159, commit release-3.0-133-g42b97387ed3f + changes) Copyright (C) 2005-2016 Red Hat, Inc. and others This is free software; see the source for copying conditions. tested kernel versions: 2.6.18 ... 4.6-rc enabled features: AVAHI BOOST_STRING_REF LIBSQLITE3 LIBXML2 NLS NSS READLINE $ gcc --version gcc (Debian 4.9.2-10) 4.9.2 Copyright (C) 2014 Free Software Foundation, Inc. This is free software; see the source for copying conditions. There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. $ env | grep SYSTEMTAP_RELEASE SYSTEMTAP_RELEASE=/home/chris/git/linux-build/4.4.14-otn-00011-g7bcaa67 ---------------------------------------------------------------------- The kernel is configued with CONFIG options per: https://sourceware.org/systemtap/wiki/SystemTapWithSelfBuiltKernel ...with the addition of CONFIG_DEBUG_INFO_DWARF if that matters: ---------------------------------------------------------------------- $ egrep '^CONFIG_(DEBUG_INFO|KPROBES|RELAY|DEBUG_FS|MODULES|MODULE_UNLOAD|UPROBES|DEBUG_INFO_DWARF4)=' .config CONFIG_RELAY=y CONFIG_KPROBES=y CONFIG_UPROBES=y CONFIG_MODULES=y CONFIG_MODULE_UNLOAD=y CONFIG_DEBUG_INFO=y CONFIG_DEBUG_INFO_DWARF4=y CONFIG_DEBUG_FS=y ---------------------------------------------------------------------- I can set a kernel function probe, e.g.: ---------------------------------------------------------------------- $ stap -p2 -e 'probe kernel.function("register_shrinker") { printf("foo\n"); }' # probes kernel.function("register_shrinker") /* pc=_stext+0x1421b0 */ /* <- kernel.function("register_shrinker") */ ---------------------------------------------------------------------- But I can't set a kernel statement probe using either a function offset or explicit line number, e.g.: ---------------------------------------------------------------------- $ grep -n -A5 '^int register_shrinker' mm/vmscan.c 226:int register_shrinker(struct shrinker *shrinker) 227-{ 228- size_t size = sizeof(*shrinker->nr_deferred); 229- 230- /* 231- * If we only have one possible node in the system anyway, save $ stap -v -p2 -e 'probe kernel.statement("register_shinker@mm/vmscan.c+3") { printf("foo\n"); }' Pass 1: parsed user script and 116 library scripts using 93372virt/31136res/2988shr/28456data kb, in 180usr/20sys/205real ms. semantic error: resolution failed in DWARF builder semantic error: while resolving probe point: identifier 'kernel' at <input>:1:7 source: probe kernel.statement("register_shinker@mm/vmscan.c+3") { printf("foo\n"); } ^ semantic error: no match Pass 2: analyzed script: 0 probes, 0 functions, 0 embeds, 0 globals using 112444virt/50900res/3736shr/47528data kb, in 330usr/40sys/362real ms. Pass 2: analysis failed. [man error::pass2] $ stap -v -p2 -e 'probe kernel.statement("*@*/vmscan.c:229") { printf("foo\n"); }' Pass 1: parsed user script and 116 library scripts using 93372virt/31132res/2988shr/28456data kb, in 190usr/30sys/204real ms. semantic error: resolution failed in DWARF builder semantic error: while resolving probe point: identifier 'kernel' at <input>:1:7 source: probe kernel.statement("*@*/vmscan.c:229") { printf("foo\n"); } ^ semantic error: no match Pass 2: analyzed script: 0 probes, 0 functions, 0 embeds, 0 globals using 108076virt/46716res/3736shr/43160data kb, in 380usr/30sys/427real ms. Pass 2: analysis failed. [man error::pass2] $ stap -vvvvv -p2 -e 'probe kernel.statement("*@*/vmscan.c:229") { printf("foo\n"); }' >& /tmp/stap.out ---------------------------------------------------------------------- The full -vvvvvv output from above is available at: https://www.dropbox.com/s/dfepzebixd7yb36/stap.out.gz?dl=0 From here I'm pretty lost, but the image looks to contain line numbers, e.g.: ---------------------------------------------------------------------- $ readelf --debug-dump=line $SYSTEMTAP_RELEASE/vmlinux | head -45 Raw dump of debug contents of section .debug_line: Offset: 0x0 Length: 375 DWARF Version: 2 Prologue Length: 86 Minimum Instruction Length: 1 Initial value of 'is_stmt': 1 Line Base: -5 Line Range: 14 Opcode Base: 13 Opcodes: Opcode 1 has 0 args Opcode 2 has 1 args Opcode 3 has 1 args Opcode 4 has 1 args Opcode 5 has 1 args Opcode 6 has 0 args Opcode 7 has 0 args Opcode 8 has 0 args Opcode 9 has 1 args Opcode 10 has 0 args Opcode 11 has 0 args Opcode 12 has 1 args The Directory Table (offset 0x1b): 1 /home/chris/git/linux/arch/x86/kernel The File Name Table (offset 0x42): Entry Dir Time Size Name 1 1 0 0 head_64.S 2 1 0 0 verify_cpu.S Line Number Statements: [0x00000060] Extended opcode 2: set Address to 0xffffffff81000000 [0x0000006b] Advance Line by 68 to 69 [0x0000006e] Copy [0x0000006f] Special opcode 81: advance Address by 5 to 0xffffffff81000005 and Line by 6 to 75 [0x00000070] Special opcode 104: advance Address by 7 to 0xffffffff8100000c and Line by 1 to 76 [0x00000071] Special opcode 106: advance Address by 7 to 0xffffffff81000013 and Line by 3 to 79 [0x00000072] Special opcode 48: advance Address by 3 to 0xffffffff81000016 and Line by 1 to 80 [0x00000073] Special opcode 76: advance Address by 5 to 0xffffffff8100001b and Line by 1 to 81 [0x00000074] Special opcode 34: advance Address by 2 to 0xffffffff8100001d and Line by 1 to 82 [0x00000075] Special opcode 94: advance Address by 6 to 0xffffffff81000023 and Line by 5 to 87 ---------------------------------------------------------------------- ...and files seem to be in the right places, e.g.: ---------------------------------------------------------------------- $ readelf --debug-dump=info $SYSTEMTAP_RELEASE/vmlinux | less Contents of the .debug_info section: ... Compilation Unit @ offset 0x4ed2: Length: 0x30 (32-bit) Version: 4 Abbrev Offset: 0x2904 Pointer Size: 8 <0><4edd>: Abbrev Number: 1 (DW_TAG_compile_unit) <4ede> DW_AT_ranges : 0xcc400 <4ee2> DW_AT_low_pc : 0x0 <4eea> DW_AT_stmt_list : 0x141ef1 <4eee> DW_AT_GNU_dwo_name: (indirect string, offset: 0x2cb1): mm/.tmp_vmscan.dwo <4ef2> DW_AT_comp_dir : (indirect string, offset: 0x20): /home/chris/git/linux-build/4.4.14-otn-00011-g7bcaa67 <4ef6> DW_AT_GNU_pubnames: 1 <4ef6> DW_AT_GNU_addr_base: 0x11fc98 <4efa> DW_AT_GNU_dwo_id : 0xac451f4dafc46631 <4f02> DW_AT_GNU_ranges_base: 0xc88d0 $ readelf --debug-dump=info /home/chris/git/linux-build/4.4.14-otn-00011-g7bcaa67/mm/.tmp_vmscan.dwo | less Contents of the .debug_info.dwo section: Compilation Unit @ offset 0x0: Length: 0x1fbe1 (32-bit) Version: 4 Abbrev Offset: 0x0 Pointer Size: 8 <0><b>: Abbrev Number: 1 (DW_TAG_compile_unit) <c> DW_AT_producer : (indexed string: 0x37): GNU C 4.9.2 -mno-sse -mno-mmx -mno-sse2 -mno-3dnow -mno-avx -m64 -mno-80387 -mno-fp-ret-in-387 -mpreferred-stack-boundary=3 -mtune=generic -mno-red-zone -mcmodel=kernel -maccumulate-outgoing-args -mfentry -march=x86-64 -gsplit-dwarf -gdwarf-4 -O2 -std=gnu90 -p -fno-strict-aliasing -fno-common -falign-jumps=1 -falign-loops=1 -funit-at-a-time -fno-asynchronous-unwind-tables -fno-delete-null-pointer-checks -fno-stack-protector -fno-omit-frame-pointer -fno-optimize-sibling-calls -fno-var-tracking-assignments -fno-strict-overflow -fconserve-stack --param allow-store-data-races=0 <d> DW_AT_language : 1 (ANSI C) <e> DW_AT_name : (indexed string: 0xd05): /home/chris/git/linux/mm/vmscan.c <10> DW_AT_comp_dir : (indexed string: 0x4d9): /home/chris/git/linux-build/4.4.14-otn-00011-g7bcaa67 <12> DW_AT_GNU_dwo_id : 0xac451f4dafc46631 $ ls -l /home/chris/git/linux/mm/vmscan.c -rw-r--r-- 1 chris chris 113618 Jun 24 01:22 /home/chris/git/linux/mm/vmscan.c ---------------------------------------------------------------------- Where to from here? Cheers, Chris ^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: Can't set statement probe in self-built linux-4.4 2016-06-30 7:58 Can't set statement probe in self-built linux-4.4 Chris Dunlop @ 2016-06-30 14:58 ` Frank Ch. Eigler 2016-06-30 22:34 ` Chris Dunlop 0 siblings, 1 reply; 14+ messages in thread From: Frank Ch. Eigler @ 2016-06-30 14:58 UTC (permalink / raw) To: Chris Dunlop; +Cc: systemtap Hi - chris wrote: > [...] > I can't seem to set statement probes in a self-built linux-4.4. What can > be going wrong? [...] It sounds like you're setting up everything all right, good job. > I can set a kernel function probe, e.g.: > > $ stap -p2 -e 'probe kernel.function("register_shrinker") { printf("foo\n"); }' > [...] > But I can't set a kernel statement probe using either a function offset or > explicit line number [...] > $ stap -v -p2 -e 'probe kernel.statement("register_shinker@mm/vmscan.c+3") { printf("foo\n"); }' > [...] Have you tried: $ stap -L 'kernel.statement("register_shrinker@*:*")' to get the list of line numbers that systemtap recognizes? > The full -vvvvvv output from above is available at: > https://www.dropbox.com/s/dfepzebixd7yb36/stap.out.gz?dl=0 Will look at that shortly. > ---------------------------------------------------------------------- > $ readelf --debug-dump=line $SYSTEMTAP_RELEASE/vmlinux | head -45 > Raw dump of debug contents of section .debug_line: > [...] > [0x0000006e] Copy > [0x0000006f] Special opcode 81: advance Address by 5 to 0xffffffff81000005 and Line by 6 to 75 > [0x00000070] Special opcode 104: advance Address by 7 to 0xffffffff8100000c and Line by 1 to 76 > [0x00000071] Special opcode 106: advance Address by 7 to 0xffffffff81000013 and Line by 3 to 79 > [0x00000072] Special opcode 48: advance Address by 3 to 0xffffffff81000016 and Line by 1 to 80 > [0x00000073] Special opcode 76: advance Address by 5 to 0xffffffff8100001b and Line by 1 to 81 > [0x00000074] Special opcode 34: advance Address by 2 to 0xffffffff8100001d and Line by 1 to 82 > [0x00000075] Special opcode 94: advance Address by 6 to 0xffffffff81000023 and Line by 5 to 87 > ---------------------------------------------------------------------- This too looks OK. Keep in mind though that systemtap does filter out line numbers that are not uniquely mappable to a single PC address. Highly optimized code can smear statements from a single line to multiple locations, and stap doesn't want to guess wrong from ambiguous alternatives. - FChE ^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: Can't set statement probe in self-built linux-4.4 2016-06-30 14:58 ` Frank Ch. Eigler @ 2016-06-30 22:34 ` Chris Dunlop 2016-07-01 16:12 ` David Smith 0 siblings, 1 reply; 14+ messages in thread From: Chris Dunlop @ 2016-06-30 22:34 UTC (permalink / raw) To: Frank Ch. Eigler; +Cc: systemtap Hi Frank, On Thu, Jun 30, 2016 at 10:58:47AM -0400, Frank Ch. Eigler wrote: >> [...] >> I can't seem to set statement probes in a self-built linux-4.4. What can >> be going wrong? [...] [...] > Have you tried: > > $ stap -L 'kernel.statement("register_shrinker@*:*")' > > to get the list of line numbers that systemtap recognizes? No, I hadn't come across that option in my travels - that's useful! Unfortunately it doesn't come back with anything: $ stap -v -L 'kernel.statement("register_shrinker@*:*")' Pass 1: parsed user script and 116 library scripts using 93372virt/31140res/3000shr/28456data kb, in 190usr/20sys/206real ms. Pass 2: analyzed script: 0 probes, 0 functions, 0 embeds, 0 globals using 131260virt/69116res/3764shr/66344data kb, in 310usr/40sys/354real ms. $ ^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: Can't set statement probe in self-built linux-4.4 2016-06-30 22:34 ` Chris Dunlop @ 2016-07-01 16:12 ` David Smith 2016-07-01 20:44 ` Chris Dunlop 0 siblings, 1 reply; 14+ messages in thread From: David Smith @ 2016-07-01 16:12 UTC (permalink / raw) To: Chris Dunlop, Frank Ch. Eigler; +Cc: systemtap On 06/30/2016 05:34 PM, Chris Dunlop wrote: > Hi Frank, > > On Thu, Jun 30, 2016 at 10:58:47AM -0400, Frank Ch. Eigler wrote: >>> [...] >>> I can't seem to set statement probes in a self-built linux-4.4. What can >>> be going wrong? [...] > > [...] > >> Have you tried: >> >> $ stap -L 'kernel.statement("register_shrinker@*:*")' >> >> to get the list of line numbers that systemtap recognizes? > > No, I hadn't come across that option in my travels - that's useful! > Unfortunately it doesn't come back with anything: > > $ stap -v -L 'kernel.statement("register_shrinker@*:*")' > Pass 1: parsed user script and 116 library scripts using 93372virt/31140res/3000shr/28456data kb, in 190usr/20sys/206real ms. > Pass 2: analyzed script: 0 probes, 0 functions, 0 embeds, 0 globals using 131260virt/69116res/3764shr/66344data kb, in 310usr/40sys/354real ms. Hmm. Please try the following: # stap -L 'kernel.function("register_shrinker").*' That should let us know if 'register_shrinker' is only inlined in your kernel. -- David Smith dsmith@redhat.com Red Hat http://www.redhat.com 256.217.0141 (direct) 256.837.0057 (fax) ^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: Can't set statement probe in self-built linux-4.4 2016-07-01 16:12 ` David Smith @ 2016-07-01 20:44 ` Chris Dunlop [not found] ` <20160701034302.GA23357@onthe.net.au> 0 siblings, 1 reply; 14+ messages in thread From: Chris Dunlop @ 2016-07-01 20:44 UTC (permalink / raw) To: David Smith; +Cc: Frank Ch. Eigler, systemtap On Fri, Jul 01, 2016 at 11:11:54AM -0500, David Smith wrote: > On 06/30/2016 05:34 PM, Chris Dunlop wrote: >> >> $ stap -v -L 'kernel.statement("register_shrinker@*:*")' >> Pass 1: parsed user script and 116 library scripts using 93372virt/31140res/3000shr/28456data kb, in 190usr/20sys/206real ms. >> Pass 2: analyzed script: 0 probes, 0 functions, 0 embeds, 0 globals using 131260virt/69116res/3764shr/66344data kb, in 310usr/40sys/354real ms. > > Hmm. Please try the following: > > # stap -L 'kernel.function("register_shrinker").*' $ stap -L 'kernel.function("register_shrinker").*' kernel.function("register_shrinker").call kernel.function("register_shrinker").exported kernel.function("register_shrinker").return > That should let us know if 'register_shrinker' is only inlined in your > kernel. ^ permalink raw reply [flat|nested] 14+ messages in thread
[parent not found: <20160701034302.GA23357@onthe.net.au>]
* Re: Can't set statement probe in self-built linux-4.4 [not found] ` <20160701034302.GA23357@onthe.net.au> @ 2016-07-04 20:55 ` Chris Dunlop 2016-07-14 16:08 ` Chris Dunlop 1 sibling, 0 replies; 14+ messages in thread From: Chris Dunlop @ 2016-07-04 20:55 UTC (permalink / raw) To: Frank Ch. Eigler, David Smith; +Cc: systemtap On Thu, Jun 30, 2016 at 05:57:44PM +1000, Chris Dunlop wrote: > Hi, > > I can't seem to set statement probes in a self-built linux-4.4. What can > be going wrong? Apologies for being a pest, but any ideas? Chris On Fri, Jul 01, 2016 at 01:43:02PM +1000, Chris Dunlop wrote: > On Thu, Jun 30, 2016 at 08:57:38PM -0400, Frank Ch. Eigler wrote: >> Something's weird about your -vvvvv trace too; a similar command >> that works here gives a lot more "function cache ...." type lines. >> >> Any chance you could tar.xz up the whole vmlinux build tree? > > Of course: https://www.dropbox.com/s/l7cvs773mw8jqga/build.tar.xz?dl=0 (193M) > > Chris On Sat, Jul 02, 2016 at 06:44:28AM +1000, Chris Dunlop wrote: > On Fri, Jul 01, 2016 at 11:11:54AM -0500, David Smith wrote: >> On 06/30/2016 05:34 PM, Chris Dunlop wrote: >>> >>> $ stap -v -L 'kernel.statement("register_shrinker@*:*")' >>> Pass 1: parsed user script and 116 library scripts using 93372virt/31140res/3000shr/28456data kb, in 190usr/20sys/206real ms. >>> Pass 2: analyzed script: 0 probes, 0 functions, 0 embeds, 0 globals using 131260virt/69116res/3764shr/66344data kb, in 310usr/40sys/354real ms. >> >> Hmm. Please try the following: >> >> # stap -L 'kernel.function("register_shrinker").*' > > $ stap -L 'kernel.function("register_shrinker").*' > kernel.function("register_shrinker").call > kernel.function("register_shrinker").exported > kernel.function("register_shrinker").return > >> That should let us know if 'register_shrinker' is only inlined in your >> kernel. ^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: Can't set statement probe in self-built linux-4.4 [not found] ` <20160701034302.GA23357@onthe.net.au> 2016-07-04 20:55 ` Chris Dunlop @ 2016-07-14 16:08 ` Chris Dunlop 2016-07-14 16:55 ` David Smith ` (2 more replies) 1 sibling, 3 replies; 14+ messages in thread From: Chris Dunlop @ 2016-07-14 16:08 UTC (permalink / raw) To: Frank Ch. Eigler; +Cc: systemtap Hi Frank, On Fri, Jul 01, 2016 at 01:43:02PM +1000, Chris Dunlop wrote: > On Thu, Jun 30, 2016 at 08:57:38PM -0400, Frank Ch. Eigler wrote: >> Something's weird about your -vvvvv trace too; a similar command >> that works here gives a lot more "function cache ...." type lines. >> >> Any chance you could tar.xz up the whole vmlinux build tree? > > Of course: https://www.dropbox.com/s/l7cvs773mw8jqga/build.tar.xz?dl=0 (193M) Any ideas? Thanks, Chris ^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: Can't set statement probe in self-built linux-4.4 2016-07-14 16:08 ` Chris Dunlop @ 2016-07-14 16:55 ` David Smith 2016-07-14 17:27 ` Chris Dunlop 2016-07-14 17:21 ` Josh Stone 2016-07-14 23:19 ` Chris Dunlop 2 siblings, 1 reply; 14+ messages in thread From: David Smith @ 2016-07-14 16:55 UTC (permalink / raw) To: Chris Dunlop, Frank Ch. Eigler; +Cc: systemtap On 07/14/2016 11:08 AM, Chris Dunlop wrote: > Hi Frank, > > On Fri, Jul 01, 2016 at 01:43:02PM +1000, Chris Dunlop wrote: >> On Thu, Jun 30, 2016 at 08:57:38PM -0400, Frank Ch. Eigler wrote: >>> Something's weird about your -vvvvv trace too; a similar command >>> that works here gives a lot more "function cache ...." type lines. >>> >>> Any chance you could tar.xz up the whole vmlinux build tree? >> >> Of course: https://www.dropbox.com/s/l7cvs773mw8jqga/build.tar.xz?dl=0 (193M) > > Any ideas? I haven't had a chance to look at your tree, but since stap can find register_shrinker() itself: > $ stap -L 'kernel.function("register_shrinker").*' > kernel.function("register_shrinker").call > kernel.function("register_shrinker").exported > kernel.function("register_shrinker").return But not any lines from it: > $ stap -v -L 'kernel.statement("register_shrinker@*:*")' > Pass 1: parsed user script and 116 library scripts using > 93372virt/31140res/3000shr/28456data kb, in 190usr/20sys/206real ms. > Pass 2: analyzed script: 0 probes, 0 functions, 0 embeds, 0 globals > using 131260virt/69116res/3764shr/66344data kb, in 310usr/40sys/354real ms. I'd say that the compiler has optimized and reorganized things to the point where systemtap can't recognize a single line number in that function. So, what to do about it? Off the top of my head, you've got a few options: 1) One option would be to probe at a different spot, say either in the functions that call register_shrinker() or in the functions that register_shrinker() calls. 2) Another option would be to try to lower the gcc's optimization level for that source file. 3) Since you are building your own kernel, you could add a tracepoint(s) to that function that contains the info you need at the point(s) you are interested in, then hook up systemtap to that tracepoint(s). -- David Smith dsmith@redhat.com Red Hat http://www.redhat.com 256.217.0141 (direct) 256.837.0057 (fax) ^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: Can't set statement probe in self-built linux-4.4 2016-07-14 16:55 ` David Smith @ 2016-07-14 17:27 ` Chris Dunlop 2016-07-14 18:23 ` David Smith 0 siblings, 1 reply; 14+ messages in thread From: Chris Dunlop @ 2016-07-14 17:27 UTC (permalink / raw) To: David Smith; +Cc: Frank Ch. Eigler, systemtap On Thu, Jul 14, 2016 at 11:54:56AM -0500, David Smith wrote: > On 07/14/2016 11:08 AM, Chris Dunlop wrote: >> On Fri, Jul 01, 2016 at 01:43:02PM +1000, Chris Dunlop wrote: >>> On Thu, Jun 30, 2016 at 08:57:38PM -0400, Frank Ch. Eigler wrote: >>>> Something's weird about your -vvvvv trace too; a similar command >>>> that works here gives a lot more "function cache ...." type lines. >>>> >>>> Any chance you could tar.xz up the whole vmlinux build tree? >>> >>> Of course: https://www.dropbox.com/s/l7cvs773mw8jqga/build.tar.xz?dl=0 (193M) >> >> Any ideas? > > I haven't had a chance to look at your tree, but since stap can find > register_shrinker() itself: > >> $ stap -L 'kernel.function("register_shrinker").*' >> kernel.function("register_shrinker").call >> kernel.function("register_shrinker").exported >> kernel.function("register_shrinker").return > > But not any lines from it: > >> $ stap -v -L 'kernel.statement("register_shrinker@*:*")' >> Pass 1: parsed user script and 116 library scripts using >> 93372virt/31140res/3000shr/28456data kb, in 190usr/20sys/206real ms. >> Pass 2: analyzed script: 0 probes, 0 functions, 0 embeds, 0 globals >> using 131260virt/69116res/3764shr/66344data kb, in > 310usr/40sys/354real ms. > > I'd say that the compiler has optimized and reorganized things to the > point where systemtap can't recognize a single line number in that function. Actually, register_shrinker was a random example: I was originally trying to (and am still wanting to) set statement probes in an externally compiled kernel module (zfsonlinux). That was (and is) failing the same way, so I thought I'd try to go back to basics and ended up at register_shinker. I haven't been able to set statement probes on anything I've tried: kernel, modules, external modules. For what it's worth, if this is expected to bring back all the line numbers systemtap can find in the whole kernel, it's not finding any at all: $ stap -v -L 'kernel.statement("*@*:*")' Pass 1: parsed user script and 116 library scripts using 93372virt/31144res/3000shr/28456data kb, in 190usr/20sys/204real ms. Pass 2: analyzed script: 0 probes, 0 functions, 0 embeds, 0 globals using 132988virt/70760res/3764shr/68072data kb, in 300usr/40sys/351real ms. $ > So, what to do about it? Off the top of my head, you've got a few options: > > 1) One option would be to probe at a different spot, say either in the > functions that call register_shrinker() or in the functions that > register_shrinker() calls. See above: I can't put statement probes in anywhere in any function. > 2) Another option would be to try to lower the gcc's optimization level > for that source file. Surely shouldn't be required for the whole kernel? That would be a bloody good optimiser! Or a really crap one. :-) > 3) Since you are building your own kernel, you could add a tracepoint(s) > to that function that contains the info you need at the point(s) you are > interested in, then hook up systemtap to that tracepoint(s). ...or printks(). Yes, but that's what I'd like to avoid by using systemtap statement probes. Chris ^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: Can't set statement probe in self-built linux-4.4 2016-07-14 17:27 ` Chris Dunlop @ 2016-07-14 18:23 ` David Smith 0 siblings, 0 replies; 14+ messages in thread From: David Smith @ 2016-07-14 18:23 UTC (permalink / raw) To: Chris Dunlop; +Cc: Frank Ch. Eigler, systemtap On 07/14/2016 12:27 PM, Chris Dunlop wrote: > On Thu, Jul 14, 2016 at 11:54:56AM -0500, David Smith wrote: >> I'd say that the compiler has optimized and reorganized things to the >> point where systemtap can't recognize a single line number in that function. > > Actually, register_shrinker was a random example: I was originally trying to > (and am still wanting to) set statement probes in an externally compiled > kernel module (zfsonlinux). That was (and is) failing the same way, so I > thought I'd try to go back to basics and ended up at register_shinker. Ah, I didn't realize that. > I haven't been able to set statement probes on anything I've tried: kernel, > modules, external modules. Hmm, so we've got a bigger problem than just register_shrinker(). > For what it's worth, if this is expected to bring back all the line numbers > systemtap can find in the whole kernel, it's not finding any at all: > > $ stap -v -L 'kernel.statement("*@*:*")' > Pass 1: parsed user script and 116 library scripts using 93372virt/31144res/3000shr/28456data kb, in 190usr/20sys/204real ms. > Pass 2: analyzed script: 0 probes, 0 functions, 0 embeds, 0 globals using 132988virt/70760res/3764shr/68072data kb, in 300usr/40sys/351real ms. > $ OK, so I downloaded your kernel and looked at the build options. In your config file, you've got: CONFIG_DEBUG_INFO=y # CONFIG_DEBUG_INFO_REDUCED is not set CONFIG_DEBUG_INFO_SPLIT=y CONFIG_DEBUG_INFO_DWARF4=y In a Fedora 23 kernel, you'll see: CONFIG_DEBUG_INFO=y # CONFIG_DEBUG_INFO_REDUCED is not set # CONFIG_DEBUG_INFO_SPLIT is not set # CONFIG_DEBUG_INFO_DWARF4 is not set CONFIG_DEBUG_INFO_VTA=y My guess would be that systemtap is having trouble with either the CONFIG_DEBUG_INFO_SPLIT option (which adds the '-gsplit-dwarf' gcc option) or the CONFIG_DEBUG_INFO_DWARF4 option (which adds the '-gdwarf-4' gcc option). I'd suspect split debuginfo first. As far as I know, systemtap has never been used with those individual .dwo files. Can you recompile without CONFIG_DEBUG_INFO_SPLIT? -- David Smith dsmith@redhat.com Red Hat http://www.redhat.com 256.217.0141 (direct) 256.837.0057 (fax) ^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: Can't set statement probe in self-built linux-4.4 2016-07-14 16:08 ` Chris Dunlop 2016-07-14 16:55 ` David Smith @ 2016-07-14 17:21 ` Josh Stone 2016-07-14 17:30 ` Chris Dunlop 2016-07-14 23:19 ` Chris Dunlop 2 siblings, 1 reply; 14+ messages in thread From: Josh Stone @ 2016-07-14 17:21 UTC (permalink / raw) To: Chris Dunlop, Frank Ch. Eigler; +Cc: systemtap On 07/14/2016 09:08 AM, Chris Dunlop wrote: > Hi Frank, > > On Fri, Jul 01, 2016 at 01:43:02PM +1000, Chris Dunlop wrote: >> On Thu, Jun 30, 2016 at 08:57:38PM -0400, Frank Ch. Eigler wrote: >>> Something's weird about your -vvvvv trace too; a similar command >>> that works here gives a lot more "function cache ...." type lines. >>> >>> Any chance you could tar.xz up the whole vmlinux build tree? >> >> Of course: https://www.dropbox.com/s/l7cvs773mw8jqga/build.tar.xz?dl=0 (193M) > > Any ideas? $ grep DEBUG_INFO .config CONFIG_DEBUG_INFO=y # CONFIG_DEBUG_INFO_REDUCED is not set CONFIG_DEBUG_INFO_SPLIT=y CONFIG_DEBUG_INFO_DWARF4=y I think SPLIT is the problem. This puts all debuginfo into separate .dwo objects, and then vmlinux itself only contains DW_AT_GNU_dwo_name references from each CU. There's no dwo_name support at all in elfutils yet, thus stap doesn't support it either. The function probe that you are getting is based only on the symbol table, which is why you're not seeing any arguments either. And statement probes aren't available at all without working debuginfo. For comparision, I get this on Fedora 24: > $ stap -L 'kernel.function("register_shrinker").*' > kernel.function("register_shrinker@mm/vmscan.c:227").call $shrinker:struct shrinker* $size:size_t > kernel.function("register_shrinker@mm/vmscan.c:227").callee("down_write@kernel/locking/rwsem.c:46") $sem:struct rw_semaphore* > kernel.function("register_shrinker@mm/vmscan.c:227").callee("up_write@kernel/locking/rwsem.c:89") $sem:struct rw_semaphore* > kernel.function("register_shrinker@mm/vmscan.c:227").exported $shrinker:struct shrinker* $size:size_t > kernel.function("register_shrinker@mm/vmscan.c:227").return $return:int $shrinker:struct shrinker* $size:size_t > $ stap -L 'kernel.statement("register_shrinker@*:*")' > kernel.statement("register_shrinker@mm/vmscan.c:228") $shrinker:struct shrinker* $size:size_t > kernel.statement("register_shrinker@mm/vmscan.c:231") $shrinker:struct shrinker* $size:size_t > kernel.statement("register_shrinker@mm/vmscan.c:232") $shrinker:struct shrinker* > kernel.statement("register_shrinker@mm/vmscan.c:234") $shrinker:struct shrinker* > kernel.statement("register_shrinker@mm/vmscan.c:235") $shrinker:struct shrinker* > kernel.statement("register_shrinker@mm/vmscan.c:236") $shrinker:struct shrinker* > kernel.statement("register_shrinker@mm/vmscan.c:238") $shrinker:struct shrinker* > kernel.statement("register_shrinker@mm/vmscan.c:239") $shrinker:struct shrinker* > kernel.statement("register_shrinker@mm/vmscan.c:240") $shrinker:struct shrinker* > kernel.statement("register_shrinker@mm/vmscan.c:241") $shrinker:struct shrinker* > kernel.statement("register_shrinker@mm/vmscan.c:242") $shrinker:struct shrinker* ^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: Can't set statement probe in self-built linux-4.4 2016-07-14 17:21 ` Josh Stone @ 2016-07-14 17:30 ` Chris Dunlop 0 siblings, 0 replies; 14+ messages in thread From: Chris Dunlop @ 2016-07-14 17:30 UTC (permalink / raw) To: Josh Stone; +Cc: Frank Ch. Eigler, systemtap On Thu, Jul 14, 2016 at 10:20:56AM -0700, Josh Stone wrote: > On 07/14/2016 09:08 AM, Chris Dunlop wrote: > > On Fri, Jul 01, 2016 at 01:43:02PM +1000, Chris Dunlop wrote: > > Any ideas? > > $ grep DEBUG_INFO .config > CONFIG_DEBUG_INFO=y > # CONFIG_DEBUG_INFO_REDUCED is not set > CONFIG_DEBUG_INFO_SPLIT=y > CONFIG_DEBUG_INFO_DWARF4=y > > I think SPLIT is the problem. This puts all debuginfo into separate > .dwo objects, and then vmlinux itself only contains DW_AT_GNU_dwo_name > references from each CU. > > There's no dwo_name support at all in elfutils yet, thus stap doesn't > support it either. > > The function probe that you are getting is based only on the symbol > table, which is why you're not seeing any arguments either. And > statement probes aren't available at all without working debuginfo. OK, that sounds like it explains the problem. I'll remove the SPLIT and let you know... Thanks! Chris ^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: Can't set statement probe in self-built linux-4.4 2016-07-14 16:08 ` Chris Dunlop 2016-07-14 16:55 ` David Smith 2016-07-14 17:21 ` Josh Stone @ 2016-07-14 23:19 ` Chris Dunlop 2016-07-15 13:57 ` David Smith 2 siblings, 1 reply; 14+ messages in thread From: Chris Dunlop @ 2016-07-14 23:19 UTC (permalink / raw) To: Josh Stone, David Smith, Frank Ch. Eigler; +Cc: systemtap Hi Josh, Dave, Frank, On Fri, Jul 15, 2016 at 03:29:54AM +1000, Chris Dunlop wrote: > On Thu, Jul 14, 2016 at 10:20:56AM -0700, Josh Stone wrote: > > On 07/14/2016 09:08 AM, Chris Dunlop wrote: > > > On Fri, Jul 01, 2016 at 01:43:02PM +1000, Chris Dunlop wrote: > > > Any ideas? > > > > $ grep DEBUG_INFO .config > > CONFIG_DEBUG_INFO=y > > # CONFIG_DEBUG_INFO_REDUCED is not set > > CONFIG_DEBUG_INFO_SPLIT=y > > CONFIG_DEBUG_INFO_DWARF4=y > > > > I think SPLIT is the problem. This puts all debuginfo into separate > > .dwo objects, and then vmlinux itself only contains DW_AT_GNU_dwo_name > > references from each CU. > > > > There's no dwo_name support at all in elfutils yet, thus stap doesn't > > support it either. > > > > The function probe that you are getting is based only on the symbol > > table, which is why you're not seeing any arguments either. And > > statement probes aren't available at all without working debuginfo. > > OK, that sounds like it explains the problem. > > I'll remove the SPLIT and let you know... Yup, that was it. It's probably worth mentioning this on the "self built kernel" wiki page until elfutils and therefore systemtap gain the support: Using systemtap with self-built kernels https://sourceware.org/systemtap/wiki/SystemTapWithSelfBuiltKernel Thanks for your help! Chris ^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: Can't set statement probe in self-built linux-4.4 2016-07-14 23:19 ` Chris Dunlop @ 2016-07-15 13:57 ` David Smith 0 siblings, 0 replies; 14+ messages in thread From: David Smith @ 2016-07-15 13:57 UTC (permalink / raw) To: Chris Dunlop, Josh Stone, Frank Ch. Eigler; +Cc: systemtap On 07/14/2016 06:18 PM, Chris Dunlop wrote: >> I'll remove the SPLIT and let you know... > > Yup, that was it. Great! > It's probably worth mentioning this on the "self built kernel" wiki page > until elfutils and therefore systemtap gain the support: > > Using systemtap with self-built kernels > https://sourceware.org/systemtap/wiki/SystemTapWithSelfBuiltKernel I added a sentence to that wiki page mentioning that split debuginfo isn't supported. > Thanks for your help! I'm glad we were able to fix your problem so that systemtap is useful for you. -- David Smith dsmith@redhat.com Red Hat http://www.redhat.com 256.217.0141 (direct) 256.837.0057 (fax) ^ permalink raw reply [flat|nested] 14+ messages in thread
end of thread, other threads:[~2016-07-15 13:57 UTC | newest] Thread overview: 14+ messages (download: mbox.gz / follow: Atom feed) -- links below jump to the message on this page -- 2016-06-30 7:58 Can't set statement probe in self-built linux-4.4 Chris Dunlop 2016-06-30 14:58 ` Frank Ch. Eigler 2016-06-30 22:34 ` Chris Dunlop 2016-07-01 16:12 ` David Smith 2016-07-01 20:44 ` Chris Dunlop [not found] ` <20160701034302.GA23357@onthe.net.au> 2016-07-04 20:55 ` Chris Dunlop 2016-07-14 16:08 ` Chris Dunlop 2016-07-14 16:55 ` David Smith 2016-07-14 17:27 ` Chris Dunlop 2016-07-14 18:23 ` David Smith 2016-07-14 17:21 ` Josh Stone 2016-07-14 17:30 ` Chris Dunlop 2016-07-14 23:19 ` Chris Dunlop 2016-07-15 13:57 ` David Smith
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 read-only IMAP folder(s) and NNTP newsgroup(s).