Re: probe process.function on libc not working

[Laris Benkis <laris at tpn dot cc>]

On 04/01/2012 3:57 AM, Adrien Kunysz wrote:
> On Wed, Jan 04, 2012 at 12:22:53AM -0500, Laris Benkis wrote:
>> I tried probing libc again with the latest snapshot and still get the
>> same failure.  Any suggestions?  Thanks
>>
>> Laris
>>
>> [laris@zilonis bin]$ ./stap --ver
>> Systemtap translator/driver (version 1.7/0.152 non-git sources)
>> Copyright (C) 2005-2011 Red Hat, Inc. and others
>> This is free software; see the source for copying conditions.
>> enabled features: TR1_UNORDERED_MAP NLS
>> [laris@zilonis bin]$
>>
>> [laris@zilonis bin]$ sudo ./stap -e 'probe
>> process("/lib/libc-2.14.90.so").function("*").call
>> {println(probefunc()." ".$$parms$)}' -c 'ls -l'
>> __sigprocmask how=2 set={.__val=[...]} oset={.__val=[...]}
>> execvp file="ls" argv="ïïï"
>> __execvpe file="ls" argv="ïïï" envp="ïï)ïïiïï~ïïïïïïïïïïïïÙïÙïÙïïï     
>> ïïïïïïïïïïïïïï"
>> getenv name="PATH"
>> __strncmp_ia32 s1="TH=/sbin:/bin:/usr/sbin:/usr/bin" s2="TH" n=2
>> __execve file="/sbin/ls" argv="ïïï" envp="ïï)ïïiïï~ïïïïïïïïïïïïÙïÙïÙïïï
>> ïïïïïïïïïïïïïï"
>> __execve file="/bin/ls" argv="ïïï" envp="ïï)ïïiïï~ïïïïïïïïïïïïÙïÙïÙïïï 
>> ïïïïïïïïïïïïïï"
>> strstr_ifunc
>> __init_cpu_features
>> __new_getrlimit e=3 rlimits={.rlim_cur=134512692, .rlim_max=3219911679}
>> __sysconf name=30
>> __getpagesize
>> __libc_dl_error_tsd
>> Warning: child process exited with signal 11 (Segmentation fault)
> What does the backtrace, the EIP and the code around the EIP in that
> core look like?
I've attached the core file.  Here are the registers and backtrace.  Thanks
Laris

(gdb) info registers
eax            0xfffff000       -4096
ecx            0x2400   9216
edx            0x800000 8388608
ebx            0x44fdeff4       1157492724
esp            0xbf84c85c       0xbf84c85c
ebp            0x44e16000       0x44e16000
esi            0x8      8
edi            0x1      1
eip            0xbf850070       0xbf850070
eflags         0x10206  [ PF IF RF ]
cs             0x73     115
ss             0x7b     123
ds             0x7b     123
es             0x7b     123
fs             0x0      0
gs             0x33     51
(gdb) bt
#0  0xbf850070 in ?? ()
#1  0x0000000b in ?? ()
#2  0x44e16a54 in ?? ()
#3  0x44e0ee78 in ?? () from /lib/ld-2.14.90.so
Backtrace stopped: Not enough registers or memory available to unwind
further

