[lttng-dev] Can't get any event output from the demo exe

Mon Mar 23 11:39:28 EDT 2015

Hi Mathieu,

thanks for looking at it.

Here the complete log of both sides

row at cobra7:~$ lttng create
Session auto-20150323-162735 created.
Traces will be written in /home/local/ESG_GMBH/row/lttng-traces/auto-20150323-162735

DEBUG1 [2915/2921]: Wait for client response (in thread_manage_clients() at main.c:3815)
DEBUG1 [2915/2921]: Receiving data from client ... (in thread_manage_clients() at main.c:3860)
DEBUG1 [2915/2921]: Nothing recv() from client... continuing (in thread_manage_clients() at main.c:3864)
DEBUG1 [2915/2921]: Clean command context structure (in clean_command_ctx() at main.c:608)
DEBUG1 [2915/2921]: Accepting client command ... (in thread_manage_clients() at main.c:3773)
DEBUG1 [2915/2921]: Wait for client response (in thread_manage_clients() at main.c:3815)
DEBUG1 [2915/2921]: Receiving data from client ... (in thread_manage_clients() at main.c:3860)
DEBUG1 [2915/2921]: Processing client command 8 (in process_client_msg() at main.c:2637)
DEBUG1 [2915/2921]: Waiting for 1 URIs from client ... (in process_client_msg() at main.c:3201)
DEBUG2 [2915/2921]: Trying to find session by name auto-20150323-162735 (in session_find_by_name() at session.c:169)
DEBUG3 [2915/2921]: Created hashtable size 4 at 0xb2a05a28 of type 1 (in lttng_ht_new() at hashtable.c:127)
DEBUG1 [2915/2921]: Tracing session auto-20150323-162735 created with ID 0 by UID 1548223785 GID 1548222977 (in session_create() at session.c:276)
DEBUG2 [2915/2921]: Trying to find session by name auto-20150323-162735 (in session_find_by_name() at session.c:169)
DEBUG3 [2915/2921]: Created hashtable size 4 at 0xb2a0ad80 of type 1 (in lttng_ht_new() at hashtable.c:127)
DEBUG2 [2915/2921]: Setting trace directory path from URI to /home/local/ESG_GMBH/row/lttng-traces/auto-20150323-162735 (in add_uri_to_consumer() at cmd.c:481)
DEBUG1 [2915/2921]: Sending response (size: 16, retcode: Success) (in thread_manage_clients() at main.c:3909)
DEBUG1 [2915/2921]: Clean command context structure (in clean_command_ctx() at main.c:608)
DEBUG1 [2915/2921]: Accepting client command ... (in thread_manage_clients() at main.c:3773)

row at cobra7:~$ lttng enable-event -u -a
All UST events are enabled in channel channel0

