public inbox for systemtap@sourceware.org
 help / color / mirror / Atom feed
From: Matt Vibrys <vibrys@o2.pl>
To: "Frank Ch. Eigler" <fche@redhat.com>, systemtap@sourceware.org
Subject: Re: non-working .return probepoint from modules
Date: Tue, 22 Mar 2022 10:48:08 +0100	[thread overview]
Message-ID: <umt4sfrawc6f.fsf@o2.pl> (raw)
In-Reply-To: <umt4zgozr06x.fsf@o2.pl>


Matt Vibrys via Systemtap <systemtap@sourceware.org> writes:

> Frank Ch. Eigler <fche@redhat.com> writes:
>
>>>> The output below provides function calls, but it's silent about it's
>>>> returns. Why so?:
>>
>> Good question, I wonder too!
>>
>>>> gmm@MY-HOST:~/user$ sudo /opt/systemtap-4.6/bin/stap -vv /home/gmm/user/scripts/drm.stp
>>>> Systemtap translator/driver (version 4.6/0.176, non-git sources)
>>>> [...]
>>
>> This is good, it contains the module-insertion fix PR28557.
>> The stap console trace looks okay.
>>
>>> For better insight I've used drm module drm_ioctl function
>>> instead. The problem persists, ie .return "locks nothing":
>>> #+begin_src systemtap
>>>   probe module("drm").function("drm_ioctl")
>>>   {
>>>     printf("-->. %s %s %s\n", thread_indent(0), ppfunc(), $$parms);
>>>   }
>>>       
>>>   probe module("drm").function("drm_ioctl").return
>>>   {
>>>     printf("<--\n");
>>>   }
>>
>> Would you consider rerunning a bit more pass-5 runtime side
>> tracing such as
>>
>> % sudo stap -DDEBUG_KPROBES -DDEBUG_SYMBOLS [...]
>>
>>
>> - FChE
>
> Hi Frank,
> thank You for response.
>
> here's the output:
> #+begin_src bash
>   prompt$ sudo /opt/systemtap-4.6/bin/stap -vv -DDEBUG_KPROBES -DDEBUG_SYMBOLS ~/user/scripts/drm.stp
>   Systemtap translator/driver (version 4.6/0.176, non-git sources)
>   Copyright (C) 2005-2021 Red Hat, Inc. and others
>   This is free software; see the source for copying conditions.
>   tested kernel versions: 2.6.32 ... 5.15.0-rc7
>   enabled features: BPF PYTHON3 LIBVIRT LIBXML2 NLS
>   Created temporary directory "/tmp/staprnTrv2"
>   Session arch: x86_64 release: 5.13.0-22-generic
>   Build tree: "/lib/modules/5.13.0-22-generic/build"
>   Kernel symbol table /lib/modules/5.13.0-22-generic/build/System.map unavailable, (No such file or directory)
>   Searched for library macro files: "/opt/systemtap-4.6/share/systemtap/tapset/linux", found: 7, processed: 7
>   Searched for library macro files: "/opt/systemtap-4.6/share/systemtap/tapset", found: 11, processed: 11
>   Searched: "/opt/systemtap-4.6/share/systemtap/tapset/linux/x86_64", found: 20, processed: 20
>   Searched: "/opt/systemtap-4.6/share/systemtap/tapset/linux", found: 407, processed: 407
>   Searched: "/opt/systemtap-4.6/share/systemtap/tapset/x86_64", found: 1, processed: 1
>   Searched: "/opt/systemtap-4.6/share/systemtap/tapset", found: 34, processed: 34
>   Pass 1: parsed user script and 480 library scripts using 121164virt/100540res/6252shr/94384data kb, in 100usr/20sys/115real ms.
>   derive-probes (location #0): module("drm").function("drm_ioctl") of keyword at /home/gmm/user/scripts/drm.stp:16:1
>   probe drm_ioctl@/build/linux-hwe-5.13-ADyN9x/linux-hwe-5.13-5.13.0/drivers/gpu/drm/drm_ioctl.c:811 module=drm reloc=.text pc=0x143b0
>   derive-probes (location #0): module("drm").function("drm_ioctl").return of keyword at /home/gmm/user/scripts/drm.stp:21:1
>   probe drm_ioctl@/build/linux-hwe-5.13-ADyN9x/linux-hwe-5.13-5.13.0/drivers/gpu/drm/drm_ioctl.c:811 module=drm reloc=.text pc=0x143b0
>   Pass 2: analyzed script: 2 probes, 12 functions, 1 embed, 2 globals using 124932virt/105328res/7236shr/98152data kb, in 130usr/0sys/135real ms.
>   function recursion-analysis: max-nesting 4  non-recursive
>   probe 0 ('module("drm").function("drm_ioctl@/build/linux-hwe-5.13-ADyN9x/linux-hwe-5.13-5.13.0/drivers/gpu/drm/drm_ioctl.c:811")') locks __private__opt_systemtap_4_6_share_systemtap_tapset_indent_stp__indent_counters[rw] __private__opt_systemtap_4_6_share_systemtap_tapset_indent_stp__indent_timestamps[rw]
>   5 statements for probe probe_6335
>   probe 1 ('module("drm").function("drm_ioctl@/build/linux-hwe-5.13-ADyN9x/linux-hwe-5.13-5.13.0/drivers/gpu/drm/drm_ioctl.c:811").return') locks nothing
>   1 statements for probe probe_6337
>   dump_unwindsyms drm index=0 base=0x10000
>   Found build-id in drm, length 20, start at 0x10
>   Pass 3: translated to C into "/tmp/staprnTrv2/stap_33df05986440b0b57b4062d608cf18eb_4656_src.c" using 124932virt/105456res/7364shr/98152data kb, in 120usr/10sys/121real ms.
>   Pass 4: using cached /root/.systemtap/cache/14/stapconf_14af95633f25eea4f38d1eb6ef710bb1_799.h
>   Running env -uARCH -uKBUILD_EXTMOD -uCROSS_COMPILE -uKBUILD_IMAGE -uKCONFIG_CONFIG -uINSTALL_PATH -uLD_LIBRARY_PATH PATH=/usr/bin:/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/snap/bin make -C /lib/modules/5.13.0-22-generic/build M=/tmp/staprnTrv2 modules CONFIG_DEBUG_INFO= CONFIG_DEBUG_INFO_BTF_MODULES= ARCH=x86_64 --no-print-directory -j21
>     CC [M]  /tmp/staprnTrv2/stap_33df05986440b0b57b4062d608cf18eb_4656_src.o
>     CC [M]  /tmp/staprnTrv2/stap_33df05986440b0b57b4062d608cf18eb_4656_aux_0.o
>     CC [M]  /tmp/staprnTrv2/stap_symbols.o
>     LD [M]  /tmp/staprnTrv2/stap_33df05986440b0b57b4062d608cf18eb_4656.o
>     MODPOST /tmp/staprnTrv2/Module.symvers
>     CC [M]  /tmp/staprnTrv2/stap_33df05986440b0b57b4062d608cf18eb_4656.mod.o
>     LD [M]  /tmp/staprnTrv2/stap_33df05986440b0b57b4062d608cf18eb_4656.ko
>   Spawn waitpid result (0x0): 0
>   Pass 4: compiled C into "stap_33df05986440b0b57b4062d608cf18eb_4656.ko" in 1400usr/360sys/1637real ms.
>   Cleaning cache, interval reached 61190 s > 300 s.
>   Copying /tmp/staprnTrv2/stap_33df05986440b0b57b4062d608cf18eb_4656.ko to /root/.systemtap/cache/33/stap_33df05986440b0b57b4062d608cf18eb_4656.ko
>   Copying /tmp/staprnTrv2/stap_33df05986440b0b57b4062d608cf18eb_4656_src.c to /root/.systemtap/cache/33/stap_33df05986440b0b57b4062d608cf18eb_4656.c
>   Copying /tmp/staprnTrv2/stapconf_14af95633f25eea4f38d1eb6ef710bb1_799.h to /root/.systemtap/cache/14/stapconf_14af95633f25eea4f38d1eb6ef710bb1_799.h
>   Pass 5: starting run.
>   Running /opt/systemtap-4.6/bin/staprun -v -R /tmp/staprnTrv2/stap_33df05986440b0b57b4062d608cf18eb_4656.ko
>   staprun:insert_module:191 Module stap_33df05986440b0b57b4062d608cf18e_10362 inserted from file /tmp/staprnTrv2/stap_33df05986440b0b57b4062d608cf18eb_4656.ko
>   _stp_set_stext:44: found kernel _stext load address: 0xffffffff8bc00000
>   _stp_kmodule_update_address:1115: module drm section .altinstr_aux address 0xffffffffc05684e2
>   _stp_kmodule_update_address:1115: module drm section .altinstr_replacement address 0xffffffffc0568075
>   _stp_kmodule_update_address:1115: module drm section .altinstructions address 0xffffffffc057cb54
>   _stp_kmodule_update_address:1115: module drm section .bss address 0xffffffffc0588d80
>   _stp_kmodule_update_address:1115: module drm section .data address 0xffffffffc0587000
>   _stp_kmodule_update_address:1115: module drm section .data..read_mostly address 0xffffffffc05886f4
>   _stp_kmodule_update_address:1115: module drm section .data.once address 0xffffffffc05886ec
>   _stp_kmodule_update_address:1115: module drm section .gnu.linkonce.this_module address 0xffffffffc0588a00
>   _stp_kmodule_update_address:1115: module drm section .init.text address 0x0
>   _stp_kmodule_update_address:1102: module drm special section .note.gnu.build-id address 0xffffffffc0569000
>   _stp_kmodule_update_address:1115: module drm section .parainstructions address 0xffffffffc057c608
>   _stp_kmodule_update_address:1115: module drm section .ref.data address 0xffffffffc0588780
>   _stp_kmodule_update_address:1115: module drm section .rodata address 0xffffffffc056b080
>   _stp_kmodule_update_address:1115: module drm section .rodata.str1.1 address 0xffffffffc057d760
>   _stp_kmodule_update_address:1115: module drm section .rodata.str1.8 address 0xffffffffc05801c0
>   _stp_kmodule_update_address:1115: module drm section .smp_locks address 0xffffffffc057c3ac
>   _stp_kmodule_update_address:1115: module drm section .static_call.text address 0xffffffffc0568518
>   _stp_kmodule_update_address:1115: module drm section .static_call_sites address 0xffffffffc05889e0
>   _stp_kmodule_update_address:1115: module drm section .text address 0xffffffffc0534000
>   _stp_kmodule_update_address:1115: module drm section .text.unlikely address 0xffffffffc0568191
>   _stp_kmodule_update_address:1115: module drm section ___srcu_struct_ptrs address 0xffffffffc05855b0
>   _stp_kmodule_update_address:1115: module drm section __bpf_raw_tp_map address 0xffffffffc0588700
>   _stp_kmodule_update_address:1115: module drm section __bug_table address 0xffffffffc0587ae0
>   _stp_kmodule_update_address:1115: module drm section __dyndbg address 0xffffffffc05889a8
>   _stp_kmodule_update_address:1115: module drm section __jump_table address 0xffffffffc0586000
>   _stp_kmodule_update_address:1115: module drm section __kcrctab address 0xffffffffc056a86c
>   _stp_kmodule_update_address:1115: module drm section __kcrctab_gpl address 0xffffffffc056aff0
>   _stp_kmodule_update_address:1115: module drm section __ksymtab address 0xffffffffc0569054
>   _stp_kmodule_update_address:1115: module drm section __ksymtab_gpl address 0xffffffffc056a6e0
>   _stp_kmodule_update_address:1115: module drm section __ksymtab_strings address 0xffffffffc0577430
>   _stp_kmodule_update_address:1115: module drm section __mcount_loc address 0xffffffffc057a6a4
>   _stp_kmodule_update_address:1115: module drm section __param address 0xffffffffc05855b8
>   _stp_kmodule_update_address:1115: module drm section __tracepoints address 0xffffffffc05888a0
>   _stp_kmodule_update_address:1115: module drm section __tracepoints_ptrs address 0xffffffffc0585680
>   _stp_kmodule_update_address:1115: module drm section __tracepoints_strings address 0xffffffffc0585690
>   _stp_kmodule_update_address:1115: module drm section _ftrace_events address 0xffffffffc0588760
>   _stp_module_check:775: build-id validation [drm]
>   _stp_build_id_check:731: build-id validation [drm] 4c8ebf4428e1562c2877a2be4c5f804cf306d2a3 vs. notes@=ffffffffc0569010 4c8ebf4428e1562c2877a2be4c5f804cf306d2a3
>   stapkp_init:756: looking up 2 probes
>   stapkp_init:770: found 2 probes
>   stapkp_register_probe:364: stapkp_register_probe module drm addr 0x4350 reg 0
>   stapkp_register_probe:364: stapkp_register_probe module drm addr 0x4350 reg 0
>   _stp_kmodule_relocate:38: drm, .text, 4350
>   _stp_kmodule_relocate:57: address=ffffffffc0538350
>   stapkp_arch_register_kprobe:230: +kprobe (null)+0
>   stapkp_register_kprobe:258: stapkp_register_kprobe module drm addr 0x4350 rc 0
>   -->.      0 myapp-test(10402): drm_ioctl filp=0xffff994332d2f200 cmd=0xc0406400 arg=0x19cf740
>   -->.      0 myapp-test(10402): drm_ioctl filp=0xffff994332d2f200 cmd=0xc0406400 arg=0x19cf740
>   -->.      0 myapp-test(10402): drm_ioctl filp=0xffff994332d2f200 cmd=0xc0106401 arg=0x7ffcb3a8ad10
>   -->.      0 myapp-test(10402): drm_ioctl filp=0xffff994332d2f200 cmd=0xc0106401 arg=0x7ffcb3a8ad10
>   -->.      0 myapp-test(10402): drm_ioctl filp=0xffff994332d2f200 cmd=0xc0086441 arg=0x19cf898
>   -->.      0 myapp-test(10402): drm_ioctl filp=0xffff994332d2f200 cmd=0xc0086441 arg=0x19cf818
>   -->.      0 myapp-test(10402): drm_ioctl filp=0xffff994332d2f200 cmd=0xc0086441 arg=0x19cf858
>   -->.      0 myapp-test(10402): drm_ioctl filp=0xffff994332d2f200 cmd=0xc0086441 arg=0x19cf7d8
>   -->.      0 myapp-test(10402): drm_ioctl filp=0xffff994332d2f500 cmd=0xc0406400 arg=0x19cd590
>   -->.      0 myapp-test(10402): drm_ioctl filp=0xffff994332d2f500 cmd=0xc0406400 arg=0x19cd590
>   -->.      0 myapp-test(10402): drm_ioctl filp=0xffff994332d2f500 cmd=0xc0106401 arg=0x7ffcb3a8ad10
>   -->.      0 myapp-test(10402): drm_ioctl filp=0xffff994332d2f500 cmd=0xc0106401 arg=0x7ffcb3a8ad10
>   -->.      0 myapp-test(10402): drm_ioctl filp=0xffff994332d2f500 cmd=0xc0086441 arg=0x19cf588
>     C-c C-cstapkp_batch_unregister_probes:514: -kprobe * 1
>   stapio:cleanup_and_exit:352 detach=0
>   stapio:cleanup_and_exit:369 closing control channel
>   staprun:remove_module:292 Module stap_33df05986440b0b57b4062d608cf18e_10362 removed.
>   Spawn waitpid result (0x0): 0
>   Pass 5: run completed in 20usr/90sys/50060real ms.
>   Running rm -rf /tmp/staprnTrv2
>   Spawn waitpid result (0x0): 0
>   Removed temporary directory "/tmp/staprnTrv2"
> #+end_src
>
> regards,
> Matt

hi systemtap team

any ideas?

regards,
Mat

  reply	other threads:[~2022-03-22  9:48 UTC|newest]

Thread overview: 7+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2021-12-15 20:51 Matt Vibrys
2021-12-16 17:38 ` Matt Vibrys
2021-12-17  2:33   ` Frank Ch. Eigler
2021-12-17 10:32     ` Matt Vibrys
2022-03-22  9:48       ` Matt Vibrys [this message]
2022-03-22 18:56         ` Frank Ch. Eigler
2022-04-06 12:37           ` Matt Vibrys

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to=umt4sfrawc6f.fsf@o2.pl \
    --to=vibrys@o2.pl \
    --cc=fche@redhat.com \
    --cc=systemtap@sourceware.org \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line before the message body.
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).