|
|
|
|
|
[SC-1:Thu Nov 22 15:12:23/cluster/temp/SDPs/EA_Nov15_NoHealthCheck] #
|
|
[SC-1:Thu Nov 22 15:12:24/cluster/temp/SDPs/EA_Nov15_NoHealthCheck] #
|
|
[SC-1:Thu Nov 22 15:12:24/cluster/temp/SDPs/EA_Nov15_NoHealthCheck] # lDEBUG1: Wait for client response [in thread_manage_clients() at main.c:3204]
|
|
DEBUG1: Receiving data from client ... [in thread_manage_clients() at main.c:3249]
|
|
DEBUG1: Nothing recv() from client... continuing [in thread_manage_clients() at main.c:3253]
|
|
DEBUG1: Clean command context structure [in clean_command_ctx() at main.c:477]
|
|
DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3162]
|
|
ttng list
|
|
DEBUG1: Wait for client response [in thread_manage_clients() at main.c:3204]
|
|
DEBUG1: Receiving data from client ... [in thread_manage_clients() at main.c:3249]
|
|
DEBUG1: Nothing recv() from client... continuing [in thread_manage_clients() at main.c:3253]
|
|
DEBUG1: Clean command context structure [in clean_command_ctx() at main.c:477]
|
|
DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3162]
|
|
DEBUG1: Wait for client response [in thread_manage_clients() at main.c:3204]
|
|
DEBUG1: Receiving data from client ... [in thread_manage_clients() at main.c:3249]
|
|
DEBUG1: Processing client command 13 [in process_client_msg() at main.c:2181]
|
|
DEBUG1: Counting number of available session for UID 0 GID 0 [in lttng_sessions_count() at main.c:2152]
|
|
DEBUG1: Getting all available session for UID 0 GID 0 [in cmd_list_lttng_sessions() at cmd.c:2111]
|
|
DEBUG1: Sending response (size: 16, retcode: Success) [in thread_manage_clients() at main.c:3300]
|
|
DEBUG1: Clean command context structure [in clean_command_ctx() at main.c:477]
|
|
DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3162]
|
|
Currently no available tracing session
|
|
[SC-1:Thu Nov 22 15:12:26/cluster/temp/SDPs/EA_Nov15_NoHealthCheck] #
|
|
[SC-1:Thu Nov 22 15:12:29/cluster/temp/SDPs/EA_Nov15_NoHealthCheck] # cheDEBUG1: Wait for client response [in thread_manage_clients() at main.c:3204]
|
|
DEBUG1: Receiving data from client ... [in thread_manage_clients() at main.c:3249]
|
|
DEBUG1: Nothing recv() from client... continuing [in thread_manage_clients() at main.c:3253]
|
|
DEBUG1: Clean command context structure [in clean_command_ctx() at main.c:477]
|
|
DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3162]
|
|
ckps
|
|
311 pts/1 00:00:00 lttng-consumerd
|
|
20711 ? 00:00:15 TraceEa
|
|
20723 ? 00:00:01 TraceEa
|
|
32601 pts/1 00:00:00 lttng-sessiond
|
|
32726 pts/1 00:00:04 TestApp_type1
|
|
32727 pts/1 00:00:05 TestApp_Thread1
|
|
[SC-1:Thu Nov 22 15:12:30/cluster/temp/SDPs/EA_Nov15_NoHealthCheck] # DEBUG1: Wait for client response [in thread_manage_clients() at main.c:3204]
|
|
DEBUG1: Receiving data from client ... [in thread_manage_clients() at main.c:3249]
|
|
DEBUG1: Nothing recv() from client... continuing [in thread_manage_clients() at main.c:3253]
|
|
DEBUG1: Clean command context structure [in clean_command_ctx() at main.c:477]
|
|
DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3162]
|
|
DEBUG1: Wait for client response [in thread_manage_clients() at main.c:3204]
|
|
DEBUG1: Receiving data from client ... [in thread_manage_clients() at main.c:3249]
|
|
DEBUG1: Nothing recv() from client... continuing [in thread_manage_clients() at main.c:3253]
|
|
DEBUG1: Clean command context structure [in clean_command_ctx() at main.c:477]
|
|
DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3162]
|
|
DEBUG1: Wait for client response [in thread_manage_clients() at main.c:3204]
|
|
DEBUG1: Receiving data from client ... [in thread_manage_clients() at main.c:3249]
|
|
DEBUG1: Nothing recv() from client... continuing [in thread_manage_clients() at main.c:3253]
|
|
DEBUG1: Clean command context structure [in clean_command_ctx() at main.c:477]
|
|
DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3162]
|
|
|
|
[SC-1:Thu Nov 22 15:12:45/cluster/temp/SDPs/EA_Nov15_NoHealthCheck] # lttng create s1
|
|
DEBUG1: Wait for client response [in thread_manage_clients() at main.c:3204]
|
|
DEBUG1: Receiving data from client ... [in thread_manage_clients() at main.c:3249]
|
|
DEBUG1: Nothing recv() from client... continuing [in thread_manage_clients() at main.c:3253]
|
|
DEBUG1: Clean command context structure [in clean_command_ctx() at main.c:477]
|
|
DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3162]
|
|
DEBUG1: Wait for client response [in thread_manage_clients() at main.c:3204]
|
|
DEBUG1: Receiving data from client ... [in thread_manage_clients() at main.c:3249]
|
|
DEBUG1: Processing client command 8 [in process_client_msg() at main.c:2181]
|
|
DEBUG1: Waiting for 1 URIs from client ... [in process_client_msg() at main.c:2689]
|
|
DEBUG2: Trying to find session by name s1 [in session_find_by_name() at session.c:122]
|
|
DEBUG1: Tracing session s1 created in (null) with ID 1 by UID 0 GID 0 [in session_create() at session.c:236]
|
|
DEBUG2: Trying to find session by name s1 [in session_find_by_name() at session.c:122]
|
|
DEBUG3: Created hashtable size 4 at 0x7fa7d4004bb0 of type 1 [in lttng_ht_new() at hashtable.c:96]
|
|
DEBUG2: Setting trace directory path from URI to /root/lttng-traces/s1-20121122-151246 [in add_uri_to_consumer() at cmd.c:407]
|
|
DEBUG1: Sending response (size: 16, retcode: Success) [in thread_manage_clients() at main.c:3300]
|
|
DEBUG1: Clean command context structure [in clean_command_ctx() at main.c:477]
|
|
DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3162]
|
|
Session s1 created.
|
|
Traces will be written in /root/lttng-traces/s1-20121122-151246
|
|
[SC-1:Thu Nov 22 15:12:46/cluster/temp/SDPs/EA_Nov15_NoHealthCheck] # sleep 1
|
|
lttng enable-event com_ericsson_cba_trace_testapp_lowtraf:OnePerSecB -u
|
|
sleep 1
|
|
lttng start
|
|
sleep 5
|
|
pkill -STOP TestApp_type1
|
|
sleep 1
|
|
date; lttng create s2
|
|
for a in $(seq 1 2); do (echo " "; echo "lttng enable-channel channel0 -s s2 -u"; date +%T.%N; time lttng enable-channel channel0 -s s2 -u; date +%T.%N; sleep 1); done
|
|
[SC-1:Thu Nov 22 15:12:47/cluster/temp/SDPs/EA_Nov15_NoHealthCheck] # lttng enable-event com_ericsson_cba_trace_testapp_lowtraf:OnePerSecB -u
|
|
DEBUG1: Wait for client response [in thread_manage_clients() at main.c:3204]
|
|
DEBUG1: Receiving data from client ... [in thread_manage_clients() at main.c:3249]
|
|
DEBUG1: Nothing recv() from client... continuing [in thread_manage_clients() at main.c:3253]
|
|
DEBUG1: Clean command context structure [in clean_command_ctx() at main.c:477]
|
|
DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3162]
|
|
DEBUG1: Wait for client response [in thread_manage_clients() at main.c:3204]
|
|
DEBUG1: Receiving data from client ... [in thread_manage_clients() at main.c:3249]
|
|
DEBUG1: Processing client command 6 [in process_client_msg() at main.c:2181]
|
|
DEBUG1: Getting session s1 by name [in process_client_msg() at main.c:2252]
|
|
DEBUG2: Trying to find session by name s1 [in session_find_by_name() at session.c:122]
|
|
DEBUG1: Creating UST session [in create_ust_session() at main.c:2068]
|
|
DEBUG3: Created hashtable size 4 at 0x7fa7d4003bd0 of type 1 [in lttng_ht_new() at hashtable.c:96]
|
|
DEBUG3: Created hashtable size 4 at 0x7fa7d4004110 of type 1 [in lttng_ht_new() at hashtable.c:96]
|
|
DEBUG3: Created hashtable size 4 at 0x7fa7d4004650 of type 0 [in lttng_ht_new() at hashtable.c:96]
|
|
DEBUG3: Created hashtable size 4 at 0x7fa7d4010480 of type 1 [in lttng_ht_new() at hashtable.c:96]
|
|
DEBUG2: UST trace session create successful [in trace_ust_create_session() at trace-ust.c:143]
|
|
DEBUG3: Copying tracing session consumer output in UST session [in copy_session_consumer() at main.c:2020]
|
|
DEBUG3: Created hashtable size 4 at 0x7fa7d4010480 of type 1 [in lttng_ht_new() at hashtable.c:96]
|
|
DEBUG3: Copy session consumer subdir /ust [in copy_session_consumer() at main.c:2038]
|
|
DEBUG3: Consumer socket created (fd: 25) and added to output [in consumer_create_socket() at consumer.c:141]
|
|
DEBUG2: Trace UST channel channel0 not found by name [in trace_ust_find_channel_by_name() at trace-ust.c:52]
|
|
DEBUG1: Enabling channel channel0 for session s1 [in cmd_enable_channel() at cmd.c:822]
|
|
DEBUG2: Trace UST channel channel0 not found by name [in trace_ust_find_channel_by_name() at trace-ust.c:52]
|
|
DEBUG3: Created hashtable size 4 at 0x7fa7d4011ed0 of type 0 [in lttng_ht_new() at hashtable.c:96]
|
|
DEBUG3: Created hashtable size 4 at 0x7fa7d4012410 of type 1 [in lttng_ht_new() at hashtable.c:96]
|
|
DEBUG2: Trace UST channel channel0 created [in trace_ust_create_channel() at trace-ust.c:207]
|
|
DEBUG2: Channel channel0 being created in UST global domain [in channel_ust_create() at channel.c:273]
|
|
DEBUG2: UST app adding channel channel0 to global domain for session id 1 [in ust_app_create_channel_glb() at ust-app.c:1994]
|
|
DEBUG2: UST app pid: 32726 session id 1 not found, creating it [in create_ust_app_session() at ust-app.c:961]
|
|
DEBUG3: Created hashtable size 4 at 0x7fa7d4013990 of type 0 [in lttng_ht_new() at hashtable.c:96]
|
|
DEBUG2: Shadow copy of session handle -1 [in shadow_copy_session() at ust-app.c:870]
|
|
DEBUG2: UST app session created successfully with handle 9 [in create_ust_app_session() at ust-app.c:988]
|
|
DEBUG3: Created hashtable size 4 at 0x7fa7d4014d00 of type 1 [in lttng_ht_new() at hashtable.c:96]
|
|
DEBUG3: Created hashtable size 4 at 0x7fa7d40151b0 of type 0 [in lttng_ht_new() at hashtable.c:96]
|
|
DEBUG3: UST app channel channel0 allocated [in alloc_ust_app_channel() at ust-app.c:302]
|
|
DEBUG2: UST app shadow copy of channel channel0 started [in shadow_copy_channel() at ust-app.c:810]
|
|
DEBUG3: UST app shadow copy of channel channel0 done [in shadow_copy_channel() at ust-app.c:847]
|
|
DEBUG2: UST app channel channel0 created successfully for pid:32726 and sock:20 [in create_ust_channel() at ust-app.c:683]
|
|
DEBUG2: UST app create channel channel0 for PID 32726 completed [in create_ust_app_channel() at ust-app.c:1233]
|
|
DEBUG2: UST app pid: 32727 session id 1 not found, creating it [in create_ust_app_session() at ust-app.c:961]
|
|
DEBUG3: Created hashtable size 4 at 0x7fa7d4016800 of type 0 [in lttng_ht_new() at hashtable.c:96]
|
|
DEBUG2: Shadow copy of session handle -1 [in shadow_copy_session() at ust-app.c:870]
|
|
DEBUG2: UST app session created successfully with handle 2 [in create_ust_app_session() at ust-app.c:988]
|
|
DEBUG3: Created hashtable size 4 at 0x7fa7d4016f90 of type 1 [in lttng_ht_new() at hashtable.c:96]
|
|
DEBUG3: Created hashtable size 4 at 0x7fa7d40174d0 of type 0 [in lttng_ht_new() at hashtable.c:96]
|
|
DEBUG3: UST app channel channel0 allocated [in alloc_ust_app_channel() at ust-app.c:302]
|
|
DEBUG2: UST app shadow copy of channel channel0 started [in shadow_copy_channel() at ust-app.c:810]
|
|
DEBUG3: UST app shadow copy of channel channel0 done [in shadow_copy_channel() at ust-app.c:847]
|
|
DEBUG2: UST app channel channel0 created successfully for pid:32727 and sock:21 [in create_ust_channel() at ust-app.c:683]
|
|
DEBUG2: UST app create channel channel0 for PID 32727 completed [in create_ust_app_channel() at ust-app.c:1233]
|
|
DEBUG2: Channel channel0 created successfully [in channel_ust_create() at channel.c:298]
|
|
DEBUG2: Trace UST channel channel0 found by name [in trace_ust_find_channel_by_name() at trace-ust.c:47]
|
|
DEBUG2: Trace UST event NOT found by name com_ericsson_cba_trace_testapp_lowtraf:OnePerSecB [in trace_ust_find_event_by_name() at trace-ust.c:79]
|
|
DEBUG3: Created hashtable size 4 at 0x7fa7d4017db0 of type 1 [in lttng_ht_new() at hashtable.c:96]
|
|
DEBUG2: Trace UST event com_ericsson_cba_trace_testapp_lowtraf:OnePerSecB, loglevel (0,-1) created [in trace_ust_create_event() at trace-ust.c:286]
|
|
DEBUG1: UST app creating event com_ericsson_cba_trace_testapp_lowtraf:OnePerSecB for all apps for session id 1 [in ust_app_create_event_glb() at ust-app.c:2119]
|
|
DEBUG3: Created hashtable size 4 at 0x7fa7d4018430 of type 1 [in lttng_ht_new() at hashtable.c:96]
|
|
DEBUG3: UST app event com_ericsson_cba_trace_testapp_lowtraf:OnePerSecB allocated [in alloc_ust_app_event() at ust-app.c:337]
|
|
DEBUG2: UST app event com_ericsson_cba_trace_testapp_lowtraf:OnePerSecB created successfully for pid:32726 [in create_ust_event() at ust-app.c:723]
|
|
DEBUG2: UST app create event com_ericsson_cba_trace_testapp_lowtraf:OnePerSecB for PID 32726 completed [in create_ust_app_event() at ust-app.c:1284]
|
|
DEBUG3: Created hashtable size 4 at 0x7fa7d4018e40 of type 1 [in lttng_ht_new() at hashtable.c:96]
|
|
DEBUG3: UST app event com_ericsson_cba_trace_testapp_lowtraf:OnePerSecB allocated [in alloc_ust_app_event() at ust-app.c:337]
|
|
DEBUG2: UST app event com_ericsson_cba_trace_testapp_lowtraf:OnePerSecB created successfully for pid:32727 [in create_ust_event() at ust-app.c:723]
|
|
DEBUG2: UST app create event com_ericsson_cba_trace_testapp_lowtraf:OnePerSecB for PID 32727 completed [in create_ust_app_event() at ust-app.c:1284]
|
|
DEBUG1: Event UST com_ericsson_cba_trace_testapp_lowtraf:OnePerSecB created in channel channel0 [in event_ust_enable_tracepoint() at event.c:486]
|
|
DEBUG1: Sending response (size: 16, retcode: Success) [in thread_manage_clients() at main.c:3300]
|
|
DEBUG1: Clean command context structure [in clean_command_ctx() at main.c:477]
|
|
DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3162]
|
|
UST event com_ericsson_cba_trace_testapp_lowtraf:OnePerSecB created in channel channel0
|
|
[SC-1:Thu Nov 22 15:12:47/cluster/temp/SDPs/EA_Nov15_NoHealthCheck] # sleep 1
|
|
[SC-1:Thu Nov 22 15:12:48/cluster/temp/SDPs/EA_Nov15_NoHealthCheck] # lttng start
|
|
DEBUG1: Wait for client response [in thread_manage_clients() at main.c:3204]
|
|
DEBUG1: Receiving data from client ... [in thread_manage_clients() at main.c:3249]
|
|
DEBUG1: Nothing recv() from client... continuing [in thread_manage_clients() at main.c:3253]
|
|
DEBUG1: Clean command context structure [in clean_command_ctx() at main.c:477]
|
|
DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3162]
|
|
DEBUG1: Wait for client response [in thread_manage_clients() at main.c:3204]
|
|
DEBUG1: Receiving data from client ... [in thread_manage_clients() at main.c:3249]
|
|
DEBUG1: Processing client command 16 [in process_client_msg() at main.c:2181]
|
|
DEBUG1: Getting session s1 by name [in process_client_msg() at main.c:2252]
|
|
DEBUG2: Trying to find session by name s1 [in session_find_by_name() at session.c:122]
|
|
DEBUG2: Setting relayd for session s1 [in setup_relayd() at cmd.c:643]
|
|
DEBUG1: Starting all UST traces [in ust_app_start_trace_all() at ust-app.c:2462]
|
|
DEBUG1: Starting tracing for ust app pid 32726 [in ust_app_start_trace() at ust-app.c:2173]
|
|
DEBUG3: mkdir() recursive /root/lttng-traces/s1-20121122-151246 with mode 504 for uid 0 and gid 0 [in run_as_mkdir_recursive() at runas.c:342]
|
|
DEBUG1: Using run_as_clone [in run_as() at runas.c:325]
|
|
DEBUG2: UST metadata opened for app pid 32726 [in create_ust_app_metadata() at ust-app.c:1325]
|
|
DEBUG2: UST metadata stream object created for app pid 32726 [in create_ust_app_metadata() at ust-app.c:1343]
|
|
DEBUG2: UST stream 1 ready (handle: 6) [in ust_app_start_trace() at ust-app.c:2263]
|
|
DEBUG2: UST stream 2 ready (handle: 5) [in ust_app_start_trace() at ust-app.c:2263]
|
|
DEBUG2: UST stream 3 ready (handle: 4) [in ust_app_start_trace() at ust-app.c:2263]
|
|
DEBUG2: UST stream 4 ready (handle: 3) [in ust_app_start_trace() at ust-app.c:2263]
|
|
DEBUG1: Sending metadata stream fd to consumer on 25 [in ust_consumer_send_session() at ust-consumer.c:303]
|
|
DEBUG1: UST consumer sending metadata stream fd [in send_metadata() at ust-consumer.c:206]
|
|
DEBUG3: mkdir() recursive /root/lttng-traces/s1-20121122-151246//ust/TestApp_type1-32726-20121122-151247/ with mode 504 for uid 0 and gid 0 [in run_as_mkdir_recursive() at runas.c:342]
|
|
DEBUG1: Using run_as_clone [in run_as() at runas.c:325]
|
|
DEBUG1: Incoming command on sock [in consumer_thread_sessiond_poll() at consumer.c:2505]
|
|
DEBUG1: UST Consumer adding channel [in lttng_ustconsumer_recv_cmd() at ust-consumer.c:134]
|
|
DEBUG1: consumer_add_channel 30 [in lttng_ustconsumer_recv_cmd() at ust-consumer.c:148]
|
|
DEBUG1: Allocated channel (key 30, shm_fd -1, wait_fd -1, mmap_len 768, max_sb_size 4096) [in consumer_allocate_channel() at consumer.c:851]
|
|
DEBUG1: received fds on sock [in consumer_thread_sessiond_poll() at consumer.c:2523]
|
|
DEBUG1: Sending streams of channel channel0 to UST consumer [in send_channel_streams() at ust-consumer.c:131]
|
|
DEBUG2: Sending channel channel0 to UST consumer [in send_channel() at ust-consumer.c:48]
|
|
DEBUG3: UST local consumer tracefile path: /root/lttng-traces/s1-20121122-151246//ust/TestApp_type1-32726-20121122-151247/ [in send_channel_streams() at ust-consumer.c:148]
|
|
DEBUG2: Sending stream 34 of channel channel0 to kernel consumer [in send_channel_stream() at ust-consumer.c:90]
|
|
DEBUG2: Sending stream 36 of channel channel0 to kernel consumer [in send_channel_stream() at ust-consumer.c:90]
|
|
DEBUG2: Sending stream 38 of channel channel0 to kernel consumer [in send_channel_stream() at ust-consumer.c:90]
|
|
DEBUG2: Sending stream 40 of channel channel0 to kernel consumer [in send_channel_stream() at ust-consumer.c:90]
|
|
DEBUG1: UST consumer channel streams sent [in send_channel_streams() at ust-consumer.c:172]
|
|
DEBUG1: consumer fds (metadata and channel streams) sent [in ust_consumer_send_session() at ust-consumer.c:333]
|
|
DEBUG1: Incoming command on sock [in consumer_thread_sessiond_poll() at consumer.c:2505]
|
|
DEBUG1: UST Consumer adding stream [in lttng_ustconsumer_recv_cmd() at ust-consumer.c:179]
|
|
DEBUG1: Consumer command ADD_STREAM chan 30 stream 32 [in lttng_ustconsumer_recv_cmd() at ust-consumer.c:194]
|
|
DEBUG3: Allocated stream /root/lttng-traces/s1-20121122-151246//ust/TestApp_type1-32726-20121122-151247//metadata (key 32, shm_fd 20, wait_fd 21, mmap_len 13056, out_fd -1, net_seq_idx -1, session_id 1 [in consumer_allocate_stream() at consumer.c:536]
|
|
DEBUG3: open() /root/lttng-traces/s1-20121122-151246//ust/TestApp_type1-32726-20121122-151247//metadata with flags 241 mode 511 for uid 0 and gid 0 [in run_as_open() at runas.c:370]
|
|
DEBUG1: Using run_as_clone [in run_as() at runas.c:325]
|
|
DEBUG1: Starting tracing for ust app pid 32727 [in ust_app_start_trace() at ust-app.c:2173]
|
|
DEBUG3: mkdir() recursive /root/lttng-traces/s1-20121122-151246 with mode 504 for uid 0 and gid 0 [in run_as_mkdir_recursive() at runas.c:342]
|
|
DEBUG1: Using run_as_clone [in run_as() at runas.c:325]
|
|
DEBUG1: UST consumer ADD_STREAM /root/lttng-traces/s1-20121122-151246//ust/TestApp_type1-32726-20121122-151247//metadata (20,21) with relayd id 0 [in lttng_ustconsumer_recv_cmd() at ust-consumer.c:277]
|
|
DEBUG1: received fds on sock [in consumer_thread_sessiond_poll() at consumer.c:2523]
|
|
DEBUG1: Metadata event catched in thread [in consumer_thread_metadata_poll() at consumer.c:2030]
|
|
DEBUG1: Adding metadata stream 21 to poll set [in consumer_thread_metadata_poll() at consumer.c:2082]
|
|
DEBUG3: Adding metadata stream 21 to hash table [in consumer_add_metadata_stream() at consumer.c:1882]
|
|
DEBUG1: Metadata poll wait with 2 fd(s) [in consumer_thread_metadata_poll() at consumer.c:2028]
|
|
DEBUG1: Incoming command on sock [in consumer_thread_sessiond_poll() at consumer.c:2505]
|
|
DEBUG1: UST Consumer adding channel [in lttng_ustconsumer_recv_cmd() at ust-consumer.c:134]
|
|
DEBUG1: consumer_add_channel 26 [in lttng_ustconsumer_recv_cmd() at ust-consumer.c:148]
|
|
DEBUG1: Allocated channel (key 26, shm_fd -1, wait_fd -1, mmap_len 816, max_sb_size 4096) [in consumer_allocate_channel() at consumer.c:851]
|
|
DEBUG1: received fds on sock [in consumer_thread_sessiond_poll() at consumer.c:2523]
|
|
DEBUG1: Incoming command on sock [in consumer_thread_sessiond_poll() at consumer.c:2505]
|
|
DEBUG1: UST Consumer adding stream [in lttng_ustconsumer_recv_cmd() at ust-consumer.c:179]
|
|
DEBUG1: Consumer command ADD_STREAM chan 26 stream 34 [in lttng_ustconsumer_recv_cmd() at ust-consumer.c:194]
|
|
DEBUG3: Allocated stream /root/lttng-traces/s1-20121122-151246//ust/TestApp_type1-32726-20121122-151247//channel0_0 (key 34, shm_fd 20, wait_fd 22, mmap_len 21888, out_fd -1, net_seq_idx -1, session_id 1 [in consumer_allocate_stream() at consumer.c:536]
|
|
DEBUG3: open() /root/lttng-traces/s1-20121122-151246//ust/TestApp_type1-32726-20121122-151247//channel0_0 with flags 241 mode 511 for uid 0 and gid 0 [in run_as_open() at runas.c:370]
|
|
DEBUG1: Using run_as_clone [in run_as() at runas.c:325]
|
|
DEBUG2: UST metadata opened for app pid 32727 [in create_ust_app_metadata() at ust-app.c:1325]
|
|
DEBUG2: UST metadata stream object created for app pid 32727 [in create_ust_app_metadata() at ust-app.c:1343]
|
|
DEBUG2: UST stream 1 ready (handle: 7) [in ust_app_start_trace() at ust-app.c:2263]
|
|
DEBUG2: UST stream 2 ready (handle: 6) [in ust_app_start_trace() at ust-app.c:2263]
|
|
DEBUG2: UST stream 3 ready (handle: 4) [in ust_app_start_trace() at ust-app.c:2263]
|
|
DEBUG2: UST stream 4 ready (handle: 5) [in ust_app_start_trace() at ust-app.c:2263]
|
|
DEBUG1: Sending metadata stream fd to consumer on 25 [in ust_consumer_send_session() at ust-consumer.c:303]
|
|
DEBUG1: UST consumer sending metadata stream fd [in send_metadata() at ust-consumer.c:206]
|
|
DEBUG3: mkdir() recursive /root/lttng-traces/s1-20121122-151246//ust/TestApp_Thread1-32727-20121122-151247/ with mode 504 for uid 0 and gid 0 [in run_as_mkdir_recursive() at runas.c:342]
|
|
DEBUG1: Using run_as_clone [in run_as() at runas.c:325]
|
|
DEBUG1: UST consumer ADD_STREAM /root/lttng-traces/s1-20121122-151246//ust/TestApp_type1-32726-20121122-151247//channel0_0 (20,22) with relayd id 0 [in lttng_ustconsumer_recv_cmd() at ust-consumer.c:277]
|
|
DEBUG1: received fds on sock [in consumer_thread_sessiond_poll() at consumer.c:2523]
|
|
DEBUG1: Incoming command on sock [in consumer_thread_sessiond_poll() at consumer.c:2505]
|
|
DEBUG1: UST Consumer adding stream [in lttng_ustconsumer_recv_cmd() at ust-consumer.c:179]
|
|
DEBUG1: Consumer command ADD_STREAM chan 26 stream 36 [in lttng_ustconsumer_recv_cmd() at ust-consumer.c:194]
|
|
DEBUG3: Allocated stream /root/lttng-traces/s1-20121122-151246//ust/TestApp_type1-32726-20121122-151247//channel0_1 (key 36, shm_fd 20, wait_fd 23, mmap_len 21888, out_fd -1, net_seq_idx -1, session_id 1 [in consumer_allocate_stream() at consumer.c:536]
|
|
DEBUG3: open() /root/lttng-traces/s1-20121122-151246//ust/TestApp_type1-32726-20121122-151247//channel0_1 with flags 241 mode 511 for uid 0 and gid 0 [in run_as_open() at runas.c:370]
|
|
DEBUG1: Using run_as_clone [in run_as() at runas.c:325]
|
|
DEBUG1: poll num_rdy : 1 [in consumer_thread_data_poll() at consumer.c:2251]
|
|
DEBUG1: consumer_data_pipe wake up [in consumer_thread_data_poll() at consumer.c:2275]
|
|
DEBUG3: Adding consumer stream 34 [in consumer_add_stream() at consumer.c:557]
|
|
DEBUG1: Updating poll fd array [in consumer_update_poll_array() at consumer.c:901]
|
|
DEBUG1: Active FD 22 [in consumer_update_poll_array() at consumer.c:917]
|
|
DEBUG1: polling on 2 fd [in consumer_thread_data_poll() at consumer.c:2249]
|
|
DEBUG1: Sending streams of channel channel0 to UST consumer [in send_channel_streams() at ust-consumer.c:131]
|
|
DEBUG2: Sending channel channel0 to UST consumer [in send_channel() at ust-consumer.c:48]
|
|
DEBUG3: UST local consumer tracefile path: /root/lttng-traces/s1-20121122-151246//ust/TestApp_Thread1-32727-20121122-151247/ [in send_channel_streams() at ust-consumer.c:148]
|
|
DEBUG2: Sending stream 46 of channel channel0 to kernel consumer [in send_channel_stream() at ust-consumer.c:90]
|
|
DEBUG2: Sending stream 48 of channel channel0 to kernel consumer [in send_channel_stream() at ust-consumer.c:90]
|
|
DEBUG2: Sending stream 50 of channel channel0 to kernel consumer [in send_channel_stream() at ust-consumer.c:90]
|
|
DEBUG2: Sending stream 52 of channel channel0 to kernel consumer [in send_channel_stream() at ust-consumer.c:90]
|
|
DEBUG1: UST consumer channel streams sent [in send_channel_streams() at ust-consumer.c:172]
|
|
DEBUG1: consumer fds (metadata and channel streams) sent [in ust_consumer_send_session() at ust-consumer.c:333]
|
|
DEBUG1: Sending response (size: 16, retcode: Success) [in thread_manage_clients() at main.c:3300]
|
|
DEBUG1: Clean command context structure [in clean_command_ctx() at main.c:477]
|
|
DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3162]
|
|
Tracing started for session s1
|
|
DEBUG1: UST consumer ADD_STREAM /root/lttng-traces/s1-20121122-151246//ust/TestApp_type1-32726-20121122-151247//channel0_1 (20,23) with relayd id 0 [in lttng_ustconsumer_recv_cmd() at ust-consumer.c:277]
|
|
DEBUG1: received fds on sock [in consumer_thread_sessiond_poll() at consumer.c:2523]
|
|
DEBUG1: Incoming command on sock [in consumer_thread_sessiond_poll() at consumer.c:2505]
|
|
DEBUG1: UST Consumer adding stream [in lttng_ustconsumer_recv_cmd() at ust-consumer.c:179]
|
|
DEBUG1: Consumer command ADD_STREAM chan 26 stream 38 [in lttng_ustconsumer_recv_cmd() at ust-consumer.c:194]
|
|
DEBUG3: Allocated stream /root/lttng-traces/s1-20121122-151246//ust/TestApp_type1-32726-20121122-151247//channel0_2 (key 38, shm_fd 20, wait_fd 25, mmap_len 21888, out_fd -1, net_seq_idx -1, session_id 1 [in consumer_allocate_stream() at consumer.c:536]
|
|
DEBUG3: open() /root/lttng-traces/s1-20121122-151246//ust/TestApp_type1-32726-20121122-151247//channel0_2 with flags 241 mode 511 for uid 0 and gid 0 [in run_as_open() at runas.c:370]
|
|
DEBUG1: Using run_as_clone [in run_as() at runas.c:325]
|
|
DEBUG1: poll num_rdy : 1 [in consumer_thread_data_poll() at consumer.c:2251]
|
|
DEBUG1: consumer_data_pipe wake up [in consumer_thread_data_poll() at consumer.c:2275]
|
|
DEBUG3: Adding consumer stream 36 [in consumer_add_stream() at consumer.c:557]
|
|
DEBUG1: Updating poll fd array [in consumer_update_poll_array() at consumer.c:901]
|
|
DEBUG1: Active FD 22 [in consumer_update_poll_array() at consumer.c:917]
|
|
DEBUG1: Active FD 23 [in consumer_update_poll_array() at consumer.c:917]
|
|
DEBUG1: polling on 3 fd [in consumer_thread_data_poll() at consumer.c:2249]
|
|
[SC-1:Thu Nov 22 15:12:48/cluster/temp/SDPs/EA_Nov15_NoHealthCheck] # sleep 5
|
|
DEBUG1: UST consumer ADD_STREAM /root/lttng-traces/s1-20121122-151246//ust/TestApp_type1-32726-20121122-151247//channel0_2 (20,25) with relayd id 0 [in lttng_ustconsumer_recv_cmd() at ust-consumer.c:277]
|
|
DEBUG1: received fds on sock [in consumer_thread_sessiond_poll() at consumer.c:2523]
|
|
DEBUG1: Incoming command on sock [in consumer_thread_sessiond_poll() at consumer.c:2505]
|
|
DEBUG1: UST Consumer adding stream [in lttng_ustconsumer_recv_cmd() at ust-consumer.c:179]
|
|
DEBUG1: Consumer command ADD_STREAM chan 26 stream 40 [in lttng_ustconsumer_recv_cmd() at ust-consumer.c:194]
|
|
DEBUG3: Allocated stream /root/lttng-traces/s1-20121122-151246//ust/TestApp_type1-32726-20121122-151247//channel0_3 (key 40, shm_fd 20, wait_fd 27, mmap_len 21888, out_fd -1, net_seq_idx -1, session_id 1 [in consumer_allocate_stream() at consumer.c:536]
|
|
DEBUG3: open() /root/lttng-traces/s1-20121122-151246//ust/TestApp_type1-32726-20121122-151247//channel0_3 with flags 241 mode 511 for uid 0 and gid 0 [in run_as_open() at runas.c:370]
|
|
DEBUG1: Using run_as_clone [in run_as() at runas.c:325]
|
|
DEBUG1: poll num_rdy : 1 [in consumer_thread_data_poll() at consumer.c:2251]
|
|
DEBUG1: consumer_data_pipe wake up [in consumer_thread_data_poll() at consumer.c:2275]
|
|
DEBUG3: Adding consumer stream 38 [in consumer_add_stream() at consumer.c:557]
|
|
DEBUG1: Updating poll fd array [in consumer_update_poll_array() at consumer.c:901]
|
|
DEBUG1: Active FD 25 [in consumer_update_poll_array() at consumer.c:917]
|
|
DEBUG1: Active FD 22 [in consumer_update_poll_array() at consumer.c:917]
|
|
DEBUG1: Active FD 23 [in consumer_update_poll_array() at consumer.c:917]
|
|
DEBUG1: polling on 4 fd [in consumer_thread_data_poll() at consumer.c:2249]
|
|
DEBUG1: UST consumer ADD_STREAM /root/lttng-traces/s1-20121122-151246//ust/TestApp_type1-32726-20121122-151247//channel0_3 (20,27) with relayd id 0 [in lttng_ustconsumer_recv_cmd() at ust-consumer.c:277]
|
|
DEBUG1: poll num_rdy : 1 [in consumer_thread_data_poll() at consumer.c:2251]
|
|
DEBUG1: consumer_data_pipe wake up [in consumer_thread_data_poll() at consumer.c:2275]
|
|
DEBUG1: received fds on sock [in consumer_thread_sessiond_poll() at consumer.c:2523]
|
|
DEBUG1: Incoming command on sock [in consumer_thread_sessiond_poll() at consumer.c:2505]
|
|
DEBUG1: UST Consumer adding channel [in lttng_ustconsumer_recv_cmd() at ust-consumer.c:134]
|
|
DEBUG3: Adding consumer stream 40 [in consumer_add_stream() at consumer.c:557]
|
|
DEBUG1: Updating poll fd array [in consumer_update_poll_array() at consumer.c:901]
|
|
DEBUG1: Active FD 25 [in consumer_update_poll_array() at consumer.c:917]
|
|
DEBUG1: Active FD 22 [in consumer_update_poll_array() at consumer.c:917]
|
|
DEBUG1: Active FD 27 [in consumer_update_poll_array() at consumer.c:917]
|
|
DEBUG1: Active FD 23 [in consumer_update_poll_array() at consumer.c:917]
|
|
DEBUG1: polling on 5 fd [in consumer_thread_data_poll() at consumer.c:2249]
|
|
DEBUG1: consumer_add_channel 42 [in lttng_ustconsumer_recv_cmd() at ust-consumer.c:148]
|
|
DEBUG1: Allocated channel (key 42, shm_fd -1, wait_fd -1, mmap_len 768, max_sb_size 4096) [in consumer_allocate_channel() at consumer.c:851]
|
|
DEBUG1: received fds on sock [in consumer_thread_sessiond_poll() at consumer.c:2523]
|
|
DEBUG1: Incoming command on sock [in consumer_thread_sessiond_poll() at consumer.c:2505]
|
|
DEBUG1: UST Consumer adding stream [in lttng_ustconsumer_recv_cmd() at ust-consumer.c:179]
|
|
DEBUG1: Consumer command ADD_STREAM chan 42 stream 44 [in lttng_ustconsumer_recv_cmd() at ust-consumer.c:194]
|
|
DEBUG3: Allocated stream /root/lttng-traces/s1-20121122-151246//ust/TestApp_Thread1-32727-20121122-151247//metadata (key 44, shm_fd 20, wait_fd 29, mmap_len 13056, out_fd -1, net_seq_idx -1, session_id 1 [in consumer_allocate_stream() at consumer.c:536]
|
|
DEBUG3: open() /root/lttng-traces/s1-20121122-151246//ust/TestApp_Thread1-32727-20121122-151247//metadata with flags 241 mode 511 for uid 0 and gid 0 [in run_as_open() at runas.c:370]
|
|
DEBUG1: Using run_as_clone [in run_as() at runas.c:325]
|
|
DEBUG1: UST consumer ADD_STREAM /root/lttng-traces/s1-20121122-151246//ust/TestApp_Thread1-32727-20121122-151247//metadata (20,29) with relayd id 0 [in lttng_ustconsumer_recv_cmd() at ust-consumer.c:277]
|
|
DEBUG1: received fds on sock [in consumer_thread_sessiond_poll() at consumer.c:2523]
|
|
DEBUG1: Metadata event catched in thread [in consumer_thread_metadata_poll() at consumer.c:2030]
|
|
DEBUG1: Adding metadata stream 29 to poll set [in consumer_thread_metadata_poll() at consumer.c:2082]
|
|
DEBUG3: Adding metadata stream 29 to hash table [in consumer_add_metadata_stream() at consumer.c:1882]
|
|
DEBUG1: Incoming command on sock [in consumer_thread_sessiond_poll() at consumer.c:2505]
|
|
DEBUG1: UST Consumer adding channel [in lttng_ustconsumer_recv_cmd() at ust-consumer.c:134]
|
|
DEBUG1: consumer_add_channel 28 [in lttng_ustconsumer_recv_cmd() at ust-consumer.c:148]
|
|
DEBUG1: Allocated channel (key 28, shm_fd -1, wait_fd -1, mmap_len 816, max_sb_size 4096) [in consumer_allocate_channel() at consumer.c:851]
|
|
DEBUG1: received fds on sock [in consumer_thread_sessiond_poll() at consumer.c:2523]
|
|
DEBUG1: Incoming command on sock [in consumer_thread_sessiond_poll() at consumer.c:2505]
|
|
DEBUG1: UST Consumer adding stream [in lttng_ustconsumer_recv_cmd() at ust-consumer.c:179]
|
|
DEBUG1: Consumer command ADD_STREAM chan 28 stream 46 [in lttng_ustconsumer_recv_cmd() at ust-consumer.c:194]
|
|
DEBUG3: Allocated stream /root/lttng-traces/s1-20121122-151246//ust/TestApp_Thread1-32727-20121122-151247//channel0_0 (key 46, shm_fd 20, wait_fd 31, mmap_len 21888, out_fd -1, net_seq_idx -1, session_id 1 [in consumer_allocate_stream() at consumer.c:536]
|
|
DEBUG3: open() /root/lttng-traces/s1-20121122-151246//ust/TestApp_Thread1-32727-20121122-151247//channel0_0 with flags 241 mode 511 for uid 0 and gid 0 [in run_as_open() at runas.c:370]
|
|
DEBUG1: Using run_as_clone [in run_as() at runas.c:325]
|
|
DEBUG1: Metadata poll wait with 3 fd(s) [in consumer_thread_metadata_poll() at consumer.c:2028]
|
|
DEBUG1: UST consumer ADD_STREAM /root/lttng-traces/s1-20121122-151246//ust/TestApp_Thread1-32727-20121122-151247//channel0_0 (20,31) with relayd id 0 [in lttng_ustconsumer_recv_cmd() at ust-consumer.c:277]
|
|
DEBUG1: received fds on sock [in consumer_thread_sessiond_poll() at consumer.c:2523]
|
|
DEBUG1: Incoming command on sock [in consumer_thread_sessiond_poll() at consumer.c:2505]
|
|
DEBUG1: UST Consumer adding stream [in lttng_ustconsumer_recv_cmd() at ust-consumer.c:179]
|
|
DEBUG1: Consumer command ADD_STREAM chan 28 stream 48 [in lttng_ustconsumer_recv_cmd() at ust-consumer.c:194]
|
|
DEBUG3: Allocated stream /root/lttng-traces/s1-20121122-151246//ust/TestApp_Thread1-32727-20121122-151247//channel0_1 (key 48, shm_fd 20, wait_fd 33, mmap_len 21888, out_fd -1, net_seq_idx -1, session_id 1 [in consumer_allocate_stream() at consumer.c:536]
|
|
DEBUG3: open() /root/lttng-traces/s1-20121122-151246//ust/TestApp_Thread1-32727-20121122-151247//channel0_1 with flags 241 mode 511 for uid 0 and gid 0 [in run_as_open() at runas.c:370]
|
|
DEBUG1: Using run_as_clone [in run_as() at runas.c:325]
|
|
DEBUG1: poll num_rdy : 1 [in consumer_thread_data_poll() at consumer.c:2251]
|
|
DEBUG1: consumer_data_pipe wake up [in consumer_thread_data_poll() at consumer.c:2275]
|
|
DEBUG3: Adding consumer stream 46 [in consumer_add_stream() at consumer.c:557]
|
|
DEBUG1: Updating poll fd array [in consumer_update_poll_array() at consumer.c:901]
|
|
DEBUG1: Active FD 25 [in consumer_update_poll_array() at consumer.c:917]
|
|
DEBUG1: Active FD 22 [in consumer_update_poll_array() at consumer.c:917]
|
|
DEBUG1: Active FD 27 [in consumer_update_poll_array() at consumer.c:917]
|
|
DEBUG1: Active FD 23 [in consumer_update_poll_array() at consumer.c:917]
|
|
DEBUG1: Active FD 31 [in consumer_update_poll_array() at consumer.c:917]
|
|
DEBUG1: polling on 6 fd [in consumer_thread_data_poll() at consumer.c:2249]
|
|
DEBUG1: UST consumer ADD_STREAM /root/lttng-traces/s1-20121122-151246//ust/TestApp_Thread1-32727-20121122-151247//channel0_1 (20,33) with relayd id 0 [in lttng_ustconsumer_recv_cmd() at ust-consumer.c:277]
|
|
DEBUG1: received fds on sock [in consumer_thread_sessiond_poll() at consumer.c:2523]
|
|
DEBUG1: Incoming command on sock [in consumer_thread_sessiond_poll() at consumer.c:2505]
|
|
DEBUG1: UST Consumer adding stream [in lttng_ustconsumer_recv_cmd() at ust-consumer.c:179]
|
|
DEBUG1: Consumer command ADD_STREAM chan 28 stream 50 [in lttng_ustconsumer_recv_cmd() at ust-consumer.c:194]
|
|
DEBUG3: Allocated stream /root/lttng-traces/s1-20121122-151246//ust/TestApp_Thread1-32727-20121122-151247//channel0_2 (key 50, shm_fd 20, wait_fd 35, mmap_len 21888, out_fd -1, net_seq_idx -1, session_id 1 [in consumer_allocate_stream() at consumer.c:536]
|
|
DEBUG3: open() /root/lttng-traces/s1-20121122-151246//ust/TestApp_Thread1-32727-20121122-151247//channel0_2 with flags 241 mode 511 for uid 0 and gid 0 [in run_as_open() at runas.c:370]
|
|
DEBUG1: Using run_as_clone [in run_as() at runas.c:325]
|
|
DEBUG1: poll num_rdy : 1 [in consumer_thread_data_poll() at consumer.c:2251]
|
|
DEBUG1: consumer_data_pipe wake up [in consumer_thread_data_poll() at consumer.c:2275]
|
|
DEBUG3: Adding consumer stream 48 [in consumer_add_stream() at consumer.c:557]
|
|
DEBUG1: Updating poll fd array [in consumer_update_poll_array() at consumer.c:901]
|
|
DEBUG1: Active FD 25 [in consumer_update_poll_array() at consumer.c:917]
|
|
DEBUG1: Active FD 22 [in consumer_update_poll_array() at consumer.c:917]
|
|
DEBUG1: Active FD 27 [in consumer_update_poll_array() at consumer.c:917]
|
|
DEBUG1: Active FD 33 [in consumer_update_poll_array() at consumer.c:917]
|
|
DEBUG1: Active FD 23 [in consumer_update_poll_array() at consumer.c:917]
|
|
DEBUG1: Active FD 31 [in consumer_update_poll_array() at consumer.c:917]
|
|
DEBUG1: polling on 7 fd [in consumer_thread_data_poll() at consumer.c:2249]
|
|
DEBUG1: UST consumer ADD_STREAM /root/lttng-traces/s1-20121122-151246//ust/TestApp_Thread1-32727-20121122-151247//channel0_2 (20,35) with relayd id 0 [in lttng_ustconsumer_recv_cmd() at ust-consumer.c:277]
|
|
DEBUG1: received fds on sock [in consumer_thread_sessiond_poll() at consumer.c:2523]
|
|
DEBUG1: Incoming command on sock [in consumer_thread_sessiond_poll() at consumer.c:2505]
|
|
DEBUG1: UST Consumer adding stream [in lttng_ustconsumer_recv_cmd() at ust-consumer.c:179]
|
|
DEBUG1: Consumer command ADD_STREAM chan 28 stream 52 [in lttng_ustconsumer_recv_cmd() at ust-consumer.c:194]
|
|
DEBUG3: Allocated stream /root/lttng-traces/s1-20121122-151246//ust/TestApp_Thread1-32727-20121122-151247//channel0_3 (key 52, shm_fd 20, wait_fd 37, mmap_len 21888, out_fd -1, net_seq_idx -1, session_id 1 [in consumer_allocate_stream() at consumer.c:536]
|
|
DEBUG3: open() /root/lttng-traces/s1-20121122-151246//ust/TestApp_Thread1-32727-20121122-151247//channel0_3 with flags 241 mode 511 for uid 0 and gid 0 [in run_as_open() at runas.c:370]
|
|
DEBUG1: Using run_as_clone [in run_as() at runas.c:325]
|
|
DEBUG1: poll num_rdy : 1 [in consumer_thread_data_poll() at consumer.c:2251]
|
|
DEBUG1: consumer_data_pipe wake up [in consumer_thread_data_poll() at consumer.c:2275]
|
|
DEBUG3: Adding consumer stream 50 [in consumer_add_stream() at consumer.c:557]
|
|
DEBUG1: Updating poll fd array [in consumer_update_poll_array() at consumer.c:901]
|
|
DEBUG1: Active FD 25 [in consumer_update_poll_array() at consumer.c:917]
|
|
DEBUG1: Active FD 22 [in consumer_update_poll_array() at consumer.c:917]
|
|
DEBUG1: Active FD 27 [in consumer_update_poll_array() at consumer.c:917]
|
|
DEBUG1: Active FD 33 [in consumer_update_poll_array() at consumer.c:917]
|
|
DEBUG1: Active FD 23 [in consumer_update_poll_array() at consumer.c:917]
|
|
DEBUG1: Active FD 31 [in consumer_update_poll_array() at consumer.c:917]
|
|
DEBUG1: Active FD 35 [in consumer_update_poll_array() at consumer.c:917]
|
|
DEBUG1: polling on 8 fd [in consumer_thread_data_poll() at consumer.c:2249]
|
|
DEBUG1: UST consumer ADD_STREAM /root/lttng-traces/s1-20121122-151246//ust/TestApp_Thread1-32727-20121122-151247//channel0_3 (20,37) with relayd id 0 [in lttng_ustconsumer_recv_cmd() at ust-consumer.c:277]
|
|
DEBUG1: received fds on sock [in consumer_thread_sessiond_poll() at consumer.c:2523]
|
|
DEBUG1: poll num_rdy : 1 [in consumer_thread_data_poll() at consumer.c:2251]
|
|
DEBUG1: consumer_data_pipe wake up [in consumer_thread_data_poll() at consumer.c:2275]
|
|
DEBUG3: Adding consumer stream 52 [in consumer_add_stream() at consumer.c:557]
|
|
DEBUG1: Updating poll fd array [in consumer_update_poll_array() at consumer.c:901]
|
|
DEBUG1: Active FD 25 [in consumer_update_poll_array() at consumer.c:917]
|
|
DEBUG1: Active FD 22 [in consumer_update_poll_array() at consumer.c:917]
|
|
DEBUG1: Active FD 27 [in consumer_update_poll_array() at consumer.c:917]
|
|
DEBUG1: Active FD 37 [in consumer_update_poll_array() at consumer.c:917]
|
|
DEBUG1: Active FD 33 [in consumer_update_poll_array() at consumer.c:917]
|
|
DEBUG1: Active FD 23 [in consumer_update_poll_array() at consumer.c:917]
|
|
DEBUG1: Active FD 31 [in consumer_update_poll_array() at consumer.c:917]
|
|
DEBUG1: Active FD 35 [in consumer_update_poll_array() at consumer.c:917]
|
|
DEBUG1: polling on 9 fd [in consumer_thread_data_poll() at consumer.c:2249]
|
|
DEBUG1: Wait for client response [in thread_manage_clients() at main.c:3204]
|
|
DEBUG1: Receiving data from client ... [in thread_manage_clients() at main.c:3249]
|
|
DEBUG1: Nothing recv() from client... continuing [in thread_manage_clients() at main.c:3253]
|
|
DEBUG1: Clean command context structure [in clean_command_ctx() at main.c:477]
|
|
DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3162]
|
|
[SC-1:Thu Nov 22 15:12:53/cluster/temp/SDPs/EA_Nov15_NoHealthCheck] # pkill -STOP TestApp_type1
|
|
|
|
[2]+ Stopped /home/test_apps/TestApp_type1 444444 np
|
|
[SC-1:Thu Nov 22 15:12:53/cluster/temp/SDPs/EA_Nov15_NoHealthCheck] # sleep 1
|
|
[SC-1:Thu Nov 22 15:12:54/cluster/temp/SDPs/EA_Nov15_NoHealthCheck] # date; lttng create s2
|
|
Thu Nov 22 15:12:54 EST 2012
|
|
DEBUG1: Wait for client response [in thread_manage_clients() at main.c:3204]
|
|
DEBUG1: Receiving data from client ... [in thread_manage_clients() at main.c:3249]
|
|
DEBUG1: Nothing recv() from client... continuing [in thread_manage_clients() at main.c:3253]
|
|
DEBUG1: Clean command context structure [in clean_command_ctx() at main.c:477]
|
|
DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3162]
|
|
DEBUG1: Wait for client response [in thread_manage_clients() at main.c:3204]
|
|
DEBUG1: Receiving data from client ... [in thread_manage_clients() at main.c:3249]
|
|
DEBUG1: Processing client command 8 [in process_client_msg() at main.c:2181]
|
|
DEBUG1: Waiting for 1 URIs from client ... [in process_client_msg() at main.c:2689]
|
|
DEBUG2: Trying to find session by name s2 [in session_find_by_name() at session.c:122]
|
|
DEBUG1: Tracing session s2 created in (null) with ID 2 by UID 0 GID 0 [in session_create() at session.c:236]
|
|
DEBUG2: Trying to find session by name s2 [in session_find_by_name() at session.c:122]
|
|
DEBUG3: Created hashtable size 4 at 0x7fa7d402d220 of type 1 [in lttng_ht_new() at hashtable.c:96]
|
|
DEBUG2: Setting trace directory path from URI to /root/lttng-traces/s2-20121122-151254 [in add_uri_to_consumer() at cmd.c:407]
|
|
DEBUG1: Sending response (size: 16, retcode: Success) [in thread_manage_clients() at main.c:3300]
|
|
DEBUG1: Clean command context structure [in clean_command_ctx() at main.c:477]
|
|
DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3162]
|
|
Session s2 created.
|
|
Traces will be written in /root/lttng-traces/s2-20121122-151254
|
|
annel channel0 -s s2 -u; date +%T.%N; sleep 1); done_NoHealthCheck] # for a in $(seq 1 2); do (echo " "; echo "lttng enable-channel channel0 -s s2 -u"; date +%T.%N; time lttng enable-ch
|
|
|
|
lttng enable-channel channel0 -s s2 -u
|
|
15:12:54.650583446
|
|
DEBUG1: Wait for client response [in thread_manage_clients() at main.c:3204]
|
|
DEBUG1: Receiving data from client ... [in thread_manage_clients() at main.c:3249]
|
|
DEBUG1: Nothing recv() from client... continuing [in thread_manage_clients() at main.c:3253]
|
|
DEBUG1: Clean command context structure [in clean_command_ctx() at main.c:477]
|
|
DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3162]
|
|
DEBUG1: Wait for client response [in thread_manage_clients() at main.c:3204]
|
|
DEBUG1: Receiving data from client ... [in thread_manage_clients() at main.c:3249]
|
|
DEBUG1: Processing client command 5 [in process_client_msg() at main.c:2181]
|
|
DEBUG1: Getting session s2 by name [in process_client_msg() at main.c:2252]
|
|
DEBUG2: Trying to find session by name s2 [in session_find_by_name() at session.c:122]
|
|
DEBUG1: Creating UST session [in create_ust_session() at main.c:2068]
|
|
DEBUG3: Created hashtable size 4 at 0x7fa7d4026060 of type 1 [in lttng_ht_new() at hashtable.c:96]
|
|
DEBUG3: Created hashtable size 4 at 0x7fa7d40265a0 of type 1 [in lttng_ht_new() at hashtable.c:96]
|
|
DEBUG3: Created hashtable size 4 at 0x7fa7d4026ae0 of type 0 [in lttng_ht_new() at hashtable.c:96]
|
|
DEBUG3: Created hashtable size 4 at 0x7fa7d40327a0 of type 1 [in lttng_ht_new() at hashtable.c:96]
|
|
DEBUG2: UST trace session create successful [in trace_ust_create_session() at trace-ust.c:143]
|
|
DEBUG3: Copying tracing session consumer output in UST session [in copy_session_consumer() at main.c:2020]
|
|
DEBUG3: Created hashtable size 4 at 0x7fa7d40327a0 of type 1 [in lttng_ht_new() at hashtable.c:96]
|
|
DEBUG3: Copy session consumer subdir /ust [in copy_session_consumer() at main.c:2038]
|
|
DEBUG3: Consumer socket created (fd: 25) and added to output [in consumer_create_socket() at consumer.c:141]
|
|
DEBUG1: Enabling channel channel0 for session s2 [in cmd_enable_channel() at cmd.c:822]
|
|
DEBUG2: Trace UST channel channel0 not found by name [in trace_ust_find_channel_by_name() at trace-ust.c:52]
|
|
DEBUG3: Created hashtable size 4 at 0x7fa7d4033fc0 of type 0 [in lttng_ht_new() at hashtable.c:96]
|
|
DEBUG3: Created hashtable size 4 at 0x7fa7d4034500 of type 1 [in lttng_ht_new() at hashtable.c:96]
|
|
DEBUG2: Trace UST channel channel0 created [in trace_ust_create_channel() at trace-ust.c:207]
|
|
DEBUG2: Channel channel0 being created in UST global domain [in channel_ust_create() at channel.c:273]
|
|
DEBUG2: UST app adding channel channel0 to global domain for session id 2 [in ust_app_create_channel_glb() at ust-app.c:1994]
|
|
DEBUG2: UST app pid: 32726 session id 2 not found, creating it [in create_ust_app_session() at ust-app.c:961]
|
|
DEBUG3: Created hashtable size 4 at 0x7fa7d4035aa0 of type 0 [in lttng_ht_new() at hashtable.c:96]
|
|
DEBUG2: Shadow copy of session handle -1 [in shadow_copy_session() at ust-app.c:870]
|
|
recvmsg: Resource temporarily unavailable
|
|
Error: Creating session for app pid 32726
|
|
DEBUG2: UST app pid: 32727 session id 2 not found, creating it [in create_ust_app_session() at ust-app.c:961]
|
|
DEBUG3: Created hashtable size 4 at 0x7fa7d4035aa0 of type 0 [in lttng_ht_new() at hashtable.c:96]
|
|
DEBUG2: Shadow copy of session handle -1 [in shadow_copy_session() at ust-app.c:870]
|
|
DEBUG1: PID 32726 unregistering with sock 20 [in ust_app_unregister() at ust-app.c:1497]
|
|
DEBUG1: Apps thread polling on 3 fds [in thread_manage_apps() at main.c:1124]
|
|
DEBUG2: UST app session created successfully with handle 10 [in create_ust_app_session() at ust-app.c:988]
|
|
DEBUG3: Created hashtable size 4 at 0x7fa7d4036290 of type 1 [in lttng_ht_new() at hashtable.c:96]
|
|
DEBUG3: Created hashtable size 4 at 0x7fa7d40367d0 of type 0 [in lttng_ht_new() at hashtable.c:96]
|
|
DEBUG3: UST app channel channel0 allocated [in alloc_ust_app_channel() at ust-app.c:302]
|
|
DEBUG2: UST app shadow copy of channel channel0 started [in shadow_copy_channel() at ust-app.c:810]
|
|
DEBUG3: UST app shadow copy of channel channel0 done [in shadow_copy_channel() at ust-app.c:847]
|
|
DEBUG2: UST app channel channel0 created successfully for pid:32727 and sock:21 [in create_ust_channel() at ust-app.c:683]
|
|
DEBUG2: UST app create channel channel0 for PID 32727 completed [in create_ust_app_channel() at ust-app.c:1233]
|
|
DEBUG2: Trace destroy UST channel channel0 [in trace_ust_destroy_channel() at trace-ust.c:459]
|
|
DEBUG1: Sending response (size: 16, retcode: UST create channel failed) [in thread_manage_clients() at main.c:3300]
|
|
DEBUG1: Clean command context structure [in clean_command_ctx() at main.c:477]
|
|
DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3162]
|
|
DEBUG1: Wait for client response [in thread_manage_clients() at main.c:3204]
|
|
DEBUG1: Receiving data from client ... [in thread_manage_clients() at main.c:3249]
|
|
DEBUG1: Nothing recv() from client... continuing [in thread_manage_clients() at main.c:3253]
|
|
DEBUG1: Clean command context structure [in clean_command_ctx() at main.c:477]
|
|
DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3162]
|
|
Error: Channel channel0: UST create channel failed (session s2)
|
|
Warning: Some command(s) went wrong
|
|
|
|
real 0m5.003s
|
|
user 0m0.000s
|
|
sys 0m0.000s
|
|
15:12:59.655489685
|
|
DEBUG3: Call RCU deleting app PID 32726 [in delete_ust_app_rcu() at ust-app.c:241]
|
|
DEBUG2: Trace UST destroy metadata 8 [in trace_ust_destroy_metadata() at trace-ust.c:494]
|
|
DEBUG2: UST app pid 32726 deleted [in delete_ust_app() at ust-app.c:224]
|
|
DEBUG1: Wait for client response [in thread_manage_clients() at main.c:3204]
|
|
DEBUG1: Receiving data from client ... [in thread_manage_clients() at main.c:3249]
|
|
DEBUG1: Nothing recv() from client... continuing [in thread_manage_clients() at main.c:3253]
|
|
DEBUG1: Clean command context structure [in clean_command_ctx() at main.c:477]
|
|
DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3162]
|
|
|
|
lttng enable-channel channel0 -s s2 -u
|
|
15:13:00.659833071
|
|
DEBUG1: Wait for client response [in thread_manage_clients() at main.c:3204]
|
|
DEBUG1: Receiving data from client ... [in thread_manage_clients() at main.c:3249]
|
|
DEBUG1: Nothing recv() from client... continuing [in thread_manage_clients() at main.c:3253]
|
|
DEBUG1: Clean command context structure [in clean_command_ctx() at main.c:477]
|
|
DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3162]
|
|
DEBUG1: Wait for client response [in thread_manage_clients() at main.c:3204]
|
|
DEBUG1: Receiving data from client ... [in thread_manage_clients() at main.c:3249]
|
|
DEBUG1: Processing client command 5 [in process_client_msg() at main.c:2181]
|
|
DEBUG1: Getting session s2 by name [in process_client_msg() at main.c:2252]
|
|
DEBUG2: Trying to find session by name s2 [in session_find_by_name() at session.c:122]
|
|
DEBUG3: Consumer socket created (fd: 25) and added to output [in consumer_create_socket() at consumer.c:141]
|
|
DEBUG1: Enabling channel channel0 for session s2 [in cmd_enable_channel() at cmd.c:822]
|
|
DEBUG2: Trace UST channel channel0 not found by name [in trace_ust_find_channel_by_name() at trace-ust.c:52]
|
|
DEBUG3: Created hashtable size 4 at 0x7fa7d4013bc0 of type 0 [in lttng_ht_new() at hashtable.c:96]
|
|
DEBUG3: Created hashtable size 4 at 0x7fa7d4018320 of type 1 [in lttng_ht_new() at hashtable.c:96]
|
|
DEBUG2: Trace UST channel channel0 created [in trace_ust_create_channel() at trace-ust.c:207]
|
|
DEBUG2: Channel channel0 being created in UST global domain [in channel_ust_create() at channel.c:273]
|
|
DEBUG2: UST app adding channel channel0 to global domain for session id 2 [in ust_app_create_channel_glb() at ust-app.c:1994]
|
|
DEBUG2: Channel channel0 created successfully [in channel_ust_create() at channel.c:298]
|
|
DEBUG1: Sending response (size: 16, retcode: Success) [in thread_manage_clients() at main.c:3300]
|
|
DEBUG1: Clean command context structure [in clean_command_ctx() at main.c:477]
|
|
DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3162]
|
|
UST channel channel0 enabled for session s2
|
|
|
|
real 0m0.002s
|
|
user 0m0.000s
|
|
sys 0m0.000s
|
|
15:13:00.663392698
|
|
[SC-1:Thu Nov 22 15:13:01/cluster/temp/SDPs/EA_Nov15_NoHealthCheck] # DEBUG1: Wait for client response [in thread_manage_clients() at main.c:3204]
|
|
DEBUG1: Receiving data from client ... [in thread_manage_clients() at main.c:3249]
|
|
DEBUG1: Nothing recv() from client... continuing [in thread_manage_clients() at main.c:3253]
|
|
DEBUG1: Clean command context structure [in clean_command_ctx() at main.c:477]
|
|
DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3162]
|
|
|
|
[SC-1:Thu Nov 22 15:13:08/cluster/temp/SDPs/EA_Nov15_NoHealthCheck] # DEBUG1: Wait for client response [in thread_manage_clients() at main.c:3204]
|
|
DEBUG1: Receiving data from client ... [in thread_manage_clients() at main.c:3249]
|
|
DEBUG1: Nothing recv() from client... continuing [in thread_manage_clients() at main.c:3253]
|
|
DEBUG1: Clean command context structure [in clean_command_ctx() at main.c:477]
|
|
DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3162]
|
|
|
|
[SC-1:Thu Nov 22 15:13:11/cluster/temp/SDPs/EA_Nov15_NoHealthCheck] # lttng list
|
|
DEBUG1: Wait for client response [in thread_manage_clients() at main.c:3204]
|
|
DEBUG1: Receiving data from client ... [in thread_manage_clients() at main.c:3249]
|
|
DEBUG1: Nothing recv() from client... continuing [in thread_manage_clients() at main.c:3253]
|
|
DEBUG1: Clean command context structure [in clean_command_ctx() at main.c:477]
|
|
DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3162]
|
|
DEBUG1: Wait for client response [in thread_manage_clients() at main.c:3204]
|
|
DEBUG1: Receiving data from client ... [in thread_manage_clients() at main.c:3249]
|
|
DEBUG1: Processing client command 13 [in process_client_msg() at main.c:2181]
|
|
DEBUG1: Counting number of available session for UID 0 GID 0 [in lttng_sessions_count() at main.c:2152]
|
|
DEBUG1: Getting all available session for UID 0 GID 0 [in cmd_list_lttng_sessions() at cmd.c:2111]
|
|
DEBUG1: Sending response (size: 8760, retcode: Success) [in thread_manage_clients() at main.c:3300]
|
|
DEBUG1: Clean command context structure [in clean_command_ctx() at main.c:477]
|
|
DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3162]
|
|
Available tracing sessions:
|
|
1) s2 (/root/lttng-traces/s2-20121122-151254) [inactive]
|
|
2) s1 (/root/lttng-traces/s1-20121122-151246) [active]
|
|
|
|
Use lttng list <session_name> for more details
|
|
[SC-1:Thu Nov 22 15:13:13/cluster/temp/SDPs/EA_Nov15_NoHealthCheck] # DEBUG1: Wait for client response [in thread_manage_clients() at main.c:3204]
|
|
DEBUG1: Receiving data from client ... [in thread_manage_clients() at main.c:3249]
|
|
DEBUG1: Nothing recv() from client... continuing [in thread_manage_clients() at main.c:3253]
|
|
DEBUG1: Clean command context structure [in clean_command_ctx() at main.c:477]
|
|
DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3162]
|
|
|
|
[SC-1:Thu Nov 22 15:13:16/cluster/temp/SDPs/EA_Nov15_NoHealthCheck] #
|
|
[SC-1:Thu Nov 22 15:13:16/cluster/temp/SDPs/EA_Nov15_NoHealthCheck] # DEBUG1: Wait for client response [in thread_manage_clients() at main.c:3204]
|
|
DEBUG1: Receiving data from client ... [in thread_manage_clients() at main.c:3249]
|
|
DEBUG1: Nothing recv() from client... continuing [in thread_manage_clients() at main.c:3253]
|
|
DEBUG1: Clean command context structure [in clean_command_ctx() at main.c:477]
|
|
DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3162]
|
|
|
|
[SC-1:Thu Nov 22 15:13:22/cluster/temp/SDPs/EA_Nov15_NoHealthCheck] # pkill -CONT TestApp
|
|
libust[32726/32728]: Error: Error handling message for global socket (in ust_listener_thread() at lttng-ust-comm.c:904)
|
|
DEBUG1: Metadata event catched in thread [in consumer_thread_metadata_poll() at consumer.c:2030]
|
|
DEBUG1: Metadata fd 21 is hup|err. [in consumer_thread_metadata_poll() at consumer.c:2112]
|
|
DEBUG1: Attempting to flush and consume the UST buffers [in consumer_thread_metadata_poll() at consumer.c:2116]
|
|
DEBUG1: In read_subbuffer (wait_fd: 21, stream key: 32) [in lttng_ustconsumer_read_subbuffer() at ust-consumer.c:431]
|
|
DEBUG1: Consumer mmap write() ret 4096 (len 4096) [in lttng_consumer_on_read_subbuffer_mmap() at consumer.c:1364]
|
|
DEBUG1: In read_subbuffer (wait_fd: 21, stream key: 32) [in lttng_ustconsumer_read_subbuffer() at ust-consumer.c:431]
|
|
DEBUG1: Reserving sub buffer failed (everything is normal, it is due to concurrency) [in lttng_ustconsumer_read_subbuffer() at ust-consumer.c:457]
|
|
DEBUG1: poll num_rdy : 4 [in consumer_thread_data_poll() at consumer.c:2251]
|
|
DEBUG1: fd 25 is hup|err|nval. Attempting flush and read. [in consumer_thread_data_poll() at consumer.c:2365]
|
|
DEBUG3: Consumer delete metadata stream 21 [in consumer_del_metadata_stream() at consumer.c:1759]
|
|
DEBUG1: Polling fd 25 tells it has hung up. [in consumer_thread_data_poll() at consumer.c:2376]
|
|
DEBUG1: fd 22 is hup|err|nval. Attempting flush and read. [in consumer_thread_data_poll() at consumer.c:2365]
|
|
DEBUG1: Metadata poll wait with 2 fd(s) [in consumer_thread_metadata_poll() at consumer.c:2028]
|
|
DEBUG1: Polling fd 22 tells it has hung up. [in consumer_thread_data_poll() at consumer.c:2376]
|
|
DEBUG1: fd 27 is hup|err|nval. Attempting flush and read. [in consumer_thread_data_poll() at consumer.c:2365]
|
|
DEBUG1: Polling fd 27 tells it has hung up. [in consumer_thread_data_poll() at consumer.c:2376]
|
|
DEBUG1: fd 23 is hup|err|nval. Attempting flush and read. [in consumer_thread_data_poll() at consumer.c:2365]
|
|
DEBUG1: Polling fd 23 tells it has hung up. [in consumer_thread_data_poll() at consumer.c:2376]
|
|
DEBUG1: polling on 9 fd [in consumer_thread_data_poll() at consumer.c:2249]
|
|
DEBUG1: poll num_rdy : 4 [in consumer_thread_data_poll() at consumer.c:2251]
|
|
DEBUG1: Normal read on fd 25 [in consumer_thread_data_poll() at consumer.c:2342]
|
|
DEBUG1: In read_subbuffer (wait_fd: 25, stream key: 38) [in lttng_ustconsumer_read_subbuffer() at ust-consumer.c:431]
|
|
DEBUG1: Consumer mmap write() ret 4096 (len 4096) [in lttng_consumer_on_read_subbuffer_mmap() at consumer.c:1364]
|
|
DEBUG1: Normal read on fd 22 [in consumer_thread_data_poll() at consumer.c:2342]
|
|
DEBUG1: In read_subbuffer (wait_fd: 22, stream key: 34) [in lttng_ustconsumer_read_subbuffer() at ust-consumer.c:431]
|
|
DEBUG1: Consumer mmap write() ret 4096 (len 4096) [in lttng_consumer_on_read_subbuffer_mmap() at consumer.c:1364]
|
|
DEBUG1: Normal read on fd 27 [in consumer_thread_data_poll() at consumer.c:2342]
|
|
DEBUG1: In read_subbuffer (wait_fd: 27, stream key: 40) [in lttng_ustconsumer_read_subbuffer() at ust-consumer.c:431]
|
|
DEBUG1: Consumer mmap write() ret 4096 (len 4096) [in lttng_consumer_on_read_subbuffer_mmap() at consumer.c:1364]
|
|
DEBUG1: Normal read on fd 23 [in consumer_thread_data_poll() at consumer.c:2342]
|
|
DEBUG1: In read_subbuffer (wait_fd: 23, stream key: 36) [in lttng_ustconsumer_read_subbuffer() at ust-consumer.c:431]
|
|
DEBUG1: Consumer mmap write() ret 4096 (len 4096) [in lttng_consumer_on_read_subbuffer_mmap() at consumer.c:1364]
|
|
DEBUG1: Polling fd 25 tells it has hung up. [in consumer_thread_data_poll() at consumer.c:2376]
|
|
DEBUG1: Polling fd 22 tells it has hung up. [in consumer_thread_data_poll() at consumer.c:2376]
|
|
DEBUG1: Polling fd 27 tells it has hung up. [in consumer_thread_data_poll() at consumer.c:2376]
|
|
DEBUG1: Polling fd 23 tells it has hung up. [in consumer_thread_data_poll() at consumer.c:2376]
|
|
DEBUG1: polling on 9 fd [in consumer_thread_data_poll() at consumer.c:2249]
|
|
DEBUG1: poll num_rdy : 4 [in consumer_thread_data_poll() at consumer.c:2251]
|
|
DEBUG1: Normal read on fd 25 [in consumer_thread_data_poll() at consumer.c:2342]
|
|
DEBUG1: In read_subbuffer (wait_fd: 25, stream key: 38) [in lttng_ustconsumer_read_subbuffer() at ust-consumer.c:431]
|
|
DEBUG1: Reserving sub buffer failed (everything is normal, it is due to concurrency) [in lttng_ustconsumer_read_subbuffer() at ust-consumer.c:457]
|
|
DEBUG1: Normal read on fd 22 [in consumer_thread_data_poll() at consumer.c:2342]
|
|
DEBUG1: In read_subbuffer (wait_fd: 22, stream key: 34) [in lttng_ustconsumer_read_subbuffer() at ust-consumer.c:431]
|
|
DEBUG1: Reserving sub buffer failed (everything is normal, it is due to concurrency) [in lttng_ustconsumer_read_subbuffer() at ust-consumer.c:457]
|
|
DEBUG1: Normal read on fd 27 [in consumer_thread_data_poll() at consumer.c:2342]
|
|
DEBUG1: In read_subbuffer (wait_fd: 27, stream key: 40) [in lttng_ustconsumer_read_subbuffer() at ust-consumer.c:431]
|
|
DEBUG1: Reserving sub buffer failed (everything is normal, it is due to concurrency) [in lttng_ustconsumer_read_subbuffer() at ust-consumer.c:457]
|
|
DEBUG1: Normal read on fd 23 [in consumer_thread_data_poll() at consumer.c:2342]
|
|
DEBUG1: In read_subbuffer (wait_fd: 23, stream key: 36) [in lttng_ustconsumer_read_subbuffer() at ust-consumer.c:431]
|
|
DEBUG1: Reserving sub buffer failed (everything is normal, it is due to concurrency) [in lttng_ustconsumer_read_subbuffer() at ust-consumer.c:457]
|
|
DEBUG1: Polling fd 25 tells it has hung up. [in consumer_thread_data_poll() at consumer.c:2376]
|
|
DEBUG1: Consumer del stream 25 [in consumer_del_stream() at consumer.c:347]
|
|
DEBUG1: Polling fd 22 tells it has hung up. [in consumer_thread_data_poll() at consumer.c:2376]
|
|
DEBUG1: Consumer del stream 22 [in consumer_del_stream() at consumer.c:347]
|
|
DEBUG1: Polling fd 27 tells it has hung up. [in consumer_thread_data_poll() at consumer.c:2376]
|
|
DEBUG1: Consumer del stream 27 [in consumer_del_stream() at consumer.c:347]
|
|
DEBUG1: Polling fd 23 tells it has hung up. [in consumer_thread_data_poll() at consumer.c:2376]
|
|
DEBUG1: Consumer del stream 23 [in consumer_del_stream() at consumer.c:347]
|
|
DEBUG1: Updating poll fd array [in consumer_update_poll_array() at consumer.c:901]
|
|
DEBUG1: Active FD 37 [in consumer_update_poll_array() at consumer.c:917]
|
|
DEBUG1: Active FD 33 [in consumer_update_poll_array() at consumer.c:917]
|
|
DEBUG1: Active FD 31 [in consumer_update_poll_array() at consumer.c:917]
|
|
DEBUG1: Active FD 35 [in consumer_update_poll_array() at consumer.c:917]
|
|
DEBUG1: polling on 5 fd [in consumer_thread_data_poll() at consumer.c:2249]
|
|
[SC-1:Thu Nov 22 15:13:23/cluster/temp/SDPs/EA_Nov15_NoHealthCheck] # lttng list
|
|
DEBUG1: Wait for client response [in thread_manage_clients() at main.c:3204]
|
|
DEBUG1: Receiving data from client ... [in thread_manage_clients() at main.c:3249]
|
|
DEBUG1: Nothing recv() from client... continuing [in thread_manage_clients() at main.c:3253]
|
|
DEBUG1: Clean command context structure [in clean_command_ctx() at main.c:477]
|
|
DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3162]
|
|
DEBUG1: Wait for client response [in thread_manage_clients() at main.c:3204]
|
|
DEBUG1: Receiving data from client ... [in thread_manage_clients() at main.c:3249]
|
|
DEBUG1: Processing client command 13 [in process_client_msg() at main.c:2181]
|
|
DEBUG1: Counting number of available session for UID 0 GID 0 [in lttng_sessions_count() at main.c:2152]
|
|
DEBUG1: Getting all available session for UID 0 GID 0 [in cmd_list_lttng_sessions() at cmd.c:2111]
|
|
DEBUG1: Sending response (size: 8760, retcode: Success) [in thread_manage_clients() at main.c:3300]
|
|
DEBUG1: Clean command context structure [in clean_command_ctx() at main.c:477]
|
|
DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3162]
|
|
Available tracing sessions:
|
|
1) s2 (/root/lttng-traces/s2-20121122-151254) [inactive]
|
|
2) s1 (/root/lttng-traces/s1-20121122-151246) [active]
|
|
|
|
Use lttng list <session_name> for more details
|
|
[SC-1:Thu Nov 22 15:13:23/cluster/temp/SDPs/EA_Nov15_NoHealthCheck] # lttng destroy s1
|
|
DEBUG1: Wait for client response [in thread_manage_clients() at main.c:3204]
|
|
DEBUG1: Receiving data from client ... [in thread_manage_clients() at main.c:3249]
|
|
DEBUG1: Nothing recv() from client... continuing [in thread_manage_clients() at main.c:3253]
|
|
DEBUG1: Clean command context structure [in clean_command_ctx() at main.c:477]
|
|
DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3162]
|
|
DEBUG1: Wait for client response [in thread_manage_clients() at main.c:3204]
|
|
DEBUG1: Receiving data from client ... [in thread_manage_clients() at main.c:3249]
|
|
DEBUG1: Processing client command 9 [in process_client_msg() at main.c:2181]
|
|
DEBUG1: Getting session s1 by name [in process_client_msg() at main.c:2252]
|
|
DEBUG2: Trying to find session by name s1 [in session_find_by_name() at session.c:122]
|
|
DEBUG3: No kernel session when tearing down session [in kernel_destroy_session() at kernel.c:730]
|
|
DEBUG1: Destroy all UST traces [in ust_app_destroy_trace_all() at ust-app.c:2514]
|
|
DEBUG1: Destroy tracing for ust app pid 32727 [in ust_app_destroy_trace() at ust-app.c:2412]
|
|
DEBUG2: Trace UST destroy metadata 9 [in trace_ust_destroy_metadata() at trace-ust.c:494]
|
|
DEBUG1: poll num_rdy : 2 [in consumer_thread_data_poll() at consumer.c:2251]
|
|
DEBUG1: fd 33 is hup|err|nval. Attempting flush and read. [in consumer_thread_data_poll() at consumer.c:2365]
|
|
DEBUG1: Polling fd 33 tells it has hung up. [in consumer_thread_data_poll() at consumer.c:2376]
|
|
DEBUG1: fd 31 is hup|err|nval. Attempting flush and read. [in consumer_thread_data_poll() at consumer.c:2365]
|
|
DEBUG1: Polling fd 31 tells it has hung up. [in consumer_thread_data_poll() at consumer.c:2376]
|
|
DEBUG1: polling on 5 fd [in consumer_thread_data_poll() at consumer.c:2249]
|
|
DEBUG1: poll num_rdy : 4 [in consumer_thread_data_poll() at consumer.c:2251]
|
|
DEBUG1: Metadata event catched in thread [in consumer_thread_metadata_poll() at consumer.c:2030]
|
|
DEBUG1: Metadata fd 29 is hup|err. [in consumer_thread_metadata_poll() at consumer.c:2112]
|
|
DEBUG1: Attempting to flush and consume the UST buffers [in consumer_thread_metadata_poll() at consumer.c:2116]
|
|
DEBUG1: Normal read on fd 33 [in consumer_thread_data_poll() at consumer.c:2342]
|
|
DEBUG1: In read_subbuffer (wait_fd: 33, stream key: 48) [in lttng_ustconsumer_read_subbuffer() at ust-consumer.c:431]
|
|
DEBUG1: In read_subbuffer (wait_fd: 29, stream key: 44) [in lttng_ustconsumer_read_subbuffer() at ust-consumer.c:431]
|
|
DEBUG1: Consumer mmap write() ret 4096 (len 4096) [in lttng_consumer_on_read_subbuffer_mmap() at consumer.c:1364]
|
|
DEBUG1: Normal read on fd 31 [in consumer_thread_data_poll() at consumer.c:2342]
|
|
DEBUG1: In read_subbuffer (wait_fd: 31, stream key: 46) [in lttng_ustconsumer_read_subbuffer() at ust-consumer.c:431]
|
|
DEBUG1: Consumer mmap write() ret 4096 (len 4096) [in lttng_consumer_on_read_subbuffer_mmap() at consumer.c:1364]
|
|
DEBUG1: fd 37 is hup|err|nval. Attempting flush and read. [in consumer_thread_data_poll() at consumer.c:2365]
|
|
DEBUG1: Consumer mmap write() ret 4096 (len 4096) [in lttng_consumer_on_read_subbuffer_mmap() at consumer.c:1364]
|
|
DEBUG1: Polling fd 37 tells it has hung up. [in consumer_thread_data_poll() at consumer.c:2376]
|
|
DEBUG1: Polling fd 33 tells it has hung up. [in consumer_thread_data_poll() at consumer.c:2376]
|
|
DEBUG1: Polling fd 31 tells it has hung up. [in consumer_thread_data_poll() at consumer.c:2376]
|
|
DEBUG1: fd 35 is hup|err|nval. Attempting flush and read. [in consumer_thread_data_poll() at consumer.c:2365]
|
|
DEBUG2: Trace UST destroy session 1 [in trace_ust_destroy_session() at trace-ust.c:576]
|
|
DEBUG1: Polling fd 35 tells it has hung up. [in consumer_thread_data_poll() at consumer.c:2376]
|
|
DEBUG1: polling on 5 fd [in consumer_thread_data_poll() at consumer.c:2249]
|
|
DEBUG1: poll num_rdy : 4 [in consumer_thread_data_poll() at consumer.c:2251]
|
|
DEBUG1: Normal read on fd 37 [in consumer_thread_data_poll() at consumer.c:2342]
|
|
DEBUG1: In read_subbuffer (wait_fd: 37, stream key: 52) [in lttng_ustconsumer_read_subbuffer() at ust-consumer.c:431]
|
|
DEBUG1: Consumer mmap write() ret 4096 (len 4096) [in lttng_consumer_on_read_subbuffer_mmap() at consumer.c:1364]
|
|
DEBUG1: Normal read on fd 33 [in consumer_thread_data_poll() at consumer.c:2342]
|
|
DEBUG1: In read_subbuffer (wait_fd: 33, stream key: 48) [in lttng_ustconsumer_read_subbuffer() at ust-consumer.c:431]
|
|
DEBUG1: Reserving sub buffer failed (everything is normal, it is due to concurrency) [in lttng_ustconsumer_read_subbuffer() at ust-consumer.c:457]
|
|
DEBUG1: Normal read on fd 31 [in consumer_thread_data_poll() at consumer.c:2342]
|
|
DEBUG1: In read_subbuffer (wait_fd: 31, stream key: 46) [in lttng_ustconsumer_read_subbuffer() at ust-consumer.c:431]
|
|
DEBUG1: Reserving sub buffer failed (everything is normal, it is due to concurrency) [in lttng_ustconsumer_read_subbuffer() at ust-consumer.c:457]
|
|
DEBUG1: Destroying session s1 [in session_destroy() at session.c:149]
|
|
DEBUG1: Normal read on fd 35 [in consumer_thread_data_poll() at consumer.c:2342]
|
|
DEBUG1: In read_subbuffer (wait_fd: 35, stream key: 50) [in lttng_ustconsumer_read_subbuffer() at ust-consumer.c:431]
|
|
DEBUG1: Sending response (size: 16, retcode: Success) [in thread_manage_clients() at main.c:3300]
|
|
DEBUG1: Consumer mmap write() ret 4096 (len 4096) [in lttng_consumer_on_read_subbuffer_mmap() at consumer.c:1364]
|
|
DEBUG1: Polling fd 37 tells it has hung up. [in consumer_thread_data_poll() at consumer.c:2376]
|
|
DEBUG1: Polling fd 33 tells it has hung up. [in consumer_thread_data_poll() at consumer.c:2376]
|
|
DEBUG1: Consumer del stream 33 [in consumer_del_stream() at consumer.c:347]
|
|
DEBUG1: Clean command context structure [in clean_command_ctx() at main.c:477]
|
|
DEBUG1: Polling fd 31 tells it has hung up. [in consumer_thread_data_poll() at consumer.c:2376]
|
|
DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3162]
|
|
DEBUG1: Consumer del stream 31 [in consumer_del_stream() at consumer.c:347]
|
|
DEBUG1: Updating kernel poll set [in update_kernel_poll() at main.c:558]
|
|
DEBUG1: Polling fd 35 tells it has hung up. [in consumer_thread_data_poll() at consumer.c:2376]
|
|
DEBUG1: Thread kernel polling on 2 fds [in thread_manage_kernel() at main.c:730]
|
|
DEBUG1: In read_subbuffer (wait_fd: 29, stream key: 44) [in lttng_ustconsumer_read_subbuffer() at ust-consumer.c:431]
|
|
DEBUG1: Updating poll fd array [in consumer_update_poll_array() at consumer.c:901]
|
|
DEBUG1: Active FD 37 [in consumer_update_poll_array() at consumer.c:917]
|
|
DEBUG1: Active FD 35 [in consumer_update_poll_array() at consumer.c:917]
|
|
DEBUG1: polling on 3 fd [in consumer_thread_data_poll() at consumer.c:2249]
|
|
DEBUG1: Reserving sub buffer failed (everything is normal, it is due to concurrency) [in lttng_ustconsumer_read_subbuffer() at ust-consumer.c:457]
|
|
DEBUG3: Consumer delete metadata stream 29 [in consumer_del_metadata_stream() at consumer.c:1759]
|
|
Session s1 destroyed
|
|
DEBUG1: Metadata poll wait with 1 fd(s) [in consumer_thread_metadata_poll() at consumer.c:2028]
|
|
DEBUG1: poll num_rdy : 2 [in consumer_thread_data_poll() at consumer.c:2251]
|
|
DEBUG1: Normal read on fd 37 [in consumer_thread_data_poll() at consumer.c:2342]
|
|
DEBUG1: In read_subbuffer (wait_fd: 37, stream key: 52) [in lttng_ustconsumer_read_subbuffer() at ust-consumer.c:431]
|
|
DEBUG1: Reserving sub buffer failed (everything is normal, it is due to concurrency) [in lttng_ustconsumer_read_subbuffer() at ust-consumer.c:457]
|
|
DEBUG1: Normal read on fd 35 [in consumer_thread_data_poll() at consumer.c:2342]
|
|
DEBUG1: In read_subbuffer (wait_fd: 35, stream key: 50) [in lttng_ustconsumer_read_subbuffer() at ust-consumer.c:431]
|
|
DEBUG1: Reserving sub buffer failed (everything is normal, it is due to concurrency) [in lttng_ustconsumer_read_subbuffer() at ust-consumer.c:457]
|
|
DEBUG1: Polling fd 37 tells it has hung up. [in consumer_thread_data_poll() at consumer.c:2376]
|
|
DEBUG1: Consumer del stream 37 [in consumer_del_stream() at consumer.c:347]
|
|
DEBUG1: Polling fd 35 tells it has hung up. [in consumer_thread_data_poll() at consumer.c:2376]
|
|
DEBUG1: Consumer del stream 35 [in consumer_del_stream() at consumer.c:347]
|
|
DEBUG1: Updating poll fd array [in consumer_update_poll_array() at consumer.c:901]
|
|
DEBUG1: polling on 1 fd [in consumer_thread_data_poll() at consumer.c:2249]
|
|
[SC-1:Thu Nov 22 15:13:23/cluster/temp/SDPs/EA_Nov15_NoHealthCheck] # lttng destroy s2
|
|
DEBUG1: Wait for client response [in thread_manage_clients() at main.c:3204]
|
|
DEBUG1: Receiving data from client ... [in thread_manage_clients() at main.c:3249]
|
|
DEBUG1: Nothing recv() from client... continuing [in thread_manage_clients() at main.c:3253]
|
|
DEBUG1: Clean command context structure [in clean_command_ctx() at main.c:477]
|
|
DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3162]
|
|
DEBUG1: Wait for client response [in thread_manage_clients() at main.c:3204]
|
|
DEBUG1: Receiving data from client ... [in thread_manage_clients() at main.c:3249]
|
|
DEBUG1: Processing client command 9 [in process_client_msg() at main.c:2181]
|
|
DEBUG1: Getting session s2 by name [in process_client_msg() at main.c:2252]
|
|
DEBUG2: Trying to find session by name s2 [in session_find_by_name() at session.c:122]
|
|
DEBUG3: No kernel session when tearing down session [in kernel_destroy_session() at kernel.c:730]
|
|
DEBUG1: Destroy all UST traces [in ust_app_destroy_trace_all() at ust-app.c:2514]
|
|
DEBUG1: Destroy tracing for ust app pid 32727 [in ust_app_destroy_trace() at ust-app.c:2412]
|
|
DEBUG2: Trace UST destroy session 2 [in trace_ust_destroy_session() at trace-ust.c:576]
|
|
DEBUG1: Destroying session s2 [in session_destroy() at session.c:149]
|
|
DEBUG1: Sending response (size: 16, retcode: Success) [in thread_manage_clients() at main.c:3300]
|
|
DEBUG1: Updating kernel poll set [in update_kernel_poll() at main.c:558]
|
|
DEBUG1: Clean command context structure [in clean_command_ctx() at main.c:477]
|
|
DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3162]
|
|
Session s2 destroyed
|
|
DEBUG1: Thread kernel polling on 2 fds [in thread_manage_kernel() at main.c:730]
|
|
[SC-1:Thu Nov 22 15:13:23/cluster/temp/SDPs/EA_Nov15_NoHealthCheck] # lttng list
|
|
DEBUG1: Wait for client response [in thread_manage_clients() at main.c:3204]
|
|
DEBUG1: Receiving data from client ... [in thread_manage_clients() at main.c:3249]
|
|
DEBUG1: Nothing recv() from client... continuing [in thread_manage_clients() at main.c:3253]
|
|
DEBUG1: Clean command context structure [in clean_command_ctx() at main.c:477]
|
|
DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3162]
|
|
DEBUG1: Wait for client response [in thread_manage_clients() at main.c:3204]
|
|
DEBUG1: Receiving data from client ... [in thread_manage_clients() at main.c:3249]
|
|
DEBUG1: Processing client command 13 [in process_client_msg() at main.c:2181]
|
|
DEBUG1: Counting number of available session for UID 0 GID 0 [in lttng_sessions_count() at main.c:2152]
|
|
DEBUG1: Getting all available session for UID 0 GID 0 [in cmd_list_lttng_sessions() at cmd.c:2111]
|
|
DEBUG1: Sending response (size: 16, retcode: Success) [in thread_manage_clients() at main.c:3300]
|
|
DEBUG1: Clean command context structure [in clean_command_ctx() at main.c:477]
|
|
DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3162]
|
|
Currently no available tracing session
|
|
[SC-1:Thu Nov 22 15:13:23/cluster/temp/SDPs/EA_Nov15_NoHealthCheck] # pkill relayd
|
|
DEBUG2: Trace destroy UST channel channel0 [in trace_ust_destroy_channel() at trace-ust.c:459]
|
|
DEBUG2: Trace destroy UST channel channel0 [in trace_ust_destroy_channel() at trace-ust.c:459]
|
|
[SC-1:Thu Nov 22 15:13:23/cluster/temp/SDPs/EA_Nov15_NoHealthCheck] # sleep 1
|
|
DEBUG2: Trace destroy UST event com_ericsson_cba_trace_testapp_lowtraf:OnePerSecB [in trace_ust_destroy_event() at trace-ust.c:417]
|
|
[SC-1:Thu Nov 22 15:13:24/cluster/temp/SDPs/EA_Nov15_NoHealthCheck] # jobs
|
|
[1] Running lttng-sessiond -vvv --verbose-consumer &
|
|
[2]- Running /home/test_apps/TestApp_type1 444444 np &
|
|
[3]+ Running /home/test_apps/TestApp_Thread1 55555 np &
|
|
[SC-1:Thu Nov 22 15:13:24/cluster/temp/SDPs/EA_Nov15_NoHealthCheck] # DEBUG1: Wait for client response [in thread_manage_clients() at main.c:3204]
|
|
DEBUG1: Receiving data from client ... [in thread_manage_clients() at main.c:3249]
|
|
DEBUG1: Nothing recv() from client... continuing [in thread_manage_clients() at main.c:3253]
|
|
DEBUG1: Clean command context structure [in clean_command_ctx() at main.c:477]
|
|
DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3162]
|
|
DEBUG1: UST registration received with pid:32726 ppid:4007 uid:0 gid:0 sock:20 name:TestApp_type1 (version 2.0) [in thread_registration_apps() at main.c:1493]
|
|
DEBUG1: Futex n to 1 wake done [in futex_nto1_wake() at futex.c:104]
|
|
DEBUG1: Accepting application registration [in thread_registration_apps() at main.c:1393]
|
|
DEBUG1: Futex n to 1 wait done [in futex_nto1_wait() at futex.c:90]
|
|
DEBUG1: Futex n to 1 prepare done [in futex_nto1_prepare() at futex.c:75]
|
|
DEBUG1: Dispatching UST registration pid:32726 ppid:4007 uid:0 gid:0 sock:20 name:TestApp_type1 (version 2.0) [in thread_dispatch_ust_registration() at main.c:1306]
|
|
DEBUG1: Woken up but nothing in the UST command queue [in thread_dispatch_ust_registration() at main.c:1294]
|
|
DEBUG3: Created hashtable size 4 at 0x643950 of type 1 [in lttng_ht_new() at hashtable.c:96]
|
|
DEBUG1: App registered with pid:32726 ppid:4007 uid:0 gid:0 sock:20 name:TestApp_type1 (version 2.0) [in ust_app_register() at ust-app.c:1467]
|
|
DEBUG2: UST app PID 32726 is compatible with internal major version 3 (supporting == 3) [in ust_app_validate_version() at ust-app.c:2945]
|
|
DEBUG1: Apps with sock 20 added to poll set [in thread_manage_apps() at main.c:1221]
|
|
DEBUG1: Apps thread polling on 4 fds [in thread_manage_apps() at main.c:1124]
|
|
DEBUG1: Wait for client response [in thread_manage_clients() at main.c:3204]
|
|
DEBUG1: Receiving data from client ... [in thread_manage_clients() at main.c:3249]
|
|
DEBUG1: Nothing recv() from client... continuing [in thread_manage_clients() at main.c:3253]
|
|
DEBUG1: Clean command context structure [in clean_command_ctx() at main.c:477]
|
|
DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3162]
|
|
|
|
[SC-1:Thu Nov 22 15:13:34/cluster/temp/SDPs/EA_Nov15_NoHealthCheck] # DEBUG1: Wait for client response [in thread_manage_clients() at main.c:3204]
|
|
DEBUG1: Receiving data from client ... [in thread_manage_clients() at main.c:3249]
|
|
DEBUG1: Nothing recv() from client... continuing [in thread_manage_clients() at main.c:3253]
|
|
DEBUG1: Clean command context structure [in clean_command_ctx() at main.c:477]
|
|
DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3162]
|
|
|
|
[SC-1:Thu Nov 22 15:13:35/cluster/temp/SDPs/EA_Nov15_NoHealthCheck] #
|
|
[SC-1:Thu Nov 22 15:13:36/cluster/temp/SDPs/EA_Nov15_NoHealthCheck] #
|
|
[SC-1:Thu Nov 22 15:13:37/cluster/temp/SDPs/EA_Nov15_NoHealthCheck] #
|
|
[SC-1:Thu Nov 22 15:13:37/cluster/temp/SDPs/EA_Nov15_NoHealthCheck] #
|