Other tracing shared library functions using DTrace

niekgigashvili

niekgigashvili

Hi,

I'm working with DTrace to track function calls within shared libraries. Typically, this is straightforward. For example, let's say I have a binary named "foo" and
a library named "libbar.so." when I run "foo," I can trace every function call made inside "libbar.so."

However, shared libraries also have constructor where essential data structures are initialized. I'd like to trace function calls specifically starting from
the constructor, but I haven't been able to achieve this. Is it possible to use DTrace to track function calls from this point?
 
Interesting problem, I was not able to find a solution for it. I'm assuming it's possible as it's possible to do this (debug constructors in libs loaded in future) with gdb.
I attempted to use dtrace -x evaltime=preinit -s trace -c ./test but it didn't match any probes this way (opposed to not specifying evaltime).

What is a bit frustrating I can match those probes ( mysetup() being a constructor function in mylib.so )
Code: 
dtrace -ln 'pid$target:mylib.so::entry' -c ./test
   ID   PROVIDER            MODULE                          FUNCTION NAME
89779    pid1926          mylib.so             __do_global_dtors_aux entry
89780    pid1926          mylib.so                  register_classes entry
89781    pid1926          mylib.so             __do_global_ctors_aux entry
89782    pid1926          mylib.so                           mysetup entry
89783    pid1926          mylib.so                             leave entry
89784    pid1926          mylib.so                             hello entry
 
So I have been trying to trace jemalloc shared library version 5.2.0 separately built. When I read DTrace docs it seemed obvious that using
evaltime option would effect when tracing will start so I tried all the options exec, preinit, postinit and main but without luck.
I wasn't able capture call to constructor "jemalloc_constructor" using DTrace. So I am curious if it is possible to achieve what I want at all.

sh: 
> sudo dtrace -x evaltime=exec -Fn 'pid$target:libjemalloc*::entry {} pid$target:libjemalloc*::return {}' -c 'bin/simple_malloc/5.2.0/simple_malloc'
dtrace: invalid probe specifier pid$target:libjemalloc*::entry {} pid$target:libjemalloc*::return {}: probe description pid75354:libjemalloc*::entry does not match any probes

> sudo dtrace -x evaltime=exec -Fn 'pid$target:::entry {} pid$target:::return {}' -c 'bin/simple_malloc/5.2.0/simple_malloc'
dtrace: description 'pid$target:::entry ' matched 57 probes
dtrace: pid 78584 has exited
CPU FUNCTION                                
  4  -> _rtld_thread_init                    
  4  <- _rtld_thread_init                    
  4  -> r_debug_state                        
  4  <- r_debug_state                        
  4  -> dlsym                                
  4  <- dlsym                                
  4  -> _rtld_is_dlopened                    
  4    -> _rtld_error                        
  4    <- _rtld_error                        
  4  <- _rtld_is_dlopened                    
  4  -> _rtld_get_stack_prot                 
  4  <- _rtld_get_stack_prot                 
  4  -> _rtld_atfork_pre                     
  4  <- _rtld_atfork_pre                     
  4  -> _rtld_atfork_post                    
  4  <- _rtld_atfork_post                    
  4  -> _rtld_thread_init                    
  4  <- _rtld_thread_init                    
  4  -> __do_global_ctors_aux                
  4  <- __do_global_ctors_aux                
  4  -> register_classes                     
  4  <- register_classes                     
  4  -> _r_debug_postinit                    
  4  <- _r_debug_postinit                    
  4  -> _start                               
  4    -> main                               
  4      -> simple_malloc                    
  4      <- simple_malloc                    
  4    <- main                               
  4    -> __do_global_dtors_aux              
  4    <- __do_global_dtors_aux              
  4    -> _rtld_addr_phdr                    
  4    <- _rtld_addr_phdr                    
  4    -> _rtld_addr_phdr                    
  4    <- _rtld_addr_phdr                    
  4    -> _rtld_addr_phdr                    
  4    <- _rtld_addr_phdr                    
  4    -> _rtld_addr_phdr                    
  4    <- _rtld_addr_phdr                    
  4    -> _rtld_addr_phdr                    
  4    <- _rtld_addr_phdr                    
  4    -> _rtld_addr_phdr                    
  4    <- _rtld_addr_phdr                    
  4    -> _rtld_addr_phdr                    
  4    <- _rtld_addr_phdr                    
  4    -> _rtld_addr_phdr                    
  4    <- _rtld_addr_phdr

with preinit I am not able to trace anything at all
sh: 
sudo dtrace -x evaltime=preinit -Fn 'pid$target:libjemalloc*::entry {} pid$target:libjemalloc*::return {}' -c 'bin/simple_malloc/5.2.0/simple_malloc'
dtrace: failed to control pid 75747: process exited with status 0

> sudo dtrace -x evaltime=preinit -Fn 'pid$target:::entry {} pid$target:::return {}' -c 'bin/simple_malloc/5.2.0/simple_malloc'
dtrace: failed to control pid 78270: process exited with status 0

this time I am able to trace all function calls made within libjemalloc.so but after call to malloc()
sh: 
> sudo dtrace -x evaltime=postinit -Fn 'pid$target:libjemalloc*::entry {} pid$target:libjemalloc*::return {}' -c 'bin/simple_malloc/5.2.0/simple_malloc'
dtrace: description 'pid$target:libjemalloc*::entry ' matched 2957 probes
dtrace: pid 76065 has exited
CPU FUNCTION                              
  7  -> malloc                            
  7    -> tsd_get_allocates                
  7    <- tsd_get_allocates                
  7    -> tsd_get                          
  7    <- tsd_get                          
  7    -> tsd_fast                        
  7      -> tsd_state_get                  
  7      <- tsd_state_get                  
  7    <- tsd_fast                        
  7    -> je_malloc_default                
  7      -> static_opts_init              
  7      <- static_opts_init              
  7      -> dynamic_opts_init              
  7      <- dynamic_opts_init              
  7      -> imalloc
  . . .
 
Last edited:
I'd probably opt for gdb then but I'm not sure what specifically are you trying to achieve/profile/debug.

I tried the same program under Solaris and there it works as expected:
Code: 
# dtrace -s ./trace -c ./test
dtrace: script './trace' matched 3 probes
*** mysetup exec
hello: my hello program

return value: 666
dtrace: pid 1654 has exited
 CPU     ID                    FUNCTION:NAME
   3 101871                    mysetup:entry mysetup
   3 101873                      hello:entry hello
   3 101872                      leave:entry leave
Where trace is just catching pid$target:mylib.so::entry.
 
Yes gdb is an option of course. If it works on Solaris it means DTrace doesn't work on FreeBSD as expected and it could be a bug
or there is some system setting not set. thank you anyway
 
I was able to minimize this to a simple test case:
Code: 
#include <stdio.h>

void __attribute__((constructor)) myinit() {
    printf("%s: hello\n", __func__);
}

int main() {
    return 42;
}
FreeBSD's dtrace probe is not matching this function even though it's listing it. I've opened PR 278489 for it.
 
You must log in or register to reply here.
Back
Top