DEBUG1 [2915/2921]: Wait for client response (in thread_manage_clients() at main.c:3815)
DEBUG1 [2915/2921]: Receiving data from client ... (in thread_manage_clients() at main.c:3860)
DEBUG1 [2915/2921]: Nothing recv() from client... continuing (in thread_manage_clients() at main.c:3864)
DEBUG1 [2915/2921]: Clean command context structure (in clean_command_ctx() at main.c:608)
DEBUG1 [2915/2921]: Accepting client command ... (in thread_manage_clients() at main.c:3773)
DEBUG1 [2915/2921]: Wait for client response (in thread_manage_clients() at main.c:3815)
DEBUG1 [2915/2921]: Receiving data from client ... (in thread_manage_clients() at main.c:3860)
DEBUG1 [2915/2921]: Processing client command 6 (in process_client_msg() at main.c:2637)
DEBUG1 [2915/2921]: Getting session auto-20150323-162735 by name (in process_client_msg() at main.c:2716)
DEBUG2 [2915/2921]: Trying to find session by name auto-20150323-162735 (in session_find_by_name() at session.c:169)
DEBUG1 [2915/2921]: Creating UST session (in create_ust_session() at main.c:2517)
DEBUG3 [2915/2921]: Created hashtable size 4 at 0xb2a039f0 of type 0 (in lttng_ht_new() at hashtable.c:127)
DEBUG3 [2915/2921]: Created hashtable size 4 at 0xb2a03d18 of type 0 (in lttng_ht_new() at hashtable.c:127)
DEBUG3 [2915/2921]: Created hashtable size 4 at 0xb2a04040 of type 1 (in lttng_ht_new() at hashtable.c:127)
DEBUG2 [2915/2921]: UST trace session create successful (in trace_ust_create_session() at trace-ust.c:263)
DEBUG3 [2915/2921]: Copying tracing session consumer output in UST session (in copy_session_consumer() at main.c:2466)
DEBUG3 [2915/2921]: Created hashtable size 4 at 0xb2a04368 of type 1 (in lttng_ht_new() at hashtable.c:127)
DEBUG3 [2915/2921]: Copy session consumer subdir /ust (in copy_session_consumer() at main.c:2484)
DEBUG1 [2915/2921]: Spawning consumerd (in spawn_consumerd() at main.c:2158)
DEBUG2 [2915/2921]: Consumer pid 2987 (in start_consumerd() at main.c:2340)
DEBUG2 [2915/2921]: Spawning consumer control thread (in start_consumerd() at main.c:2343)
DEBUG3 [2915/2918]: [ht-thread] Polling on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:64)
DEBUG1 [2987/2987]: Using 32-bit UST consumer at: /usr/lib/i386-linux-gnu/lttng/libexec/lttng-consumerd (in spawn_consumerd() at main.c:2278)
DEBUG1 [2915/2988]: [thread] Manage consumer started (in thread_manage_consumer() at main.c:994)
DEBUG2 [2915/2988]: Receiving code from consumer err_sock (in thread_manage_consumer() at main.c:1079)
DEBUG1 [2915/2988]: Consumer command socket ready (fd: 26 (in thread_manage_consumer() at main.c:1113)
DEBUG1 [2915/2988]: Consumer metadata socket ready (fd: 27) (in thread_manage_consumer() at main.c:1115)
DEBUG3 [2915/2921]: Consumer socket created (fd: 26) and added to output (in consumer_create_socket() at consumer.c:301)
DEBUG1 [2915/2921]: Setting relayd for session auto-20150323-162735 (in cmd_setup_relayd() at cmd.c:722)
DEBUG2 [2915/2921]: Trace UST channel channel0 not found by name (in trace_ust_find_channel_by_name() at trace-ust.c:162)
DEBUG1 [2915/2921]: Enabling channel  for session auto-20150323-162735 (in cmd_enable_channel() at cmd.c:910)
DEBUG2 [2915/2921]: Trace UST channel channel0 not found by name (in trace_ust_find_channel_by_name() at trace-ust.c:162)
DEBUG3 [2915/2921]: Created hashtable size 4 at 0xb2a04910 of type 0 (in lttng_ht_new() at hashtable.c:127)
DEBUG3 [2915/2921]: Created hashtable size 4 at 0xb2a04bf0 of type 1 (in lttng_ht_new() at hashtable.c:127)
DEBUG2 [2915/2921]: Trace UST channel channel0 created (in trace_ust_create_channel() at trace-ust.c:331)
DEBUG2 [2915/2921]: Channel channel0 is being created for UST with buffer 1 and id 0 (in channel_ust_create() at channel.c:348)
DEBUG2 [2915/2921]: UST app adding channel channel0 to UST domain for session id 0 (in ust_app_create_channel_glb() at ust-app.c:3536)
DEBUG2 [2915/2921]: Channel channel0 created successfully (in channel_ust_create() at channel.c:383)
DEBUG2 [2915/2921]: Trace UST channel channel0 found by name (in trace_ust_find_channel_by_name() at trace-ust.c:157)
DEBUG2 [2915/2921]: Trace UST event * NOT found (in trace_ust_find_event() at trace-ust.c:198)
DEBUG2 [2915/2921]: Trace UST event *, loglevel (0,-1) created (in trace_ust_create_event() at trace-ust.c:405)
DEBUG1 [2915/2921]: UST app creating event * for all apps for session id 0 (in ust_app_create_event_glb() at ust-app.c:3687)
DEBUG1 [2915/2921]: Event UST * created in channel channel0 (in event_ust_enable_tracepoint() at event.c:469)
DEBUG1 [2915/2921]: Sending response (size: 16, retcode: Success) (in thread_manage_clients() at main.c:3909)
DEBUG1 [2915/2921]: Clean command context structure (in clean_command_ctx() at main.c:608)
DEBUG1 [2915/2921]: Accepting client command ... (in thread_manage_clients() at main.c:3773)

row at cobra7:~$ lttng start
Tracing started for session auto-20150323-162735

DEBUG1 [2915/2921]: Wait for client response (in thread_manage_clients() at main.c:3815)
DEBUG1 [2915/2921]: Receiving data from client ... (in thread_manage_clients() at main.c:3860)
DEBUG1 [2915/2921]: Nothing recv() from client... continuing (in thread_manage_clients() at main.c:3864)
DEBUG1 [2915/2921]: Clean command context structure (in clean_command_ctx() at main.c:608)
DEBUG1 [2915/2921]: Accepting client command ... (in thread_manage_clients() at main.c:3773)
DEBUG1 [2915/2921]: Wait for client response (in thread_manage_clients() at main.c:3815)
DEBUG1 [2915/2921]: Receiving data from client ... (in thread_manage_clients() at main.c:3860)
DEBUG1 [2915/2921]: Processing client command 16 (in process_client_msg() at main.c:2637)
DEBUG1 [2915/2921]: Getting session auto-20150323-162735 by name (in process_client_msg() at main.c:2716)
DEBUG2 [2915/2921]: Trying to find session by name auto-20150323-162735 (in session_find_by_name() at session.c:169)
DEBUG1 [2915/2921]: Starting all UST traces (in ust_app_start_trace_all() at ust-app.c:4034)
DEBUG1 [2915/2921]: Sending response (size: 16, retcode: Success) (in thread_manage_clients() at main.c:3909)
DEBUG1 [2915/2921]: Clean command context structure (in clean_command_ctx() at main.c:608)
DEBUG1 [2915/2921]: Accepting client command ... (in thread_manage_clients() at main.c:3773)

row at cobra7:~/lttng_source/lttng-ust/doc/examples/demo$ ./demo-trace
liblttng_ust_tracepoint[3581/3581]: just registered a tracepoints section from 0xb757c780 and having 2 tracepoints (in tracepoint_register_lib() at tracepoint.c:767)
liblttng_ust_tracepoint[3581/3581]: registered tracepoint: ust_baddr_statedump:soinfo (in tracepoint_register_lib() at tracepoint.c:772)
liblttng_ust_tracepoint[3581/3581]: registered tracepoint: lttng_ust_tracef:event (in tracepoint_register_lib() at tracepoint.c:772)
libust[3581/3581]: 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[3581/3581]: adding probe ust_baddr_statedump containing 1 events to lazy registration list (in lttng_probe_register() at lttng-probes.c:216)
libust[3581/3581]: 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[3581/3581]: LTT : ltt ring buffer client "relay-overwrite-mmap" init
(in lttng_ring_buffer_client_overwrite_init() at lttng-ring-buffer-client.h:681)
libust[3581/3581]: 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[3581/3581]: LTT : ltt ring buffer client "relay-discard-mmap" init
(in lttng_ring_buffer_client_discard_init() at lttng-ring-buffer-client.h:681)
libust[3581/3581]: 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[3581/3582]: Info: sessiond not accepting connections to global apps socket (in ust_listener_thread() at lttng-ust-comm.c:1221)
libust[3581/3583]: Info: sessiond not accepting connections to local apps socket (in ust_listener_thread() at lttng-ust-comm.c:1221)
libust[3581/3582]: Waiting for global apps sessiond (in wait_for_sessiond() at lttng-ust-comm.c:1132)
libust[3581/3581]: Provider "lttng_ust_tracef" accepted, version 1.0 is compatible with LTTng UST provider version 1.0. (in check_provider_version() at lttng-probes.c:174)
libust[3581/3583]: Waiting for local apps sessiond (in wait_for_sessiond() at lttng-ust-comm.c:1132)
libust[3581/3581]: just registered probe ust_baddr_statedump containing 1 events (in lttng_lazy_probe_register() at lttng-probes.c:115)
libust[3581/3581]: adding probe lttng_ust_tracef containing 1 events to lazy registration list (in lttng_probe_register() at lttng-probes.c:216)
libust[3581/3581]: Provider "ust_tests_demo3" accepted, version 1.0 is compatible with LTTng UST provider version 1.0. (in check_provider_version() at lttng-probes.c:174)
libust[3581/3581]: just registered probe lttng_ust_tracef containing 1 events (in lttng_lazy_probe_register() at lttng-probes.c:115)
libust[3581/3581]: adding probe ust_tests_demo3 containing 1 events to lazy registration list (in lttng_probe_register() at lttng-probes.c:216)
libust[3581/3581]: Provider "ust_tests_demo" accepted, version 1.0 is compatible with LTTng UST provider version 1.0. (in check_provider_version() at lttng-probes.c:174)
libust[3581/3581]: just registered probe ust_tests_demo3 containing 1 events (in lttng_lazy_probe_register() at lttng-probes.c:115)
libust[3581/3581]: adding probe ust_tests_demo containing 2 events to lazy registration list (in lttng_probe_register() at lttng-probes.c:216)
libust[3581/3581]: Provider "ust_tests_demo2" accepted, version 1.0 is compatible with LTTng UST provider version 1.0. (in check_provider_version() at lttng-probes.c:174)
libust[3581/3581]: just registered probe ust_tests_demo containing 2 events (in lttng_lazy_probe_register() at lttng-probes.c:115)
libust[3581/3581]: adding probe ust_tests_demo2 containing 1 events to lazy registration list (in lttng_probe_register() at lttng-probes.c:216)
liblttng_ust_tracepoint[3581/3581]: just registered a tracepoints section from 0x804b144 and having 4 tracepoints (in tracepoint_register_lib() at tracepoint.c:767)
liblttng_ust_tracepoint[3581/3581]: registered tracepoint: ust_tests_demo:starting (in tracepoint_register_lib() at tracepoint.c:772)
liblttng_ust_tracepoint[3581/3581]: registered tracepoint: ust_tests_demo:done (in tracepoint_register_lib() at tracepoint.c:772)
liblttng_ust_tracepoint[3581/3581]: registered tracepoint: ust_tests_demo2:loop (in tracepoint_register_lib() at tracepoint.c:772)
liblttng_ust_tracepoint[3581/3581]: registered tracepoint: ust_tests_demo3:done (in tracepoint_register_lib() at tracepoint.c:772)
Demo program starting.
Tracing...  done.
liblttng_ust_tracepoint[3581/3581]: just unregistered a tracepoints section from 0x804b144 (in tracepoint_unregister_lib() at tracepoint.c:797)
libust[3581/3581]: Provider "ust_tests_demo2" accepted, version 1.0 is compatible with LTTng UST provider version 1.0. (in check_provider_version() at lttng-probes.c:174)
libust[3581/3581]: just unregistered probe ust_tests_demo2 (in lttng_probe_unregister() at lttng-probes.c:245)
libust[3581/3581]: Provider "ust_tests_demo" accepted, version 1.0 is compatible with LTTng UST provider version 1.0. (in check_provider_version() at lttng-probes.c:174)
libust[3581/3581]: just unregistered probe ust_tests_demo (in lttng_probe_unregister() at lttng-probes.c:245)
libust[3581/3581]: Provider "ust_tests_demo3" accepted, version 1.0 is compatible with LTTng UST provider version 1.0. (in check_provider_version() at lttng-probes.c:174)
libust[3581/3581]: just unregistered probe ust_tests_demo3 (in lttng_probe_unregister() at lttng-probes.c:245)
libust[3581/3581]: Provider "lttng_ust_tracef" accepted, version 1.0 is compatible with LTTng UST provider version 1.0. (in check_provider_version() at lttng-probes.c:174)
libust[3581/3581]: just unregistered probe lttng_ust_tracef (in lttng_probe_unregister() at lttng-probes.c:245)
libust[3581/3581]: LTT : ltt ring buffer client "relay-discard-rt-mmap" exit
(in lttng_ring_buffer_client_discard_rt_exit() at lttng-ring-buffer-client.h:688)
libust[3581/3581]: LTT : ltt ring buffer client "relay-discard-mmap" exit
(in lttng_ring_buffer_client_discard_exit() at lttng-ring-buffer-client.h:688)
libust[3581/3581]: LTT : ltt ring buffer client "relay-overwrite-rt-mmap" exit
(in lttng_ring_buffer_client_overwrite_rt_exit() at lttng-ring-buffer-client.h:688)
libust[3581/3581]: LTT : ltt ring buffer client "relay-overwrite-mmap" exit
(in lttng_ring_buffer_client_overwrite_exit() at lttng-ring-buffer-client.h:688)
libust[3581/3581]: LTT : ltt ring buffer client "relay-metadata-mmap" exit
(in lttng_ring_buffer_metadata_client_exit() at lttng-ring-buffer-metadata-client.h:337)
libust[3581/3581]: 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[3581/3581]: just unregistered probe ust_baddr_statedump (in lttng_probe_unregister() at lttng-probes.c:245)
liblttng_ust_tracepoint[3581/3581]: just unregistered a tracepoints section from 0xb757c780 (in tracepoint_unregister_lib() at tracepoint.c:797)
row at cobra7:~/lttng_source/lttng-ust/doc/examples/demo$

=> no log in sessiond shell