>
>> WARNING: /home/laris/systemtap-1.7-19981/bin/staprun exited with status: 1
>> Pass 5: run failed.  Try again with another '--vp 00001' option.
>>
>>
>> On 22/12/2011 6:27 PM, Laris Benkis wrote:
>>> I'm having trouble tracing into libc. Here's the reader's digest version
>>> and stap-report. Attached is the -DDEBUG_UPROBES output. Any ideas where
>>> the problem lies? Thanks
>>>
>>> Laris
>>>
>>>
>>> stap -e 'probe process("/lib/libc-2.14.90.so").function("*").call
>>> {println(probefunc()." ".$$parms$)}' -c 'ls -l'
>>> Warning: child process exited with signal 11 (Segmentation fault)
>>> __sigprocmask how=2 set={.__val=[...]} oset={.__val=[...]}
>>> execvp file="ls" argv="hï!ïï!"
>>> __execvpe file="ls" argv="hï!ïï!" envp="cïïïvïïïïïïïïïïïïïïïËïïæ
>>> ïïïïïïïïïïïXïïïmïïïïïïïïïïïïïïïÉïïèïïïï ïïïïïï"ïïïVïïïyïïïïïïïïïïïÎïï"
>>> getenv name="PATH"
>>> __strncmp_ia32 s1="TH=/usr/local/bin:/bin:/usr/bin" s2="TH" n=2
>>> __execve file="/usr/local/bin/ls" argv="hï!ïï!"
>>> envp="cïïïvïïïïïïïïïïïïïïïËïïæïïïïïïXïïïmïïïïïïïïïïïïïïïÉïïèïïïï
>>> ïïïïïï"ïïïVïïïyïïïïïïïïïïïÎïï"
>>> __execve file="/bin/ls" argv="hï!ïï!" envp="cïïïvïïïïïïïïïïïïïïïËïïæ
>>> ïïïïïïïïïïïXïïïmïïïïïïïïïïïïïïïÉïïè ïïïï ïïïïïï"ïïïVïïïyïïïïïïïïïïïÎïï"
>>> strstr_ifunc
>>> __init_cpu_features
>>> __new_getrlimit e=3 rlimits={.rlim_cur=134512692, .rlim_max=3219911679}
>>> __sysconf name=30
>>> __getpagesize
>>> __libc_dl_error_tsd
>>> Warning: /usr/bin/staprun exited with status: 1
>>> Pass 5: run failed. Try again with another '--vp 00001' option.
>>>
>>>
>>> [laris@zilonis ~]$ cat stap-report.txt
>>> == stap -V ==
>>> Systemtap translator/driver (version 1.6/0.152 non-git sources)
>>> Copyright (C) 2005-2011 Red Hat, Inc. and others
>>> This is free software; see the source for copying conditions.
>>> enabled features: AVAHI LIBRPM LIBSQLITE3 NSS BOOST_SHARED_PTR
>>> TR1_UNORDERED_MAP NLS
>>> == which stap ==
>>> /usr/bin/stap
>>> == locate --regex '/stap(run)?$' | xargs ls -ald ==
>>> drwxrwxr-x. 2 laris laris 4096 Dec 19 00:13 /home/laris/stap
>>> -rwxr-xr-x. 1 root root 1920576 Jul 25 19:24 /usr/bin/stap
>>> ---s--x---. 1 root stapusr 145408 Jul 25 19:24 /usr/bin/staprun
>>> == printenv | egrep
>>> '^PATH=|^LD_LIBRARY_PATH=|^SYSTEMTAP_.*=|^XDG_DATA.*=' ==
>>> PATH=/usr/local/bin:/bin:/usr/bin
>>> == stap -vv -p4 -e 'probe begin {exit()}' ==
>>> Systemtap translator/driver (version 1.6/0.152 non-git sources)
>>> Copyright (C) 2005-2011 Red Hat, Inc. and others
>>> This is free software; see the source for copying conditions.
>>> enabled features: AVAHI LIBRPM LIBSQLITE3 NSS BOOST_SHARED_PTR
>>> TR1_UNORDERED_MAP NLS
>>> Created temporary directory "/tmp/stapkSniqm"
>>> Session arch: i386 release: 3.1.5-6.fc16.i686
>>> Searched: " /usr/share/systemtap/tapset/i386/*.stp ", found: 4, processed: 4
>>> Searched: " /usr/share/systemtap/tapset/*.stp ", found: 73, processed: 73
>>> Pass 1: parsed user script and 77 library script(s) using
>>> 25224virt/13832res/2544shr kb, in 230usr/10sys/242real ms.
>>> Pass 2: analyzed script: 1 probe(s), 1 function(s), 0 embed(s), 0
>>> global(s) using 25488virt/14096res/2576shr kb, in 10usr/0sys/6real ms.
>>> /root/.systemtap/cache/e6/stap_e64e86c5872c37ebad9b5294ecbcc322_635.ko
>>> Pass 3: using cached
>>> /root/.systemtap/cache/e6/stap_e64e86c5872c37ebad9b5294ecbcc322_635.c
>>> Pass 4: using cached
>>> /root/.systemtap/cache/e6/stap_e64e86c5872c37ebad9b5294ecbcc322_635.ko
>>> Running rm -rf /tmp/stapkSniqm
>>> Spawn waitpid result (0x0): 0
>>> == gcc -v ==
>>> Using built-in specs.
>>> COLLECT_GCC=gcc
>>> COLLECT_LTO_WRAPPER=/usr/libexec/gcc/i686-redhat-linux/4.6.2/lto-wrapper
>>> Target: i686-redhat-linux
>>> Configured with: ../configure --prefix=/usr --mandir=/usr/share/man
>>> --infodir=/usr/share/info
>>> --with-bugurl=http://bugzilla.redhat.com/bugzilla --enable-bootstrap
>>> --enable-shared --enable-threads=posix --enable-checking=release
>>> --with-system-zlib --enable-__cxa_atexit --disable-libunwind-exceptions
>>> --enable-gnu-unique-object --enable-linker-build-id
>>> --enable-languages=c,c++,objc,obj-c++,java,fortran,ada,go,lto
>>> --enable-plugin --enable-java-awt=gtk --disable-dssi
>>> --with-java-home=/usr/lib/jvm/java-1.5.0-gcj-1.5.0.0/jre
>>> --enable-libgcj-multifile --enable-java-maintainer-mode
>>> --with-ecj-jar=/usr/share/java/eclipse-ecj.jar
>>> --disable-libjava-multilib --with-ppl --with-cloog --with-tune=generic
>>> --with-arch=i686 --build=i686-redhat-linux
>>> Thread model: posix
>>> gcc version 4.6.2 20111027 (Red Hat 4.6.2-1) (GCC)
>>> == uname -a ==
>>> Linux zilonis.tpn.cc 3.1.5-6.fc16.i686 #1 SMP Thu Dec 15 16:26:31 UTC
>>> 2011 i686 i686 i386 GNU/Linux
>>> == dmesg | egrep 'stap|systemtap' | tail -n 10 ==
>>> [349734.047152] stap_f00a6908ee1cf38c730f35e4569a3012_20037: systemtap:
>>> 1.6/0.152, base: fbf05000, memory: 104data/42text/1ctx/10net/18alloc kb,
>>> probes: 39
>>> [349761.966717] stap_8a7ca24af256d26b2a544c59cd3590f_20261: systemtap:
>>> 1.6/0.152, base: fc195000, memory: 100data/24text/2ctx/10net/19alloc kb,
>>> probes: 39
>>> [349787.431056] stap_a89fd8b79597df06e2aed3bbbbb8a308_20489: systemtap:
>>> 1.6/0.152, base: fc443000, memory: 105data/47text/3ctx/10net/20alloc kb,
>>> probes: 39
>>> [349815.645926] stap_6197efb33bfc2032bb21e6c46a3fd5e3_20715: systemtap:
>>> 1.6/0.152, base: fc72c000, memory: 107data/73text/42ctx/10net/59alloc
>>> kb, probes: 39
>>> [349832.533574] stap_a89fd8b79597df06e2aed3bbbbb8a308_20724: systemtap:
>>> 1.6/0.152, base: fc9e8000, memory: 105data/47text/3ctx/10net/20alloc kb,
>>> probes: 39
>>> [349836.930973] stap_6197efb33bfc2032bb21e6c46a3fd5e3_20733: systemtap:
>>> 1.6/0.152, base: fccd1000, memory: 107data/73text/42ctx/10net/59alloc
>>> kb, probes: 39
>>> [349900.457026] stap_6197efb33bfc2032bb21e6c46a3fd5e3_20742: systemtap:
>>> 1.6/0.152, base: fcfc1000, memory: 107data/73text/42ctx/10net/59alloc
>>> kb, probes: 39
>>> [350400.204798] stap_331043668b61ef0f698e2b8ea4e4c62b_1_21761:
>>> systemtap: 1.6/0.152, base: fd472000, memory:
>>> 1482data/24text/2ctx/10net/19alloc kb, probes: 4964
>>> [350418.223413] stap_331043668b61ef0f698e2b8ea4e4c62b_1_21999:
>>> systemtap: 1.6/0.152, base: f9666000, memory:
>>> 1482data/24text/2ctx/10net/19alloc kb, probes: 4964
>>> [353883.302456] stap_258a75f82f7dd5d0c2303a96a3e47fda_2_22494:
>>> systemtap: 1.6/0.152, base: fa4bb000, memory:
>>> 1349data/1582text/46ctx/10net/63alloc kb, probes: 2628
>>> == cat /proc/cpuinfo | egrep 'processor|vendor_id|model name' ==
>>> processor : 0
>>> vendor_id : GenuineIntel
>>> model name : Intel(R) Pentium(R) D CPU 3.20GHz
>>> processor : 1
>>> vendor_id : GenuineIntel
>>> model name : Intel(R) Pentium(R) D CPU 3.20GHz
>>> == rpm -qa --qf '%{name}-%{version} %{release}.%{arch}\n' | egrep
>>> 'systemtap|elfutils|kernel|gcc' | sort ==
>>> abrt-addon-kerneloops-2.0.7 2.fc16.i686
>>> elfutils-0.152 1.fc16.i686
>>> elfutils-libelf-0.152 1.fc16.i686
>>> elfutils-libs-0.152 1.fc16.i686
>>> gcc-4.6.2 1.fc16.i686
>>> gcc-c++-4.6.2 1.fc16.i686
>>> kernel-3.1.0 7.fc16.i686
>>> kernel-3.1.5 6.fc16.i686
>>> kernel-debuginfo-3.1.5 6.fc16.i686
>>> kernel-debuginfo-common-i686-3.1.5 6.fc16.i686
>>> kernel-devel-3.1.5 6.fc16.i686
>>> kernel-headers-3.1.5 6.fc16.i686
>>> libgcc-4.6.2 1.fc16.i686
>>> libreport-plugin-kerneloops-2.0.8 3.fc16.i686
>>> systemtap-1.6 1.fc16.i686
>>> systemtap-runtime-1.6 1.fc16.i686
>>> systemtap-sdt-devel-1.6 1.fc16.i686
>>> == egrep 'PROBE|TRACE|MARKER|_DEBUG_'
>>> /lib/modules/3.1.5-6.fc16.i686/build/.config | grep -v not.set | sort |
>>> fmt -w 80 ==
>>> CONFIG_AIC79XX_DEBUG_MASK=0 CONFIG_AIC7XXX_DEBUG_MASK=0
>>> CONFIG_ARCH_CPU_PROBE_RELEASE=y CONFIG_ARCH_SUPPORTS_DEBUG_PAGEALLOC=y
>>> CONFIG_BLK_DEV_IO_TRACE=y CONFIG_CAN_PM_TRACE=y
>>> CONFIG_CB710_DEBUG_ASSUMPTIONS=y CONFIG_CONTEXT_SWITCH_TRACER=y
>>> CONFIG_DEBUG_BOOT_PARAMS=y CONFIG_DEBUG_BUGVERBOSE=y CONFIG_DEBUG_DEVRES=y
>>> CONFIG_DEBUG_FS=y CONFIG_DEBUG_HIGHMEM=y CONFIG_DEBUG_INFO=y
>>> CONFIG_DEBUG_KERNEL=y CONFIG_DEBUG_LIST=y CONFIG_DEBUG_MEMORY_INIT=y
>>> CONFIG_DEBUG_NX_TEST=m CONFIG_DEBUG_RODATA_TEST=y CONFIG_DEBUG_RODATA=y
>>> CONFIG_DEBUG_SHIRQ=y CONFIG_DEBUG_STACKOVERFLOW=y CONFIG_DYNAMIC_FTRACE=y
>>> CONFIG_FTRACE_MCOUNT_RECORD=y CONFIG_FTRACE_NMI_ENTER=y
>>> CONFIG_FTRACE_SYSCALLS=y CONFIG_FTRACE=y CONFIG_FUNCTION_TRACER=y
>>> CONFIG_GENERIC_IRQ_PROBE=y CONFIG_GENERIC_TRACER=y
>>> CONFIG_HAVE_ARCH_TRACEHOOK=y CONFIG_HAVE_DYNAMIC_FTRACE=y
>>> CONFIG_HAVE_FTRACE_MCOUNT_RECORD=y CONFIG_HAVE_FTRACE_NMI_ENTER=y
>>> CONFIG_HAVE_FUNCTION_GRAPH_TRACER=y CONFIG_HAVE_FUNCTION_TRACE_MCOUNT_TEST=y
>>> CONFIG_HAVE_FUNCTION_TRACER=y CONFIG_HAVE_KPROBES=y CONFIG_HAVE_KRETPROBES=y
>>> CONFIG_HAVE_MMIOTRACE_SUPPORT=y CONFIG_HAVE_OPTPROBES=y
>>> CONFIG_HAVE_SYSCALL_TRACEPOINTS=y CONFIG_INFINIBAND_IPOIB_DEBUG_DATA=y
>>> CONFIG_KEYS_DEBUG_PROC_KEYS=y CONFIG_KPROBE_EVENT=y CONFIG_KPROBES=y
>>> CONFIG_KRETPROBES=y CONFIG_MTD_GEN_PROBE=m CONFIG_MTD_JEDECPROBE=m
>>> CONFIG_MTD_NAND_DISKONCHIP_PROBE_ADDRESS=0 CONFIG_MTD_QINFO_PROBE=m
>>> CONFIG_NET_DCCPPROBE=m CONFIG_NETFILTER_XT_TARGET_TRACE=m
>>> CONFIG_NET_SCTPPROBE=m CONFIG_NOP_TRACER=y CONFIG_OPTPROBES=y
>>> CONFIG_PCMCIA_PROBE=y CONFIG_PM_TRACE_RTC=y CONFIG_PM_TRACE=y
>>> CONFIG_SCHED_TRACER=y CONFIG_STACK_TRACER=y CONFIG_STACKTRACE_SUPPORT=y
>>> CONFIG_STACKTRACE=y CONFIG_TRACE_IRQFLAGS_SUPPORT=y CONFIG_TRACEPOINTS=y
>>> CONFIG_TRACER_MAX_TRACE=y CONFIG_USER_STACKTRACE_SUPPORT=y CONFIG_UTRACE=y
>>> CONFIG_WIMAX_DEBUG_LEVEL=8 CONFIG_WIMAX_I2400M_DEBUG_LEVEL=8
>>> == find /debugfs /proc /sys /dev -name '*kprobes*' 2>/dev/null | xargs
>>> grep . ==
>>> /proc/sys/debug/kprobes-optimization:1
>>>
>>>
>>>
>>>
>>>

Attachment: core.29098
Description: Binary data