The requested output that was generated by the stated command is in
http://pastebin.com/zxuFQ8yV (part 1) and http://pastebin.com/GgR8d3pV
(part 2).
The full LTTng debug output, split by executed commands, is in
http://pastebin.com/NsCxaYGT
As I tried to say before, note that these three lines are occuring for
every registration, but they should occur only once:
liblttng_ust_tracepoint[313/313]: just registered a tracepoints section
from 0x76e7b42c and having 2 tracepoints (in tracepoint_register_lib()
at tracepoint.c:767)
liblttng_ust_tracepoint[313/313]: registered tracepoint:
ust_baddr_statedump:soinfo (in tracepoint_register_lib() at
tracepoint.c:772)
liblttng_ust_tracepoint[313/313]: registered tracepoint:
lttng_ust_tracef:event (in tracepoint_register_lib() at tracepoint.c:772)
Corresponding lines for other tracepoint providers are missing instead.
This is the full UST part of the debug output. Part of that is what I
had posted before.
root@cyclone5:~# LD_PRELOAD="liblttng-ust-libc-wrapper.so
liblttng-ust-cyg-profile.so liblttng-ust-pthread-wrapper.so
liblttng-ust-dl.so" ls
liblttng_ust_tracepoint[313/313]: just registered a tracepoints section
from 0x76e7b42c and having 2 tracepoints (in tracepoint_register_lib()
at tracepoint.c:767)
liblttng_ust_tracepoint[313/313]: registered tracepoint:
ust_baddr_statedump:soinfo (in tracepoint_register_lib() at
tracepoint.c:772)
liblttng_ust_tracepoint[313/313]: registered tracepoint:
lttng_ust_tracef:event (in tracepoint_register_lib() at tracepoint.c:772)
libust[313/313]: 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[313/313]: adding probe ust_baddr_statedump containing 1 events to
lazy registration list (in lttng_probe_register() at lttng-probes.c:216)
libust[313/313]: LTT : ltt ring buffer client "relay-metadata-mmap" init
(in lttng_ring_buffer_metadata_client_init() at
lttng-ring-buffer-metadata-client.h:330)
libust[313/313]: LTT : ltt ring buffer client "relay-overwrite-mmap" init
(in lttng_ring_buffer_client_overwrite_init() at
lttng-ring-buffer-client.h:681)
libust[313/313]: LTT : ltt ring buffer client "relay-overwrite-rt-mmap" init
(in lttng_ring_buffer_client_overwrite_rt_init() at
lttng-ring-buffer-client.h:681)
libust[313/313]: LTT : ltt ring buffer client "relay-discard-mmap" init
(in lttng_ring_buffer_client_discard_init() at
lttng-ring-buffer-client.h:681)
libust[313/313]: LTT : ltt ring buffer client "relay-discard-rt-mmap" init
(in lttng_ring_buffer_client_discard_rt_init() at
lttng-ring-buffer-client.h:681)
libust[313/315]: Info: sessiond not accepting connections to local apps
socket (in ust_listener_thread() at lttng-ust-comm.c:1224)
libust[313/315]: Waiting for local apps sessiond (in wait_for_sessiond()
at lttng-ust-comm.c:1135)
libust[313/314]: Message Received "Get Tracer Version" (65), Handle
"root" (0) (in print_cmd() at lttng-ust-comm.c:367)
libust[313/314]: Return value: 0 (in handle_message() at
lttng-ust-comm.c:827)
libust[313/314]: message successfully sent (in send_reply() at
lttng-ust-comm.c:484)
libust[313/314]: Message Received "Create Session" (64), Handle "root"
(0) (in print_cmd() at lttng-ust-comm.c:367)
libust[313/314]: Return value: 1 (in handle_message() at
lttng-ust-comm.c:827)
libust[313/314]: message successfully sent (in send_reply() at
lttng-ust-comm.c:484)
libust[313/314]: Message Received "Create Channel" (81), Handle
"session" (1) (in print_cmd() at lttng-ust-comm.c:367)
libust[313/314]: channel data received (in handle_message() at
lttng-ust-comm.c:723)
libust[313/314]: Return value: 2 (in handle_message() at
lttng-ust-comm.c:827)
libust[313/314]: message successfully sent (in send_reply() at
lttng-ust-comm.c:484)
libust[313/314]: Message Received "Create Stream" (96), Handle "channel"
(2) (in print_cmd() at lttng-ust-comm.c:367)
libust[313/314]: Return value: 0 (in handle_message() at
lttng-ust-comm.c:827)
libust[313/314]: message successfully sent (in send_reply() at
lttng-ust-comm.c:484)
libust[313/314]: Message Received "Create Stream" (96), Handle "channel"
(2) (in print_cmd() at lttng-ust-comm.c:367)
libust[313/314]: Return value: 0 (in handle_message() at
lttng-ust-comm.c:827)
libust[313/314]: message successfully sent (in send_reply() at
lttng-ust-comm.c:484)
libust[313/314]: Message Received "Create Context" (112), Handle
"channel" (2) (in print_cmd() at lttng-ust-comm.c:367)
libust[313/314]: Return value: 0 (in handle_message() at
lttng-ust-comm.c:827)
libust[313/314]: message successfully sent (in send_reply() at
lttng-ust-comm.c:484)
libust[313/314]: Message Received "Create Context" (112), Handle
"channel" (2) (in print_cmd() at lttng-ust-comm.c:367)
libust[313/314]: Return value: 0 (in handle_message() at
lttng-ust-comm.c:827)
libust[313/314]: message successfully sent (in send_reply() at
lttng-ust-comm.c:484)
libust[313/314]: Message Received "Create Context" (112), Handle
"channel" (2) (in print_cmd() at lttng-ust-comm.c:367)
libust[313/314]: Return value: 0 (in handle_message() at
lttng-ust-comm.c:827)
libust[313/314]: message successfully sent (in send_reply() at
lttng-ust-comm.c:484)
libust[313/314]: Message Received "Create Context" (112), Handle
"channel" (2) (in print_cmd() at lttng-ust-comm.c:367)
libust[313/314]: Return value: 0 (in handle_message() at
lttng-ust-comm.c:827)
libust[313/314]: message successfully sent (in send_reply() at
lttng-ust-comm.c:484)
libust[313/314]: Message Received "Create Event" (97), Handle "channel"
(2) (in print_cmd() at lttng-ust-comm.c:367)
libust[313/314]: Return value: 3 (in handle_message() at
lttng-ust-comm.c:827)
libust[313/314]: message successfully sent (in send_reply() at
lttng-ust-comm.c:484)
libust[313/314]: Message Received "Enable" (128), Handle "enabler" (3)
(in print_cmd() at lttng-ust-comm.c:367)
libust[313/314]: Return value: 0 (in handle_message() at
lttng-ust-comm.c:827)
libust[313/314]: message successfully sent (in send_reply() at
lttng-ust-comm.c:484)
libust[313/314]: Message Received "Enable" (128), Handle "session" (1)
(in print_cmd() at lttng-ust-comm.c:367)
libust[313/314]: Sent register channel notification: chan_id 0,
header_type 1
(in ustcomm_register_channel() at lttng-ust-comm.c:1108)
libust[313/314]: just registered probe ust_baddr_statedump containing 1
events (in lttng_lazy_probe_register() at lttng-probes.c:115)
libust[313/314]: 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[313/314]: Registering probe to tracepoint
ust_baddr_statedump:soinfo (in __tracepoint_probe_register() at
tracepoint.c:563)
libust[313/314]: Return value: 0 (in handle_message() at
lttng-ust-comm.c:827)
libust[313/314]: message successfully sent (in send_reply() at
lttng-ust-comm.c:484)
libust[313/314]: Message Received "Wait for Quiescent State" (67),
Handle "root" (0) (in print_cmd() at lttng-ust-comm.c:367)
libust[313/314]: Return value: 0 (in handle_message() at
lttng-ust-comm.c:827)
libust[313/314]: message successfully sent (in send_reply() at
lttng-ust-comm.c:484)
libust[313/314]: Message Received "Registration Done" (68), Handle
"root" (0) (in print_cmd() at lttng-ust-comm.c:367)
libust[313/314]: Return value: 0 (in handle_message() at
lttng-ust-comm.c:827)
libust[313/314]: message successfully sent (in send_reply() at
lttng-ust-comm.c:484)
libust[313/313]: adding probe lttng_ust_tracef containing 1 events to
lazy registration list (in lttng_probe_register() at lttng-probes.c:216)
libust[313/313]: just registered probe lttng_ust_tracef containing 1
events (in lttng_lazy_probe_register() at lttng-probes.c:115)
libust[313/313]: Sent register event notification for name
"lttng_ust_tracef:event": ret_code 0, event_id 1
(in ustcomm_register_event() at lttng-ust-comm.c:1001)
liblttng_ust_tracepoint[313/313]: Registering probe to tracepoint
lttng_ust_tracef:event (in __tracepoint_probe_register() at
tracepoint.c:563)
liblttng_ust_tracepoint[313/313]: just registered a tracepoints section
from 0x76e7b42c and having 2 tracepoints (in tracepoint_register_lib()
at tracepoint.c:767)
liblttng_ust_tracepoint[313/313]: registered tracepoint:
ust_baddr_statedump:soinfo (in tracepoint_register_lib() at
tracepoint.c:772)
liblttng_ust_tracepoint[313/313]: registered tracepoint:
lttng_ust_tracef:event (in tracepoint_register_lib() at tracepoint.c:772)
libust[313/313]: Provider "ust_baddr" accepted, version 1.0 is
compatible with LTTng UST provider version 1.0. (in
check_provider_version() at lttng-probes.c:174)
libust[313/313]: adding probe ust_baddr containing 2 events to lazy
registration list (in lttng_probe_register() at lttng-probes.c:216)
libust[313/313]: just registered probe ust_baddr containing 2 events (in
lttng_lazy_probe_register() at lttng-probes.c:115)
libust[313/313]: Sent register event notification for name
"ust_baddr:push": ret_code 0, event_id 2
(in ustcomm_register_event() at lttng-ust-comm.c:1001)
libust[313/313]: Sent register event notification for name
"ust_baddr:pop": ret_code 0, event_id 3
(in ustcomm_register_event() at lttng-ust-comm.c:1001)
liblttng_ust_tracepoint[313/313]: Registering probe to tracepoint
ust_baddr:pop (in __tracepoint_probe_register() at tracepoint.c:563)
liblttng_ust_tracepoint[313/313]: Registering probe to tracepoint
ust_baddr:push (in __tracepoint_probe_register() at tracepoint.c:563)
liblttng_ust_tracepoint[313/313]: just registered a tracepoints section
from 0x76e7b42c and having 2 tracepoints (in tracepoint_register_lib()
at tracepoint.c:767)
liblttng_ust_tracepoint[313/313]: registered tracepoint:
ust_baddr_statedump:soinfo (in tracepoint_register_lib() at
tracepoint.c:772)
liblttng_ust_tracepoint[313/313]: registered tracepoint:
lttng_ust_tracef:event (in tracepoint_register_lib() at tracepoint.c:772)
libust[313/313]: 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[313/313]: adding probe ust_pthread containing 4 events to lazy
registration list (in lttng_probe_register() at lttng-probes.c:216)
libust[313/313]: just registered probe ust_pthread containing 4 events
(in lttng_lazy_probe_register() at lttng-probes.c:115)
libust[313/313]: 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[313/313]: 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[313/313]: 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[313/313]: 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[313/313]: Registering probe to tracepoint
ust_pthread:pthread_mutex_unlock (in __tracepoint_probe_register() at
tracepoint.c:563)
liblttng_ust_tracepoint[313/313]: Registering probe to tracepoint
ust_pthread:pthread_mutex_trylock (in __tracepoint_probe_register() at
tracepoint.c:563)
liblttng_ust_tracepoint[313/313]: Registering probe to tracepoint
ust_pthread:pthread_mutex_lock_acq (in __tracepoint_probe_register() at
tracepoint.c:563)
liblttng_ust_tracepoint[313/313]: Registering probe to tracepoint
ust_pthread:pthread_mutex_lock_req (in __tracepoint_probe_register() at
tracepoint.c:563)
liblttng_ust_tracepoint[313/313]: just registered a tracepoints section
from 0x76e7b42c and having 2 tracepoints (in tracepoint_register_lib()
at tracepoint.c:767)
liblttng_ust_tracepoint[313/313]: registered tracepoint:
ust_baddr_statedump:soinfo (in tracepoint_register_lib() at
tracepoint.c:772)
liblttng_ust_tracepoint[313/313]: registered tracepoint:
lttng_ust_tracef:event (in tracepoint_register_lib() at tracepoint.c:772)
libust[313/313]: Provider "lttng_ust_cyg_profile" accepted, version 1.0
is compatible with LTTng UST provider version 1.0. (in
check_provider_version() at lttng-probes.c:174)
libust[313/313]: adding probe lttng_ust_cyg_profile containing 2 events
to lazy registration list (in lttng_probe_register() at lttng-probes.c:216)
libust[313/313]: just registered probe lttng_ust_cyg_profile containing
2 events (in lttng_lazy_probe_register() at lttng-probes.c:115)
libust[313/313]: Sent register event notification for name
"lttng_ust_cyg_profile:func_entry": ret_code 0, event_id 8
(in ustcomm_register_event() at lttng-ust-comm.c:1001)
libust[313/313]: Sent register event notification for name
"lttng_ust_cyg_profile:func_exit": ret_code 0, event_id 9
(in ustcomm_register_event() at lttng-ust-comm.c:1001)
liblttng_ust_tracepoint[313/313]: Registering probe to tracepoint
lttng_ust_cyg_profile:func_exit (in __tracepoint_probe_register() at
tracepoint.c:563)
liblttng_ust_tracepoint[313/313]: Registering probe to tracepoint
lttng_ust_cyg_profile:func_entry (in __tracepoint_probe_register() at
tracepoint.c:563)
liblttng_ust_tracepoint[313/313]: just registered a tracepoints section
from 0x76e7b42c and having 2 tracepoints (in tracepoint_register_lib()
at tracepoint.c:767)
liblttng_ust_tracepoint[313/313]: registered tracepoint:
ust_baddr_statedump:soinfo (in tracepoint_register_lib() at
tracepoint.c:772)
liblttng_ust_tracepoint[313/313]: registered tracepoint:
lttng_ust_tracef:event (in tracepoint_register_lib() at tracepoint.c:772)
libust[313/313]: Provider "ust_libc" accepted, version 1.0 is compatible
with LTTng UST provider version 1.0. (in check_provider_version() at
lttng-probes.c:174)
libust[313/313]: adding probe ust_libc containing 6 events to lazy
registration list (in lttng_probe_register() at lttng-probes.c:216)
libust[313/313]: just registered probe ust_libc containing 6 events (in
lttng_lazy_probe_register() at lttng-probes.c:115)
libust[313/313]: Sent register event notification for name
"ust_libc:malloc": ret_code 0, event_id 10
(in ustcomm_register_event() at lttng-ust-comm.c:1001)
libust[313/313]: Sent register event notification for name
"ust_libc:free": ret_code 0, event_id 11
(in ustcomm_register_event() at lttng-ust-comm.c:1001)
libust[313/313]: Sent register event notification for name
"ust_libc:calloc": ret_code 0, event_id 12
(in ustcomm_register_event() at lttng-ust-comm.c:1001)
libust[313/313]: Sent register event notification for name
"ust_libc:realloc": ret_code 0, event_id 13
(in ustcomm_register_event() at lttng-ust-comm.c:1001)
libust[313/313]: Sent register event notification for name
"ust_libc:memalign": ret_code 0, event_id 14
(in ustcomm_register_event() at lttng-ust-comm.c:1001)
libust[313/313]: Sent register event notification for name
"ust_libc:posix_memalign": ret_code 0, event_id 15
(in ustcomm_register_event() at lttng-ust-comm.c:1001)
liblttng_ust_tracepoint[313/313]: Registering probe to tracepoint
ust_libc:posix_memalign (in __tracepoint_probe_register() at
tracepoint.c:563)
liblttng_ust_tracepoint[313/313]: Registering probe to tracepoint
ust_libc:memalign (in __tracepoint_probe_register() at tracepoint.c:563)
liblttng_ust_tracepoint[313/313]: Registering probe to tracepoint
ust_libc:realloc (in __tracepoint_probe_register() at tracepoint.c:563)
liblttng_ust_tracepoint[313/313]: Registering probe to tracepoint
ust_libc:calloc (in __tracepoint_probe_register() at tracepoint.c:563)
liblttng_ust_tracepoint[313/313]: Registering probe to tracepoint
ust_libc:free (in __tracepoint_probe_register() at tracepoint.c:563)
liblttng_ust_tracepoint[313/313]: Registering probe to tracepoint
ust_libc:malloc (in __tracepoint_probe_register() at tracepoint.c:563)
Am 21.10.2015 um 17:38 schrieb Jonathan Rajotte Julien:
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@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
[email protected]
http://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev
_______________________________________________
lttng-dev mailing list
[email protected]
http://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev
