[lttng-dev] lttng-sessiond stuck at "Accepting application registration"

Jérémie Galarneau jeremie.galarneau at efficios.com
Tue Mar 29 18:52:12 UTC 2016


Hi Aditya,

Thanks for reporting this issue. Can you open a ticket on the bug
tracker with your observations?

Please have a look at our bug reporting guidelines to make sure you
don't forget anything and we'll look into this as time allows.

https://lttng.org/community/#bug-reporting-guidelines

Thanks,
Jérémie

On Mon, Mar 28, 2016 at 8:51 AM, aditya dogra <dogra.aditya at gmail.com> wrote:
> Adding Lttng-dev
>
> We are running running a 32 bit application on a 64 bit machine. We have
> built 32bit versions of both the sessiond and the consumerd.
> Could anyone please point us on how do go about debugging this ?
>
> lttng (LTTng Trace Control) 2.7.1 - Herbe à Détourne - v2.7.1
>
>
> Facing some issues when we do "lttng start".
>
> DEBUG1 - 14:22:18.457697 [9524/9556]: Wait for client response (in
> thread_manage_clients() at main.c:4362)
> DEBUG1 - 14:22:18.457754 [9524/9556]: Receiving data from client ... (in
> thread_manage_clients() at main.c:4407)
> DEBUG1 - 14:22:18.457776 [9524/9556]: Processing client command 16 (in
> process_client_msg() at main.c:2989)
> DEBUG1 - 14:22:18.457782 [9524/9556]: Getting session auto-20160323-142131
> by name (in process_client_msg() at main.c:3076)
> DEBUG2 - 14:22:18.457788 [9524/9556]: Trying to find session by name
> auto-20160323-142131 (in session_find_by_name() at session.c:172)
> DEBUG1 - 14:22:18.457797 [9524/9556]: Starting all UST traces (in
> ust_app_start_trace_all() at ust-app.c:4592)
> DEBUG1 - 14:22:18.457804 [9524/9556]: Starting tracing for ust app pid 11876
> (in ust_app_start_trace() at ust-app.c:4205)
> DEBUG3 - 14:22:18.457811 [9524/9556]: mkdir() recursive
> /root/lttng-traces/auto-20160323-142131 with mode 504 for uid 0 and gid 0
> (in run_as_mkdir_recursive() at runas.c:468)
> DEBUG1 - 14:22:18.457821 [9524/9556]: Using run_as worker (in run_as() at
> runas.c:449)
> DEBUG3 - 14:22:18.457871 [9524/9556]: Buffer registry per UID find id: 2,
> ABI: 32, uid: 499 (in buffer_reg_uid_find() at buffer-registry.c:204)
> DEBUG3 - 14:22:18.457885 [9524/9556]: Created hashtable size 4 at 0xf4233240
> of type 1 (in lttng_ht_new() at hashtable.c:136)
> DEBUG3 - 14:22:18.457893 [9524/9556]: Created hashtable size 4 at 0xf4233318
> of type 0 (in lttng_ht_new() at hashtable.c:136)
> DEBUG3 - 14:22:18.457899 [9524/9556]: UST app channel metadata allocated (in
> alloc_ust_app_channel() at ust-app.c:967)
> DEBUG2 - 14:22:18.457906 [9524/9556]: Asking UST consumer for channel (in
> ask_channel_creation() at ust-consumer.c:121)
> DEBUG3 - 14:22:18.457914 [9524/9556]: mkdir() recursive
> /root/lttng-traces/auto-20160323-142131/ust/uid/499/32-bit with mode 504 for
> uid 0 and gid 0 (in run_as_mkdir_recursive() at runas.c:468)
> DEBUG1 - 14:22:18.457921 [9524/9556]: Using run_as worker (in run_as() at
> runas.c:449)
> DEBUG2 - 14:22:18.458130 [9524/9556]: UST ask channel 6 successfully done
> with 1 stream(s) (in ask_channel_creation() at ust-consumer.c:216)
> DEBUG2 - 14:22:18.458139 [9524/9556]: Consumer setup metadata channel key 6
> (in consumer_setup_metadata() at consumer.c:1236)
> DEBUG2 - 14:22:18.458176 [9524/9556]: UST metadata with key 6 created for
> app pid 11876 (in create_ust_app_metadata() at ust-app.c:3133)
> DEBUG3 - 14:22:18.458183 [9524/9556]: UST app deleting channel metadata (in
> delete_ust_app_channel() at ust-app.c:391)
> DEBUG3 - 14:22:18.458276 [9524/9560]: [ust-thread] Manage notify return from
> poll on 3 fds (in ust_thread_manage_notify() at ust-thread.c:76)
> DEBUG3 - 14:22:18.458289 [9524/9560]: UST app receiving notify from sock 33
> (in ust_app_recv_notify() at ust-app.c:5289)
> DEBUG2 - 14:22:18.458297 [9524/9560]: UST app ustctl register channel
> received (in ust_app_recv_notify() at ust-app.c:5343)
> DEBUG3 - 14:22:18.458309 [9524/9560]: Buffer registry per UID find id: 2,
> ABI: 32, uid: 499 (in buffer_reg_uid_find() at buffer-registry.c:204)
> Error: Error starting tracing for app pid: 11876 (ret: -1024)
> DEBUG3 - 14:22:22.453769 [9524/9560]: UST registry channel finding key 0 (in
> ust_registry_channel_find() at ust-registry.c:490)
> DEBUG1 - 14:22:22.453780 [9524/9556]: Sending response (size: 16, retcode:
> Success) (in thread_manage_clients() at main.c:4456)
> DEBUG3 - 14:22:22.453787 [9524/9560]: Append to metadata: "stream {
>         id = 0;
>         event.header := struct event_header_compact;
>         packet.context := struct packet_context;
> " (in lttng_metadata_printf() at ust-metadata.c:175)
> DEBUG1 - 14:22:22.453811 [9524/9556]: Clean command context structure (in
> clean_command_ctx() at main.c:829)
> DEBUG3 - 14:22:22.453813 [9524/9560]: Append to metadata: "};
>
> " (in lttng_metadata_printf() at ust-metadata.c:175)
> DEBUG1 - 14:22:22.453821 [9524/9556]: Accepting client command ... (in
> thread_manage_clients() at main.c:4310)
> DEBUG3 - 14:22:22.453829 [9524/9560]: UST app replying to register channel
> key 0 with id 0, type: 1, ret: 0 (in reply_ust_register_channel() at
> ust-app.c:5155)
> DEBUG3 - 14:22:22.453839 [9524/9560]: UST app reply channel failed.
> Application died (in reply_ust_register_channel() at ust-app.c:5162)
> DEBUG1 - 14:22:22.453851 [9524/9560]: UST app notify socket unregister 33
> (in ust_app_notify_sock_unregister() at ust-app.c:5417)
> Tracing started for session auto-20160323-142131
> DEBUG3 - 14:22:22.453860 [9524/9560]: [ust-thread] Manage notify polling (in
> ust_thread_manage_notify() at ust-thread.c:69)
> DEBUG3 - 14:22:22.453865 [9524/9526]: [ht-thread] Returning from poll on 2
> fds. (in thread_ht_cleanup() at ht-cleanup.c:74)
> DEBUG3 - 14:22:22.453882 [9524/9526]: [ht-thread] Polling. (in
> thread_ht_cleanup() at ht-cleanup.c:67)
> DEBUG3 - 14:22:22.453888 [9524/9526]: [ht-thread] Returning from poll on 2
> fds. (in thread_ht_cleanup() at ht-cleanup.c:74)
> DEBUG3 - 14:22:22.453895 [9524/9526]: [ht-thread] Polling. (in
> thread_ht_cleanup() at ht-cleanup.c:67)
>
>
>
> We believe that due to the above issue, no traces are created.
>
>
> lttng view
> DEBUG1 - 14:24:26.807884 [9524/9556]: Wait for client response (in
> thread_manage_clients() at main.c:4362)
> DEBUG1 - 14:24:26.807934 [9524/9556]: Receiving data from client ... (in
> thread_manage_clients() at main.c:4407)
> DEBUG1 - 14:24:26.807955 [9524/9556]: Processing client command 13 (in
> process_client_msg() at main.c:2989)
> DEBUG1 - 14:24:26.807962 [9524/9556]: Counting number of available session
> for UID 0 GID 0 (in lttng_sessions_count() at main.c:2958)
> DEBUG1 - 14:24:26.807970 [9524/9556]: Getting all available session for UID
> 0 GID 0 (in cmd_list_lttng_sessions() at cmd.c:2783)
> DEBUG1 - 14:24:26.807978 [9524/9556]: Sending response (size: 4392, retcode:
> Success) (in thread_manage_clients() at main.c:4456)
> DEBUG1 - 14:24:26.807999 [9524/9556]: Clean command context structure (in
> clean_command_ctx() at main.c:829)
> DEBUG1 - 14:24:26.808006 [9524/9556]: Accepting client command ... (in
> thread_manage_clients() at main.c:4310)
> Trace directory: /root/lttng-traces/auto-20160323-142131
>
>
>
>
> We are using tracef() in our application.
>
>
> #include <lttng/tracef.h>
>
> tracef("my message, my integer: %d", 0x1234);
>
>
> lttng list --userspace
> DEBUG1 - 14:21:17.747867 [9524/9556]: Wait for client response (in
> thread_manage_clients() at main.c:4362)
> DEBUG1 - 14:21:17.747921 [9524/9556]: Receiving data from client ... (in
> thread_manage_clients() at main.c:4407)
> DEBUG1 - 14:21:17.747943 [9524/9556]: Processing client command 14 (in
> process_client_msg() at main.c:2989)
> DEBUG2 - 14:21:17.748521 [9524/9556]: Reallocating event list from 32 to 64
> entries (in ust_app_list_events() at ust-app.c:3502)
> DEBUG2 - 14:21:17.748623 [9524/9556]: UST app list events done (35 events)
> (in ust_app_list_events() at ust-app.c:3543)
> DEBUG1 - 14:21:17.748638 [9524/9556]: Sending response (size: 20456,
> retcode: Success) (in thread_manage_clients() at main.c:4456)
> DEBUG1 - 14:21:17.748663 [9524/9556]: Clean command context structure (in
> clean_command_ctx() at main.c:829)
> DEBUG1 - 14:21:17.748670 [9524/9556]: Accepting client command ... (in
> thread_manage_clients() at main.c:4310)
> UST events:
> -------------
>
> PID: 11876 - Name: <process_name>
>       lttng_ust_cyg_profile_fast:func_exit (loglevel: TRACE_DEBUG_FUNCTION
> (12)) (type: tracepoint)
>       lttng_ust_cyg_profile_fast:func_entry (loglevel: TRACE_DEBUG_FUNCTION
> (12)) (type: tracepoint)
>       lttng_ust_cyg_profile:func_exit (loglevel: TRACE_DEBUG_FUNCTION (12))
> (type: tracepoint)
>       lttng_ust_cyg_profile:func_entry (loglevel: TRACE_DEBUG_FUNCTION (12))
> (type: tracepoint)
>       lttng_ust_dl:dlclose (loglevel: TRACE_DEBUG_LINE (13)) (type:
> tracepoint)
>       lttng_ust_dl:dlopen (loglevel: TRACE_DEBUG_LINE (13)) (type:
> tracepoint)
>       lttng_ust_libc:posix_memalign (loglevel: TRACE_DEBUG_LINE (13)) (type:
> tracepoint)
>       lttng_ust_libc:memalign (loglevel: TRACE_DEBUG_LINE (13)) (type:
> tracepoint)
>       lttng_ust_libc:realloc (loglevel: TRACE_DEBUG_LINE (13)) (type:
> tracepoint)
>       lttng_ust_libc:calloc (loglevel: TRACE_DEBUG_LINE (13)) (type:
> tracepoint)
>       lttng_ust_libc:free (loglevel: TRACE_DEBUG_LINE (13)) (type:
> tracepoint)
>       lttng_ust_libc:malloc (loglevel: TRACE_DEBUG_LINE (13)) (type:
> tracepoint)
>       lttng_ust_pthread:pthread_mutex_unlock (loglevel: TRACE_DEBUG_LINE
> (13)) (type: tracepoint)
>       lttng_ust_pthread:pthread_mutex_trylock (loglevel: TRACE_DEBUG_LINE
> (13)) (type: tracepoint)
>       lttng_ust_pthread:pthread_mutex_lock_acq (loglevel: TRACE_DEBUG_LINE
> (13)) (type: tracepoint)
>       lttng_ust_pthread:pthread_mutex_lock_req (loglevel: TRACE_DEBUG_LINE
> (13)) (type: tracepoint)
>       lttng_ust_tracelog:TRACE_DEBUG (loglevel: TRACE_DEBUG (14)) (type:
> tracepoint)
>       lttng_ust_tracelog:TRACE_DEBUG_LINE (loglevel: TRACE_DEBUG_LINE (13))
> (type: tracepoint)
>       lttng_ust_tracelog:TRACE_DEBUG_FUNCTION (loglevel:
> TRACE_DEBUG_FUNCTION (12)) (type: tracepoint)
>       lttng_ust_tracelog:TRACE_DEBUG_UNIT (loglevel: TRACE_DEBUG_UNIT (11))
> (type: tracepoint)
>       lttng_ust_tracelog:TRACE_DEBUG_MODULE (loglevel: TRACE_DEBUG_MODULE
> (10)) (type: tracepoint)
>       lttng_ust_tracelog:TRACE_DEBUG_PROCESS (loglevel: TRACE_DEBUG_PROCESS
> (9)) (type: tracepoint)
>       lttng_ust_tracelog:TRACE_DEBUG_PROGRAM (loglevel: TRACE_DEBUG_PROGRAM
> (8)) (type: tracepoint)
>       lttng_ust_tracelog:TRACE_DEBUG_SYSTEM (loglevel: TRACE_DEBUG_SYSTEM
> (7)) (type: tracepoint)
>       lttng_ust_tracelog:TRACE_INFO (loglevel: TRACE_INFO (6)) (type:
> tracepoint)
>       lttng_ust_tracelog:TRACE_NOTICE (loglevel: TRACE_NOTICE (5)) (type:
> tracepoint)
>       lttng_ust_tracelog:TRACE_WARNING (loglevel: TRACE_WARNING (4)) (type:
> tracepoint)
>       lttng_ust_tracelog:TRACE_ERR (loglevel: TRACE_ERR (3)) (type:
> tracepoint)
>       lttng_ust_tracelog:TRACE_CRIT (loglevel: TRACE_CRIT (2)) (type:
> tracepoint)
>       lttng_ust_tracelog:TRACE_ALERT (loglevel: TRACE_ALERT (1)) (type:
> tracepoint)
>       lttng_ust_tracelog:TRACE_EMERG (loglevel: TRACE_EMERG (0)) (type:
> tracepoint)
>       lttng_ust_tracef:event (loglevel: TRACE_DEBUG (14)) (type: tracepoint)
>       lttng_ust_statedump:end (loglevel: TRACE_DEBUG_LINE (13)) (type:
> tracepoint)
>       lttng_ust_statedump:soinfo (loglevel: TRACE_DEBUG_LINE (13)) (type:
> tracepoint)
>       lttng_ust_statedump:start (loglevel: TRACE_DEBUG_LINE (13)) (type:
> tracepoint)
>
>
>
>
>
> Kindly help us in fixing this issue.
>
> Regards,
> Aditya Dogra
> "When the going gets tough, the tough get going"
>
> On Mon, Mar 28, 2016 at 3:38 PM, Vijay Anand <vjanandr85 at gmail.com> wrote:
>>
>> Just to add, we are running running a 32 bit application on a 64 bit
>> machine. We have built 32bit versions of both the sessiond and the
>> consumerd.
>> Could anyone please point us on how do go about debugging this ?
>>
>> Regards,
>> Vijay
>>
>> On Wed, Mar 23, 2016 at 6:10 PM, Prashanth Raghavendra
>> <prashanth.raghavendra at gmail.com> wrote:
>>>
>>> Hi Jeremie,
>>>
>>> We upgraded to LTTNG 2.7.
>>>
>>> lttng (LTTng Trace Control) 2.7.1 - Herbe à Détourne - v2.7.1
>>>
>>>
>>> Facing some issues when we do "lttng start".
>>>
>>> DEBUG1 - 14:22:18.457697 [9524/9556]: Wait for client response (in
>>> thread_manage_clients() at main.c:4362)
>>> DEBUG1 - 14:22:18.457754 [9524/9556]: Receiving data from client ... (in
>>> thread_manage_clients() at main.c:4407)
>>> DEBUG1 - 14:22:18.457776 [9524/9556]: Processing client command 16 (in
>>> process_client_msg() at main.c:2989)
>>> DEBUG1 - 14:22:18.457782 [9524/9556]: Getting session
>>> auto-20160323-142131 by name (in process_client_msg() at main.c:3076)
>>> DEBUG2 - 14:22:18.457788 [9524/9556]: Trying to find session by name
>>> auto-20160323-142131 (in session_find_by_name() at session.c:172)
>>> DEBUG1 - 14:22:18.457797 [9524/9556]: Starting all UST traces (in
>>> ust_app_start_trace_all() at ust-app.c:4592)
>>> DEBUG1 - 14:22:18.457804 [9524/9556]: Starting tracing for ust app pid
>>> 11876 (in ust_app_start_trace() at ust-app.c:4205)
>>> DEBUG3 - 14:22:18.457811 [9524/9556]: mkdir() recursive
>>> /root/lttng-traces/auto-20160323-142131 with mode 504 for uid 0 and gid 0
>>> (in run_as_mkdir_recursive() at runas.c:468)
>>> DEBUG1 - 14:22:18.457821 [9524/9556]: Using run_as worker (in run_as() at
>>> runas.c:449)
>>> DEBUG3 - 14:22:18.457871 [9524/9556]: Buffer registry per UID find id: 2,
>>> ABI: 32, uid: 499 (in buffer_reg_uid_find() at buffer-registry.c:204)
>>> DEBUG3 - 14:22:18.457885 [9524/9556]: Created hashtable size 4 at
>>> 0xf4233240 of type 1 (in lttng_ht_new() at hashtable.c:136)
>>> DEBUG3 - 14:22:18.457893 [9524/9556]: Created hashtable size 4 at
>>> 0xf4233318 of type 0 (in lttng_ht_new() at hashtable.c:136)
>>> DEBUG3 - 14:22:18.457899 [9524/9556]: UST app channel metadata allocated
>>> (in alloc_ust_app_channel() at ust-app.c:967)
>>> DEBUG2 - 14:22:18.457906 [9524/9556]: Asking UST consumer for channel (in
>>> ask_channel_creation() at ust-consumer.c:121)
>>> DEBUG3 - 14:22:18.457914 [9524/9556]: mkdir() recursive
>>> /root/lttng-traces/auto-20160323-142131/ust/uid/499/32-bit with mode 504 for
>>> uid 0 and gid 0 (in run_as_mkdir_recursive() at runas.c:468)
>>> DEBUG1 - 14:22:18.457921 [9524/9556]: Using run_as worker (in run_as() at
>>> runas.c:449)
>>> DEBUG2 - 14:22:18.458130 [9524/9556]: UST ask channel 6 successfully done
>>> with 1 stream(s) (in ask_channel_creation() at ust-consumer.c:216)
>>> DEBUG2 - 14:22:18.458139 [9524/9556]: Consumer setup metadata channel key
>>> 6 (in consumer_setup_metadata() at consumer.c:1236)
>>> DEBUG2 - 14:22:18.458176 [9524/9556]: UST metadata with key 6 created for
>>> app pid 11876 (in create_ust_app_metadata() at ust-app.c:3133)
>>> DEBUG3 - 14:22:18.458183 [9524/9556]: UST app deleting channel metadata
>>> (in delete_ust_app_channel() at ust-app.c:391)
>>> DEBUG3 - 14:22:18.458276 [9524/9560]: [ust-thread] Manage notify return
>>> from poll on 3 fds (in ust_thread_manage_notify() at ust-thread.c:76)
>>> DEBUG3 - 14:22:18.458289 [9524/9560]: UST app receiving notify from sock
>>> 33 (in ust_app_recv_notify() at ust-app.c:5289)
>>> DEBUG2 - 14:22:18.458297 [9524/9560]: UST app ustctl register channel
>>> received (in ust_app_recv_notify() at ust-app.c:5343)
>>> DEBUG3 - 14:22:18.458309 [9524/9560]: Buffer registry per UID find id: 2,
>>> ABI: 32, uid: 499 (in buffer_reg_uid_find() at buffer-registry.c:204)
>>> Error: Error starting tracing for app pid: 11876 (ret: -1024)
>>> DEBUG3 - 14:22:22.453769 [9524/9560]: UST registry channel finding key 0
>>> (in ust_registry_channel_find() at ust-registry.c:490)
>>> DEBUG1 - 14:22:22.453780 [9524/9556]: Sending response (size: 16,
>>> retcode: Success) (in thread_manage_clients() at main.c:4456)
>>> DEBUG3 - 14:22:22.453787 [9524/9560]: Append to metadata: "stream {
>>>         id = 0;
>>>         event.header := struct event_header_compact;
>>>         packet.context := struct packet_context;
>>> " (in lttng_metadata_printf() at ust-metadata.c:175)
>>> DEBUG1 - 14:22:22.453811 [9524/9556]: Clean command context structure (in
>>> clean_command_ctx() at main.c:829)
>>> DEBUG3 - 14:22:22.453813 [9524/9560]: Append to metadata: "};
>>>
>>> " (in lttng_metadata_printf() at ust-metadata.c:175)
>>> DEBUG1 - 14:22:22.453821 [9524/9556]: Accepting client command ... (in
>>> thread_manage_clients() at main.c:4310)
>>> DEBUG3 - 14:22:22.453829 [9524/9560]: UST app replying to register
>>> channel key 0 with id 0, type: 1, ret: 0 (in reply_ust_register_channel() at
>>> ust-app.c:5155)
>>> DEBUG3 - 14:22:22.453839 [9524/9560]: UST app reply channel failed.
>>> Application died (in reply_ust_register_channel() at ust-app.c:5162)
>>> DEBUG1 - 14:22:22.453851 [9524/9560]: UST app notify socket unregister 33
>>> (in ust_app_notify_sock_unregister() at ust-app.c:5417)
>>> Tracing started for session auto-20160323-142131
>>> DEBUG3 - 14:22:22.453860 [9524/9560]: [ust-thread] Manage notify polling
>>> (in ust_thread_manage_notify() at ust-thread.c:69)
>>> DEBUG3 - 14:22:22.453865 [9524/9526]: [ht-thread] Returning from poll on
>>> 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:74)
>>> DEBUG3 - 14:22:22.453882 [9524/9526]: [ht-thread] Polling. (in
>>> thread_ht_cleanup() at ht-cleanup.c:67)
>>> DEBUG3 - 14:22:22.453888 [9524/9526]: [ht-thread] Returning from poll on
>>> 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:74)
>>> DEBUG3 - 14:22:22.453895 [9524/9526]: [ht-thread] Polling. (in
>>> thread_ht_cleanup() at ht-cleanup.c:67)
>>>
>>>
>>>
>>> We believe that due to the above issue, no traces are created.
>>>
>>>
>>> lttng view
>>> DEBUG1 - 14:24:26.807884 [9524/9556]: Wait for client response (in
>>> thread_manage_clients() at main.c:4362)
>>> DEBUG1 - 14:24:26.807934 [9524/9556]: Receiving data from client ... (in
>>> thread_manage_clients() at main.c:4407)
>>> DEBUG1 - 14:24:26.807955 [9524/9556]: Processing client command 13 (in
>>> process_client_msg() at main.c:2989)
>>> DEBUG1 - 14:24:26.807962 [9524/9556]: Counting number of available
>>> session for UID 0 GID 0 (in lttng_sessions_count() at main.c:2958)
>>> DEBUG1 - 14:24:26.807970 [9524/9556]: Getting all available session for
>>> UID 0 GID 0 (in cmd_list_lttng_sessions() at cmd.c:2783)
>>> DEBUG1 - 14:24:26.807978 [9524/9556]: Sending response (size: 4392,
>>> retcode: Success) (in thread_manage_clients() at main.c:4456)
>>> DEBUG1 - 14:24:26.807999 [9524/9556]: Clean command context structure (in
>>> clean_command_ctx() at main.c:829)
>>> DEBUG1 - 14:24:26.808006 [9524/9556]: Accepting client command ... (in
>>> thread_manage_clients() at main.c:4310)
>>> Trace directory: /root/lttng-traces/auto-20160323-142131
>>>
>>>
>>>
>>>
>>> We are using tracef() in our application.
>>>
>>>
>>> #include <lttng/tracef.h>
>>>
>>> tracef("my message, my integer: %d", 0x1234);
>>>
>>>
>>> lttng list --userspace
>>> DEBUG1 - 14:21:17.747867 [9524/9556]: Wait for client response (in
>>> thread_manage_clients() at main.c:4362)
>>> DEBUG1 - 14:21:17.747921 [9524/9556]: Receiving data from client ... (in
>>> thread_manage_clients() at main.c:4407)
>>> DEBUG1 - 14:21:17.747943 [9524/9556]: Processing client command 14 (in
>>> process_client_msg() at main.c:2989)
>>> DEBUG2 - 14:21:17.748521 [9524/9556]: Reallocating event list from 32 to
>>> 64 entries (in ust_app_list_events() at ust-app.c:3502)
>>> DEBUG2 - 14:21:17.748623 [9524/9556]: UST app list events done (35
>>> events) (in ust_app_list_events() at ust-app.c:3543)
>>> DEBUG1 - 14:21:17.748638 [9524/9556]: Sending response (size: 20456,
>>> retcode: Success) (in thread_manage_clients() at main.c:4456)
>>> DEBUG1 - 14:21:17.748663 [9524/9556]: Clean command context structure (in
>>> clean_command_ctx() at main.c:829)
>>> DEBUG1 - 14:21:17.748670 [9524/9556]: Accepting client command ... (in
>>> thread_manage_clients() at main.c:4310)
>>> UST events:
>>> -------------
>>>
>>> PID: 11876 - Name: <process_name>
>>>       lttng_ust_cyg_profile_fast:func_exit (loglevel:
>>> TRACE_DEBUG_FUNCTION (12)) (type: tracepoint)
>>>       lttng_ust_cyg_profile_fast:func_entry (loglevel:
>>> TRACE_DEBUG_FUNCTION (12)) (type: tracepoint)
>>>       lttng_ust_cyg_profile:func_exit (loglevel: TRACE_DEBUG_FUNCTION
>>> (12)) (type: tracepoint)
>>>       lttng_ust_cyg_profile:func_entry (loglevel: TRACE_DEBUG_FUNCTION
>>> (12)) (type: tracepoint)
>>>       lttng_ust_dl:dlclose (loglevel: TRACE_DEBUG_LINE (13)) (type:
>>> tracepoint)
>>>       lttng_ust_dl:dlopen (loglevel: TRACE_DEBUG_LINE (13)) (type:
>>> tracepoint)
>>>       lttng_ust_libc:posix_memalign (loglevel: TRACE_DEBUG_LINE (13))
>>> (type: tracepoint)
>>>       lttng_ust_libc:memalign (loglevel: TRACE_DEBUG_LINE (13)) (type:
>>> tracepoint)
>>>       lttng_ust_libc:realloc (loglevel: TRACE_DEBUG_LINE (13)) (type:
>>> tracepoint)
>>>       lttng_ust_libc:calloc (loglevel: TRACE_DEBUG_LINE (13)) (type:
>>> tracepoint)
>>>       lttng_ust_libc:free (loglevel: TRACE_DEBUG_LINE (13)) (type:
>>> tracepoint)
>>>       lttng_ust_libc:malloc (loglevel: TRACE_DEBUG_LINE (13)) (type:
>>> tracepoint)
>>>       lttng_ust_pthread:pthread_mutex_unlock (loglevel: TRACE_DEBUG_LINE
>>> (13)) (type: tracepoint)
>>>       lttng_ust_pthread:pthread_mutex_trylock (loglevel: TRACE_DEBUG_LINE
>>> (13)) (type: tracepoint)
>>>       lttng_ust_pthread:pthread_mutex_lock_acq (loglevel:
>>> TRACE_DEBUG_LINE (13)) (type: tracepoint)
>>>       lttng_ust_pthread:pthread_mutex_lock_req (loglevel:
>>> TRACE_DEBUG_LINE (13)) (type: tracepoint)
>>>       lttng_ust_tracelog:TRACE_DEBUG (loglevel: TRACE_DEBUG (14)) (type:
>>> tracepoint)
>>>       lttng_ust_tracelog:TRACE_DEBUG_LINE (loglevel: TRACE_DEBUG_LINE
>>> (13)) (type: tracepoint)
>>>       lttng_ust_tracelog:TRACE_DEBUG_FUNCTION (loglevel:
>>> TRACE_DEBUG_FUNCTION (12)) (type: tracepoint)
>>>       lttng_ust_tracelog:TRACE_DEBUG_UNIT (loglevel: TRACE_DEBUG_UNIT
>>> (11)) (type: tracepoint)
>>>       lttng_ust_tracelog:TRACE_DEBUG_MODULE (loglevel: TRACE_DEBUG_MODULE
>>> (10)) (type: tracepoint)
>>>       lttng_ust_tracelog:TRACE_DEBUG_PROCESS (loglevel:
>>> TRACE_DEBUG_PROCESS (9)) (type: tracepoint)
>>>       lttng_ust_tracelog:TRACE_DEBUG_PROGRAM (loglevel:
>>> TRACE_DEBUG_PROGRAM (8)) (type: tracepoint)
>>>       lttng_ust_tracelog:TRACE_DEBUG_SYSTEM (loglevel: TRACE_DEBUG_SYSTEM
>>> (7)) (type: tracepoint)
>>>       lttng_ust_tracelog:TRACE_INFO (loglevel: TRACE_INFO (6)) (type:
>>> tracepoint)
>>>       lttng_ust_tracelog:TRACE_NOTICE (loglevel: TRACE_NOTICE (5)) (type:
>>> tracepoint)
>>>       lttng_ust_tracelog:TRACE_WARNING (loglevel: TRACE_WARNING (4))
>>> (type: tracepoint)
>>>       lttng_ust_tracelog:TRACE_ERR (loglevel: TRACE_ERR (3)) (type:
>>> tracepoint)
>>>       lttng_ust_tracelog:TRACE_CRIT (loglevel: TRACE_CRIT (2)) (type:
>>> tracepoint)
>>>       lttng_ust_tracelog:TRACE_ALERT (loglevel: TRACE_ALERT (1)) (type:
>>> tracepoint)
>>>       lttng_ust_tracelog:TRACE_EMERG (loglevel: TRACE_EMERG (0)) (type:
>>> tracepoint)
>>>       lttng_ust_tracef:event (loglevel: TRACE_DEBUG (14)) (type:
>>> tracepoint)
>>>       lttng_ust_statedump:end (loglevel: TRACE_DEBUG_LINE (13)) (type:
>>> tracepoint)
>>>       lttng_ust_statedump:soinfo (loglevel: TRACE_DEBUG_LINE (13)) (type:
>>> tracepoint)
>>>       lttng_ust_statedump:start (loglevel: TRACE_DEBUG_LINE (13)) (type:
>>> tracepoint)
>>>
>>>
>>>
>>>
>>>
>>> Kindly help us in fixing this issue.
>>>
>>>
>>>
>>>
>>> Regards,
>>> Prashanth
>>>
>>> On Mon, Feb 15, 2016 at 6:20 PM, Prashanth Raghavendra
>>> <prashanth.raghavendra at gmail.com> wrote:
>>>>
>>>> Hi Jeremie,
>>>>
>>>> Thanks for the clarification.
>>>> We will try with the latest version.
>>>>
>>>>
>>>> Regards,
>>>> Prashanth
>>>>
>>>> On Fri, Feb 12, 2016 at 10:10 PM, Jérémie Galarneau
>>>> <jeremie.galarneau at efficios.com> wrote:
>>>>>
>>>>> On Fri, Feb 12, 2016 at 8:57 AM, Prashanth Raghavendra
>>>>> <prashanth.raghavendra at gmail.com> wrote:
>>>>> > Greetings,
>>>>> >
>>>>> > We are trying to use lttng for tracing our application code
>>>>> > (userspace).
>>>>> >
>>>>> > Host OS:  WR5.0.1.13 Linux
>>>>> > Lttng-tools version 2.1.0, 32-bit  (lttng: ELF 32-bit LSB executable,
>>>>> > Intel
>>>>> > 80386)
>>>>> > Babeltrace version 1.0.0
>>>>> >
>>>>>
>>>>> Hi,
>>>>>
>>>>> Unfortunately, both of these versions have been unsupported for a long
>>>>> time.
>>>>> Let us know if the problem still occurs with the latest LTTng and
>>>>> Babeltrace releases.
>>>>>
>>>>> Regards,
>>>>> Jérémie
>>>>>
>>>>> > Logged in as root.
>>>>> >
>>>>> >
>>>>> >
>>>>> > When we start the lttng-sessiond, it gets stuck at "Accepting
>>>>> > application
>>>>> > registration”.
>>>>> >
>>>>> > Linux(debug)# /isan/lib/lttng-sessiond -vvv --no-kernel
>>>>> > DEBUG3: Creating LTTng run directory: /var/run/lttng [in
>>>>> > create_lttng_rundir() at main.c:3683]
>>>>> > DEBUG2: Kernel consumer err path: /var/run/lttng/kconsumerd/error [in
>>>>> > main()
>>>>> > at main.c:3931]
>>>>> > DEBUG2: Kernel consumer cmd path: /var/run/lttng/kconsumerd/command
>>>>> > [in
>>>>> > main() at main.c:3933]
>>>>> > DEBUG1: Client socket path /var/run/lttng/client-lttng-sessiond [in
>>>>> > main()
>>>>> > at main.c:3986]
>>>>> > DEBUG1: Application socket path /var/run/lttng/apps-lttng-sessiond
>>>>> > [in
>>>>> > main() at main.c:3987]
>>>>> > DEBUG1: LTTng run directory path: /var/run/lttng [in main() at
>>>>> > main.c:3988]
>>>>> > DEBUG2: UST consumer 32 bits err path:
>>>>> > /var/run/lttng/ustconsumerd32/error
>>>>> > [in main() at main.c:3997]
>>>>> > DEBUG2: UST consumer 32 bits cmd path:
>>>>> > /var/run/lttng/ustconsumerd32/command
>>>>> > [in main() at main.c:3999]
>>>>> > DEBUG2: UST consumer 64 bits err path:
>>>>> > /var/run/lttng/ustconsumerd64/error
>>>>> > [in main() at main.c:4008]
>>>>> > DEBUG2: UST consumer 64 bits cmd path:
>>>>> > /var/run/lttng/ustconsumerd64/command
>>>>> > [in main() at main.c:4010]
>>>>> > DEBUG3: Created hashtable size 4 at 0x88d7080 of type 1 [in
>>>>> > lttng_ht_new()
>>>>> > at hashtable.c:96]
>>>>> > DEBUG3: Created hashtable size 4 at 0x88d7370 of type 1 [in
>>>>> > lttng_ht_new()
>>>>> > at hashtable.c:96]
>>>>> > DEBUG2: Creating consumer directory: /var/run/lttng/kconsumerd [in
>>>>> > set_consumer_sockets() at main.c:3725]
>>>>> > DEBUG2: Creating consumer directory: /var/run/lttng/ustconsumerd64
>>>>> > [in
>>>>> > set_consumer_sockets() at main.c:3725]
>>>>> > DEBUG2: Creating consumer directory: /var/run/lttng/ustconsumerd32
>>>>> > [in
>>>>> > set_consumer_sockets() at main.c:3725]
>>>>> > DEBUG1: Signal handler set for SIGTERM, SIGPIPE and SIGINT [in
>>>>> > set_signal_handler() at main.c:3817]
>>>>> > DEBUG3: Session daemon client socket 8 and application socket 9
>>>>> > created [in
>>>>> > init_daemon_socket() at main.c:3587]
>>>>> > Warning: No tracing group detected
>>>>> > DEBUG1: epoll set max size is 3243642 [in compat_epoll_set_max_size()
>>>>> > at
>>>>> > compat-epoll.c:224]
>>>>> > DEBUG1: Command subsystem initialized [in cmd_init() at cmd.c:2423]
>>>>> > DEBUG1: [thread] Manage health check started [in
>>>>> > thread_manage_health() at
>>>>> > main.c:2944]
>>>>> > DEBUG1: [thread] Manage client started [in thread_manage_clients() at
>>>>> > main.c:3138]
>>>>> > DEBUG1: [thread] Dispatch UST command started [in
>>>>> > thread_dispatch_ust_registration() at main.c:1295]
>>>>> > DEBUG1: Futex n to 1 prepare done [in futex_nto1_prepare() at
>>>>> > futex.c:75]
>>>>> > DEBUG1: Woken up but nothing in the UST command queue [in
>>>>> > thread_dispatch_ust_registration() at main.c:1305]
>>>>> > DEBUG1: [thread] Manage application registration started [in
>>>>> > thread_registration_apps() at main.c:1371]
>>>>> > DEBUG1: [thread] Manage application started [in thread_manage_apps()
>>>>> > at
>>>>> > main.c:1101]
>>>>> > DEBUG1: Health check ready [in thread_manage_health() at main.c:2983]
>>>>> > DEBUG1: Accepting client command ... [in thread_manage_clients() at
>>>>> > main.c:3182]
>>>>> > DEBUG1: Notifying applications of session daemon state: 1 [in
>>>>> > notify_ust_apps() at main.c:496]
>>>>> > DEBUG1: Apps thread polling on 2 fds [in thread_manage_apps() at
>>>>> > main.c:1134]
>>>>> > DEBUG1: Got the wait shm fd 16 [in get_wait_shm() at shm.c:117]
>>>>> > DEBUG1: Futex wait update active 1 [in futex_wait_update() at
>>>>> > futex.c:63]
>>>>> > DEBUG1: Accepting application registration [in
>>>>> > thread_registration_apps() at
>>>>> > main.c:1406]  ===è Remain struck here
>>>>> >
>>>>> >
>>>>> >
>>>>> > Because of this, we suspect that the traces from our application are
>>>>> > not
>>>>> > getting generated. And we get error when we run lttng view:
>>>>> > (lttng enable-event, start etc went through fine)
>>>>> >
>>>>> > Linux(debug)# lttng stop
>>>>> > Waiting for data availability
>>>>> > Warning: Tracing already stopped for session auto-20160211-133851
>>>>> > Linux(debug)# lttng view
>>>>> > Trace directory: /home/
>>>>> >
>>>>> > [error] Cannot open any trace for reading.
>>>>> >
>>>>> > [error] opening trace “/home/" for reading.
>>>>> >
>>>>> > [error] none of the specified trace paths could be opened.
>>>>> >
>>>>> >
>>>>> >
>>>>> > Please help us in fixing this issue.
>>>>> >
>>>>> > Thank you.
>>>>> >
>>>>> >
>>>>> >
>>>>> >
>>>>> > Best Regards,
>>>>> >
>>>>> > Prashanth Raghavendra
>>>>> > Aditya Dogra
>>>>> >
>>>>> >
>>>>> >
>>>>> >
>>>>> >
>>>>> > _______________________________________________
>>>>> > lttng-dev mailing list
>>>>> > lttng-dev at lists.lttng.org
>>>>> > http://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev
>>>>> >
>>>>>
>>>>>
>>>>>
>>>>> --
>>>>> Jérémie Galarneau
>>>>> EfficiOS Inc.
>>>>> http://www.efficios.com
>>>>
>>>>
>>>
>>
>



-- 
Jérémie Galarneau
EfficiOS Inc.
http://www.efficios.com


More information about the lttng-dev mailing list