[lttng-dev] Problem LD_PRELOADing multiple UST helpers

Wed Oct 21 11:38:11 EDT 2015

Hi Christian,

The more debug output the merrier !

Could you attach the file generated (ld_debug.out.xxxx) by this command:

LD_PRELOAD="liblttng-ust-libc-wrapper.so liblttng-ust-cyg-profile.so 
liblttng-ust-pthread-wrapper.so liblttng-ust-dl.so" LD_DEBUG=all 
LD_DEBUG_OUTPUT=ld_debug.out ls

Also is the output provided in your previous email all of the debug 
output from 'ls' ?

Cheers!

On 2015-10-21 09:25 AM, Christian Ascheberg wrote:
> Hello,
>
> I am having a strange problem with LTTng UST helpers on a Cyclone V 
> ARM development board. If I LD_PRELOAD multiple helpers, then only 
> data of the first loaded helper appears in the trace.
> Below I have some debug output that looks wrong:
>
> This is the command:
> root at cyclone5:~# LTTNG_UST_DEBUG=1 
> LD_PRELOAD="liblttng-ust-libc-wrapper.so liblttng-ust-cyg-profile.so 
> liblttng-ust-pthread-wrapper.so liblttng-ust-dl.so" ls
>
> - This is some output regarding the first registration:
> liblttng_ust_tracepoint[XXX/XXX]: just registered a tracepoints 
> section from 0x76e7b42c and having 2 tracepoints (in 
> tracepoint_register_lib() at tracepoint.c:767)
> liblttng_ust_tracepoint[XXX/XXX]: registered tracepoint: 
> ust_baddr_statedump:soinfo (in tracepoint_register_lib() at 
> tracepoint.c:772)
> liblttng_ust_tracepoint[XXX/XXX]: registered tracepoint: 
> lttng_ust_tracef:event (in tracepoint_register_lib() at tracepoint.c:772)
> libust[XXX/XXX]: Provider "ust_baddr_statedump" accepted, version 1.0 
> is compatible with LTTng UST provider version 1.0. (in 
> check_provider_version() at lttng-probes.c:174)
> libust[XXX/XXX]: adding probe ust_baddr_statedump containing 1 events 
> to lazy registration list (in lttng_probe_register() at 
> lttng-probes.c:216)
> libust[XXX/XXY]: just registered probe ust_baddr_statedump containing 
> 1 events (in lttng_lazy_probe_register() at lttng-probes.c:115)
> libust[XXX/XXY]: Sent register event notification for name 
> "ust_baddr_statedump:soinfo": ret_code 0, event_id 0
>  (in ustcomm_register_event() at lttng-ust-comm.c:1001)
> liblttng_ust_tracepoint[XXX/XXY]: Registering probe to tracepoint 
> ust_baddr_statedump:soinfo (in __tracepoint_probe_register() at 
> tracepoint.c:563)
> liblttng_ust_tracepoint[XXX/XXX]: Registering probe to tracepoint 
> lttng_ust_tracef:event (in __tracepoint_probe_register() at 
> tracepoint.c:563)
>
> - And here is some strange output regarding another registration:
> liblttng_ust_tracepoint[XXX/XXX]: just registered a tracepoints 
> section from 0x76e7b42c and having 2 tracepoints (in 
> tracepoint_register_lib() at tracepoint.c:767)
> liblttng_ust_tracepoint[XXX/XXX]: registered tracepoint: 
> ust_baddr_statedump:soinfo (in tracepoint_register_lib() at 
> tracepoint.c:772)
> liblttng_ust_tracepoint[XXX/XXX]: registered tracepoint: 
> lttng_ust_tracef:event (in tracepoint_register_lib() at tracepoint.c:772)
> libust[XXX/XXX]: Provider "ust_pthread" accepted, version 1.0 is 
> compatible with LTTng UST provider version 1.0. (in 
> check_provider_version() at lttng-probes.c:174)
> libust[XXX/XXX]: adding probe ust_pthread containing 4 events to lazy 
> registration list (in lttng_probe_register() at lttng-probes.c:216)
> libust[XXX/XXX]: just registered probe ust_pthread containing 4 events 
> (in lttng_lazy_probe_register() at lttng-probes.c:115)
> libust[XXX/XXX]: Sent register event notification for name 
> "ust_pthread:pthread_mutex_lock_req": ret_code 0, event_id 4
>  (in ustcomm_register_event() at lttng-ust-comm.c:1001)
> libust[XXX/XXX]: Sent register event notification for name 
> "ust_pthread:pthread_mutex_lock_acq": ret_code 0, event_id 5
>  (in ustcomm_register_event() at lttng-ust-comm.c:1001)
> libust[XXX/XXX]: Sent register event notification for name 
> "ust_pthread:pthread_mutex_trylock": ret_code 0, event_id 6
>  (in ustcomm_register_event() at lttng-ust-comm.c:1001)
> libust[XXX/XXX]: Sent register event notification for name 
> "ust_pthread:pthread_mutex_unlock": ret_code 0, event_id 7
>  (in ustcomm_register_event() at lttng-ust-comm.c:1001)
> liblttng_ust_tracepoint[XXX/XXX]: Registering probe to tracepoint 
> ust_pthread:pthread_mutex_unlock (in __tracepoint_probe_register() at 
> tracepoint.c:563)
> liblttng_ust_tracepoint[XXX/XXX]: Registering probe to tracepoint 
> ust_pthread:pthread_mutex_trylock (in __tracepoint_probe_register() at 
> tracepoint.c:563)
> liblttng_ust_tracepoint[XXX/XXX]: Registering probe to tracepoint 
> ust_pthread:pthread_mutex_lock_acq (in __tracepoint_probe_register() 
> at tracepoint.c:563)
> liblttng_ust_tracepoint[XXX/XXX]: Registering probe to tracepoint 
> ust_pthread:pthread_mutex_lock_req (in __tracepoint_probe_register() 
> at tracepoint.c:563)
>
> As with this one, the first three lines of all registrations are 
> always the same and do not match the following (in this case) 
> 'Provider "ust_pthread" accepted'.
> I subsequently only get tracepoint data from ust_baddr_statedump:soinfo.
>
> I followed these build instructions for my board using Yocto 1.7: 
> http://rocketboards.org/foswiki/view/Documentation/GSRD150CompilingLinux
> I also tried updating the recipes to use the latest version of LTTng. 
> The output above is from LTTng v2.6.2.
> I can provide more debug output if that helps. I do not see this 
> problem on my desktop computer.
>
> Can somebody confirm this problem?
>
> Thanks, Christian
>
> _______________________________________________
> lttng-dev mailing list
> lttng-dev at lists.lttng.org
> http://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev

-- 
Jonathan R. Julien
Efficios