DEBUG3 - 14:17:02.698960 [7657/7657]: Creating LTTng run directory: /home/zhengd/.lttng (in create_lttng_rundir() at main.c:4690) DEBUG1 - 14:17:02.699148 [7657/7657]: Client socket path /home/zhengd/.lttng/client-lttng-sessiond (in main() at main.c:5138) DEBUG1 - 14:17:02.699162 [7657/7657]: Application socket path /home/zhengd/.lttng/lttng-ust-sock-5 (in main() at main.c:5139) DEBUG1 - 14:17:02.699170 [7657/7657]: Application wait path /lttng-ust-wait-5-1000 (in main() at main.c:5140) DEBUG1 - 14:17:02.699177 [7657/7657]: LTTng run directory path: /home/zhengd/.lttng (in main() at main.c:5141) DEBUG2 - 14:17:02.699191 [7657/7657]: UST consumer 32 bits err path: /home/zhengd/.lttng/ustconsumerd32/error (in main() at main.c:5150) DEBUG2 - 14:17:02.699200 [7657/7657]: UST consumer 32 bits cmd path: /home/zhengd/.lttng/ustconsumerd32/command (in main() at main.c:5152) DEBUG2 - 14:17:02.699215 [7657/7657]: UST consumer 64 bits err path: /home/zhengd/.lttng/ustconsumerd64/error (in main() at main.c:5161) DEBUG2 - 14:17:02.699224 [7657/7657]: UST consumer 64 bits cmd path: /home/zhengd/.lttng/ustconsumerd64/command (in main() at main.c:5163) DEBUG3 - 14:17:02.699703 [7657/7657]: Created hashtable size 4 at 0x7fe01f923ee0 of type 1 (in lttng_ht_new() at hashtable.c:127) DEBUG3 - 14:17:02.699729 [7657/7657]: Created hashtable size 4 at 0x7fe01f924290 of type 1 (in lttng_ht_new() at hashtable.c:127) DEBUG3 - 14:17:02.699738 [7657/7657]: Created hashtable size 4 at 0x7fe01f9246b0 of type 1 (in lttng_ht_new() at hashtable.c:127) DEBUG3 - 14:17:02.699747 [7657/7657]: Created hashtable size 4 at 0x7fe01f924af0 of type 1 (in lttng_ht_new() at hashtable.c:127) DEBUG2 - 14:17:02.699762 [7657/7657]: Creating consumer directory: /home/zhengd/.lttng/ustconsumerd64 (in set_consumer_sockets() at main.c:4732) DEBUG2 - 14:17:02.700140 [7657/7657]: Creating consumer directory: /home/zhengd/.lttng/ustconsumerd32 (in set_consumer_sockets() at main.c:4732) DEBUG3 - 14:17:02.700467 [7657/7657]: Session daemon client socket 8 and application socket 9 created (in init_daemon_socket() at main.c:4598) DEBUG3 - 14:17:02.700505 [7657/7657]: Created hashtable size 4 at 0x7fe01f924f30 of type 2 (in lttng_ht_new() at hashtable.c:127) DEBUG3 - 14:17:02.700516 [7657/7657]: Global buffer per UID registry initialized (in buffer_reg_init_uid_registry() at buffer-registry.c:99) DEBUG3 - 14:17:02.700525 [7657/7657]: Created hashtable size 4 at 0x7fe01f925370 of type 2 (in lttng_ht_new() at hashtable.c:127) DEBUG3 - 14:17:02.700533 [7657/7657]: Global buffer per PID registry initialized (in buffer_reg_init_pid_registry() at buffer-registry.c:220) DEBUG1 - 14:17:02.700559 [7657/7657]: epoll set max size is 1217638 (in compat_epoll_set_max_size() at compat-epoll.c:290) DEBUG1 - 14:17:02.700571 [7657/7657]: Command subsystem initialized (in cmd_init() at cmd.c:3227) DEBUG1 - 14:17:02.700655 [7657/7657]: Pid 7657 written in file /home/zhengd/.lttng/lttng-sessiond.pid (in utils_create_pid_file() at utils.c:467) DEBUG1 - 14:17:02.700726 [7657/7657]: Pid 5345 written in file /home/zhengd/.lttng/jul.port (in utils_create_pid_file() at utils.c:467) DEBUG1 - 14:17:02.700759 [7657/7657]: TCP inet operation timeout set to 216 sec (in lttcomm_inet_init() at inet.c:529) DEBUG1 - 14:17:02.700771 [7657/7657]: Health check time delta in seconds set to 236 (in health_init() at health.c:73) DEBUG1 - 14:17:02.701124 [7657/7664]: [ust-thread] Manage application notify command (in ust_thread_manage_notify() at ust-thread.c:39) DEBUG3 - 14:17:02.701168 [7657/7664]: [ust-thread] Manage notify polling on 2 fds (in ust_thread_manage_notify() at ust-thread.c:68) DEBUG1 - 14:17:02.701189 [7657/7665]: [jul-thread] Manage JUL application registration. (in jul_thread_manage_registration() at jul-thread.c:260) DEBUG3 - 14:17:02.701217 [7657/7665]: URI string: tcp://localhost (in uri_parse() at uri.c:293) DEBUG2 - 14:17:02.701417 [7657/7665]: IP address resolved to 127.0.0.1 (in set_ip_address() at uri.c:134) DEBUG3 - 14:17:02.701433 [7657/7665]: URI dtype: 1, proto: 1, host: localhost, subdir: , ctrl: 0, data: 0 (in uri_parse() at uri.c:507) DEBUG1 - 14:17:02.701486 [7657/7665]: [jul-thread] Listening on TCP port 5345 and socket 18 (in init_tcp_socket() at jul-thread.c:158) DEBUG3 - 14:17:02.701500 [7657/7665]: [jul-thread] Manage JUL polling on 2 fds (in jul_thread_manage_registration() at jul-thread.c:288) DEBUG1 - 14:17:02.701518 [7657/7666]: [load-session-thread] Load session (in thread_load_session() at load-session-thread.c:90) DEBUG1 - 14:17:02.701543 [7657/7663]: [thread] Manage application started (in thread_manage_apps() at main.c:1425) DEBUG1 - 14:17:02.701569 [7657/7663]: Apps thread polling on 2 fds (in thread_manage_apps() at main.c:1455) DEBUG1 - 14:17:02.701588 [7657/7662]: [thread] Manage application registration started (in thread_registration_apps() at main.c:1935) DEBUG1 - 14:17:02.701617 [7657/7662]: Notifying applications of session daemon state: 1 (in notify_ust_apps() at main.c:756) DEBUG1 - 14:17:02.701661 [7657/7662]: Got the wait shm fd 21 (in get_wait_shm() at shm.c:115) DEBUG1 - 14:17:02.701688 [7657/7662]: Futex wait update active 1 (in futex_wait_update() at futex.c:63) DEBUG1 - 14:17:02.701698 [7657/7662]: Accepting application registration (in thread_registration_apps() at main.c:1972) DEBUG1 - 14:17:02.701714 [7657/7661]: [thread] Dispatch UST command started (in thread_dispatch_ust_registration() at main.c:1711) DEBUG1 - 14:17:02.701729 [7657/7661]: Futex n to 1 prepare done (in futex_nto1_prepare() at futex.c:75) DEBUG1 - 14:17:02.701737 [7657/7661]: Woken up but nothing in the UST command queue (in thread_dispatch_ust_registration() at main.c:1734) DEBUG1 - 14:17:02.701753 [7657/7660]: [thread] Manage client started (in thread_manage_clients() at main.c:3948) DEBUG1 - 14:17:02.701787 [7657/7660]: Accepting client command ... (in thread_manage_clients() at main.c:3995) DEBUG1 - 14:17:02.703087 [7657/7659]: [thread] Manage health check started (in thread_manage_health() at main.c:3762) DEBUG1 - 14:17:02.703222 [7657/7659]: Health check ready (in thread_manage_health() at main.c:3827) DEBUG1 - 14:17:02.703247 [7657/7658]: [ht-thread] startup. (in thread_ht_cleanup() at ht-cleanup.c:36) DEBUG3 - 14:17:02.703298 [7657/7658]: [ht-thread] Polling on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:64) DEBUG1 - 14:17:07.703388 [7657/7662]: UST registration received with pid:6590 ppid:1 uid:1000 gid:1000 sock:25 name:mcd (version 5.0) (in thread_registration_apps() at main.c:2080) DEBUG1 - 14:17:07.703793 [7657/7662]: Futex n to 1 wake done (in futex_nto1_wake() at futex.c:104) DEBUG1 - 14:17:07.703804 [7657/7662]: Accepting application registration (in thread_registration_apps() at main.c:1972) DEBUG1 - 14:17:07.703902 [7657/7662]: UST registration received with pid:6590 ppid:1 uid:1000 gid:1000 sock:26 name:mcd (version 5.0) (in thread_registration_apps() at main.c:2080) DEBUG1 - 14:17:07.703914 [7657/7662]: Futex n to 1 wake done (in futex_nto1_wake() at futex.c:104) DEBUG1 - 14:17:07.703929 [7657/7662]: Accepting application registration (in thread_registration_apps() at main.c:1972) DEBUG1 - 14:17:07.703904 [7657/7661]: Futex n to 1 wait done (in futex_nto1_wait() at futex.c:90) DEBUG1 - 14:17:07.703951 [7657/7661]: Futex n to 1 prepare done (in futex_nto1_prepare() at futex.c:75) DEBUG1 - 14:17:07.703959 [7657/7661]: Dispatching UST registration pid:6590 ppid:1 uid:1000 gid:1000 sock:25 name:mcd (version 5.0) (in thread_dispatch_ust_registration() at main.c:1746) DEBUG3 - 14:17:07.703994 [7657/7661]: UST app creating application for socket 25 (in ust_app_create() at ust-app.c:2848) DEBUG3 - 14:17:07.704009 [7657/7661]: Created hashtable size 4 at 0x7fdff4000a10 of type 2 (in lttng_ht_new() at hashtable.c:127) DEBUG3 - 14:17:07.704085 [7657/7661]: Created hashtable size 4 at 0x7fdff4000e50 of type 1 (in lttng_ht_new() at hashtable.c:127) DEBUG1 - 14:17:07.704107 [7657/7661]: Dispatching UST registration pid:6590 ppid:1 uid:1000 gid:1000 sock:26 name:mcd (version 5.0) (in thread_dispatch_ust_registration() at main.c:1746) DEBUG3 - 14:17:07.704117 [7657/7661]: UST app notify socket 26 is set (in thread_dispatch_ust_registration() at main.c:1803) DEBUG1 - 14:17:07.704137 [7657/7661]: App registered with pid:6590 ppid:1 uid:1000 gid:1000 sock:25 name:mcd notify_sock:26 (version 5.0) (in ust_app_add() at ust-app.c:2936) DEBUG3 - 14:17:07.704350 [7657/7664]: UST thread notify added sock 26 to pollset (in ust_thread_manage_notify() at ust-thread.c:137) DEBUG3 - 14:17:07.704373 [7657/7664]: [ust-thread] Manage notify polling on 3 fds (in ust_thread_manage_notify() at ust-thread.c:68) DEBUG1 - 14:17:07.704389 [7657/7661]: Woken up but nothing in the UST command queue (in thread_dispatch_ust_registration() at main.c:1734) DEBUG1 - 14:17:07.704395 [7657/7663]: Apps with sock 25 added to poll set (in thread_manage_apps() at main.c:1516) DEBUG1 - 14:17:07.704475 [7657/7663]: Apps thread polling on 3 fds (in thread_manage_apps() at main.c:1455) DEBUG1 - 14:17:19.811726 [7657/7660]: Wait for client response (in thread_manage_clients() at main.c:4037) DEBUG1 - 14:17:19.811812 [7657/7660]: Receiving data from client ... (in thread_manage_clients() at main.c:4082) DEBUG1 - 14:17:19.811888 [7657/7660]: Nothing recv() from client... continuing (in thread_manage_clients() at main.c:4086) DEBUG1 - 14:17:19.811904 [7657/7660]: Clean command context structure (in clean_command_ctx() at main.c:736) DEBUG1 - 14:17:19.811915 [7657/7660]: Accepting client command ... (in thread_manage_clients() at main.c:3995) DEBUG1 - 14:17:19.812111 [7657/7660]: Wait for client response (in thread_manage_clients() at main.c:4037) DEBUG1 - 14:17:19.812148 [7657/7660]: Receiving data from client ... (in thread_manage_clients() at main.c:4082) DEBUG1 - 14:17:19.812185 [7657/7660]: Processing client command 8 (in process_client_msg() at main.c:2774) DEBUG1 - 14:17:19.812205 [7657/7660]: Waiting for 1 URIs from client ... (in process_client_msg() at main.c:3412) DEBUG2 - 14:17:19.812224 [7657/7660]: Trying to find session by name Jul7EIGHT (in session_find_by_name() at session.c:169) DEBUG3 - 14:17:19.812244 [7657/7660]: Created hashtable size 4 at 0x7fe008005ee0 of type 1 (in lttng_ht_new() at hashtable.c:127) DEBUG1 - 14:17:19.812257 [7657/7660]: Tracing session Jul7EIGHT created with ID 0 by UID 1000 GID 1000 (in session_create() at session.c:276) DEBUG2 - 14:17:19.812265 [7657/7660]: Trying to find session by name Jul7EIGHT (in session_find_by_name() at session.c:169) DEBUG3 - 14:17:19.812284 [7657/7660]: Created hashtable size 4 at 0x7fe00800b380 of type 1 (in lttng_ht_new() at hashtable.c:127) DEBUG2 - 14:17:19.812294 [7657/7660]: Setting trace directory path from URI to /home/zhengd/lttng-traces/Jul7EIGHT-20150707-141719 (in add_uri_to_consumer() at cmd.c:486) DEBUG1 - 14:17:19.812305 [7657/7660]: Sending response (size: 16, retcode: Success) (in thread_manage_clients() at main.c:4131) DEBUG1 - 14:17:19.812383 [7657/7660]: Clean command context structure (in clean_command_ctx() at main.c:736) DEBUG1 - 14:17:19.812400 [7657/7660]: Accepting client command ... (in thread_manage_clients() at main.c:3995) DEBUG1 - 14:17:27.685176 [7657/7660]: Wait for client response (in thread_manage_clients() at main.c:4037) DEBUG1 - 14:17:27.685704 [7657/7660]: Receiving data from client ... (in thread_manage_clients() at main.c:4082) DEBUG1 - 14:17:27.685737 [7657/7660]: Nothing recv() from client... continuing (in thread_manage_clients() at main.c:4086) DEBUG1 - 14:17:27.685757 [7657/7660]: Clean command context structure (in clean_command_ctx() at main.c:736) DEBUG1 - 14:17:27.685767 [7657/7660]: Accepting client command ... (in thread_manage_clients() at main.c:3995) DEBUG1 - 14:17:27.685777 [7657/7660]: Wait for client response (in thread_manage_clients() at main.c:4037) DEBUG1 - 14:17:27.685791 [7657/7660]: Receiving data from client ... (in thread_manage_clients() at main.c:4082) DEBUG1 - 14:17:27.685915 [7657/7660]: Processing client command 14 (in process_client_msg() at main.c:2774) DEBUG2 - 14:17:27.687025 [7657/7660]: UST app list events done (6 events) (in ust_app_list_events() at ust-app.c:3168) DEBUG1 - 14:17:27.687050 [7657/7660]: Sending response (size: 3520, retcode: Success) (in thread_manage_clients() at main.c:4131) DEBUG1 - 14:17:27.687096 [7657/7660]: Clean command context structure (in clean_command_ctx() at main.c:736) DEBUG1 - 14:17:27.687108 [7657/7660]: Accepting client command ... (in thread_manage_clients() at main.c:3995) DEBUG1 - 14:17:36.115896 [7657/7660]: Wait for client response (in thread_manage_clients() at main.c:4037) DEBUG1 - 14:17:36.115952 [7657/7660]: Receiving data from client ... (in thread_manage_clients() at main.c:4082) DEBUG1 - 14:17:36.116066 [7657/7660]: Nothing recv() from client... continuing (in thread_manage_clients() at main.c:4086) DEBUG1 - 14:17:36.116090 [7657/7660]: Clean command context structure (in clean_command_ctx() at main.c:736) DEBUG1 - 14:17:36.116100 [7657/7660]: Accepting client command ... (in thread_manage_clients() at main.c:3995) DEBUG1 - 14:17:36.116257 [7657/7660]: Wait for client response (in thread_manage_clients() at main.c:4037) DEBUG1 - 14:17:36.116280 [7657/7660]: Receiving data from client ... (in thread_manage_clients() at main.c:4082) DEBUG1 - 14:17:36.116316 [7657/7660]: Processing client command 6 (in process_client_msg() at main.c:2774) DEBUG1 - 14:17:36.116330 [7657/7660]: Getting session Jul7EIGHT by name (in process_client_msg() at main.c:2855) DEBUG2 - 14:17:36.116339 [7657/7660]: Trying to find session by name Jul7EIGHT (in session_find_by_name() at session.c:169) DEBUG1 - 14:17:36.116348 [7657/7660]: Creating UST session (in create_ust_session() at main.c:2654) DEBUG3 - 14:17:36.116361 [7657/7660]: Created hashtable size 4 at 0x7fe008003eb0 of type 0 (in lttng_ht_new() at hashtable.c:127) DEBUG3 - 14:17:36.116372 [7657/7660]: Created hashtable size 4 at 0x7fe0080042f0 of type 0 (in lttng_ht_new() at hashtable.c:127) DEBUG3 - 14:17:36.116398 [7657/7660]: Created hashtable size 4 at 0x7fe008004730 of type 1 (in lttng_ht_new() at hashtable.c:127) DEBUG2 - 14:17:36.116414 [7657/7660]: UST trace session create successful (in trace_ust_create_session() at trace-ust.c:263) DEBUG3 - 14:17:36.116423 [7657/7660]: Copying tracing session consumer output in UST session (in copy_session_consumer() at main.c:2603) DEBUG3 - 14:17:36.116448 [7657/7660]: Created hashtable size 4 at 0x7fe008004b70 of type 1 (in lttng_ht_new() at hashtable.c:127) DEBUG3 - 14:17:36.116463 [7657/7660]: Copy session consumer subdir /ust (in copy_session_consumer() at main.c:2621) DEBUG1 - 14:17:36.116475 [7657/7660]: Spawning consumerd (in spawn_consumerd() at main.c:2292) DEBUG2 - 14:17:36.116776 [7657/7660]: Consumer pid 7681 (in start_consumerd() at main.c:2477) DEBUG2 - 14:17:36.116875 [7657/7660]: Spawning consumer control thread (in start_consumerd() at main.c:2480) DEBUG1 - 14:17:36.116934 [7681/7681]: Using 64-bit UST consumer at: /usr/lib64/lttng/libexec/lttng-consumerd (in spawn_consumerd() at main.c:2372) DEBUG3 - 14:17:36.116964 [7657/7658]: [ht-thread] Polling on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:64) DEBUG1 - 14:17:36.117451 [7657/7682]: [thread] Manage consumer started (in thread_manage_consumer() at main.c:1122) DEBUG2 - 14:17:36.118226 [7657/7682]: Receiving code from consumer err_sock (in thread_manage_consumer() at main.c:1207) DEBUG1 - 14:17:36.219187 [7657/7682]: Consumer command socket ready (fd: 30 (in thread_manage_consumer() at main.c:1241) DEBUG1 - 14:17:36.219228 [7657/7682]: Consumer metadata socket ready (fd: 31) (in thread_manage_consumer() at main.c:1243) DEBUG3 - 14:17:36.219243 [7657/7660]: Consumer socket created (fd: 30) and added to output (in consumer_create_socket() at consumer.c:301) DEBUG1 - 14:17:36.219267 [7657/7660]: Setting relayd for session Jul7EIGHT (in cmd_setup_relayd() at cmd.c:727) DEBUG2 - 14:17:36.219280 [7657/7660]: Trace UST channel channel0 not found by name (in trace_ust_find_channel_by_name() at trace-ust.c:162) DEBUG1 - 14:17:36.219290 [7657/7660]: Enabling channel for session Jul7EIGHT (in cmd_enable_channel() at cmd.c:915) DEBUG2 - 14:17:36.219299 [7657/7660]: Trace UST channel channel0 not found by name (in trace_ust_find_channel_by_name() at trace-ust.c:162) DEBUG3 - 14:17:36.219326 [7657/7660]: Created hashtable size 4 at 0x7fe008005240 of type 0 (in lttng_ht_new() at hashtable.c:127) DEBUG3 - 14:17:36.219337 [7657/7660]: Created hashtable size 4 at 0x7fe008005610 of type 1 (in lttng_ht_new() at hashtable.c:127) DEBUG2 - 14:17:36.219346 [7657/7660]: Trace UST channel channel0 created (in trace_ust_create_channel() at trace-ust.c:331) DEBUG2 - 14:17:36.219355 [7657/7660]: Channel channel0 is being created for UST with buffer 1 and id 0 (in channel_ust_create() at channel.c:348) DEBUG2 - 14:17:36.219384 [7657/7660]: UST app adding channel channel0 to UST domain for session id 0 (in ust_app_create_channel_glb() at ust-app.c:3536) DEBUG2 - 14:17:36.219395 [7657/7660]: UST app pid: 6590 session id 0 not found, creating it (in create_ust_app_session() at ust-app.c:1842) DEBUG3 - 14:17:36.219410 [7657/7660]: Created hashtable size 4 at 0x7fe008005a30 of type 0 (in lttng_ht_new() at hashtable.c:127) DEBUG2 - 14:17:36.219442 [7657/7660]: Shadow copy of session handle -1 (in shadow_copy_session() at ust-app.c:1598) DEBUG3 - 14:17:36.219454 [7657/7660]: Buffer registry per UID find id: 0, ABI: 32, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.c:195) DEBUG3 - 14:17:36.219464 [7657/7660]: Created hashtable size 4 at 0x7fe008011a90 of type 2 (in lttng_ht_new() at hashtable.c:127) DEBUG3 - 14:17:36.219473 [7657/7660]: Buffer registry per UID created id: 0, ABI: 32, uid: 1000, domain: 2 (in buffer_reg_uid_create() at buffer-registry.c:144) DEBUG3 - 14:17:36.219480 [7657/7660]: Buffer registry per UID adding to global registry with id: 0 (in buffer_reg_uid_add() at buffer-registry.c:166) DEBUG3 - 14:17:36.219492 [7657/7660]: Created hashtable size 4 at 0x7fe008011f70 of type 2 (in lttng_ht_new() at hashtable.c:127) DEBUG3 - 14:17:36.219625 [7657/7660]: Append to metadata: "typealias integer { size = 8; align = 8; signed = false; } := uint8_t; typealias integer { size = 16; align = 8; signed = false; } := uint16_t; typealias integer { size = 32; align = 8; signed = false; } := uint32_t; typealias integer { size = 64; align = 8; signed = false; } := uint64_t; typealias integer { size = 32; align = 8; signed = false; } := unsigned long; typealias integer { size = 5; align = 1; signed = false; } := uint5_t; typealias integer { size = 27; align = 1; signed = false; } := uint27_t; trace { major = 1; minor = 8; uuid = "c92fd4c7-d5e9-459b-9a26-5b2da8a8622e"; byte_order = le; packet.header := struct { uint32_t magic; uint8_t uuid[16]; uint32_t stream_id; }; }; " (in lttng_metadata_printf() at ust-metadata.c:151) DEBUG3 - 14:17:36.219641 [7657/7660]: Append to metadata: "env { hostname = "dilong"; domain = "ust"; tracer_name = "lttng-ust"; tracer_major = 2; tracer_minor = 5; " (in lttng_metadata_printf() at ust-metadata.c:151) DEBUG3 - 14:17:36.219650 [7657/7660]: Append to metadata: "}; " (in lttng_metadata_printf() at ust-metadata.c:151) DEBUG3 - 14:17:36.219658 [7657/7660]: Append to metadata: "clock { name = monotonic; " (in lttng_metadata_printf() at ust-metadata.c:151) DEBUG3 - 14:17:36.219724 [7657/7660]: Append to metadata: " uuid = "7383836d-9dd7-4556-bb2b-e2478ac889ee"; " (in lttng_metadata_printf() at ust-metadata.c:151) DEBUG3 - 14:17:36.219792 [7657/7660]: Append to metadata: " description = "Monotonic Clock"; freq = 1000000000; /* Frequency, in Hz */ /* clock value offset from Epoch is: offset * (1/freq) */ offset = 1436272809318801513; }; " (in lttng_metadata_printf() at ust-metadata.c:151) DEBUG3 - 14:17:36.219804 [7657/7660]: Append to metadata: "typealias integer { size = 27; align = 1; signed = false; map = clock.monotonic.value; } := uint27_clock_monotonic_t; typealias integer { size = 32; align = 8; signed = false; map = clock.monotonic.value; } := uint32_clock_monotonic_t; typealias integer { size = 64; align = 8; signed = false; map = clock.monotonic.value; } := uint64_clock_monotonic_t; " (in lttng_metadata_printf() at ust-metadata.c:151) DEBUG3 - 14:17:36.219854 [7657/7660]: Append to metadata: "struct packet_context { uint64_clock_monotonic_t timestamp_begin; uint64_clock_monotonic_t timestamp_end; uint64_t content_size; uint64_t packet_size; unsigned long events_discarded; uint32_t cpu_id; }; " (in lttng_metadata_printf() at ust-metadata.c:151) DEBUG3 - 14:17:36.219886 [7657/7660]: Append to metadata: "struct event_header_compact { enum : uint5_t { compact = 0 ... 30, extended = 31 } id; variant { struct { uint27_clock_monotonic_t timestamp; } compact; struct { uint32_t id; uint64_clock_monotonic_t timestamp; } extended; } v; } align(8); struct event_header_large { enum : uint16_t { compact = 0 ... 65534, extended = 65535 } id; variant { struct { uint32_clock_monotonic_t timestamp; } compact; struct { uint32_t id; uint64_clock_monotonic_t timestamp; } extended; } v; } align(8); " (in lttng_metadata_printf() at ust-metadata.c:151) DEBUG3 - 14:17:36.219897 [7657/7660]: UST app buffer registry per UID created successfully (in setup_buffer_reg_uid() at ust-app.c:1804) DEBUG2 - 14:17:36.220091 [7657/7660]: UST app session created successfully with handle 3 (in create_ust_app_session() at ust-app.c:1910) DEBUG3 - 14:17:36.220119 [7657/7660]: Created hashtable size 4 at 0x7fe0080125d0 of type 1 (in lttng_ht_new() at hashtable.c:127) DEBUG3 - 14:17:36.220130 [7657/7660]: Created hashtable size 4 at 0x7fe008012a10 of type 0 (in lttng_ht_new() at hashtable.c:127) DEBUG3 - 14:17:36.220138 [7657/7660]: UST app channel channel0 allocated (in alloc_ust_app_channel() at ust-app.c:882) DEBUG2 - 14:17:36.220146 [7657/7660]: UST app shadow copy of channel channel0 started (in shadow_copy_channel() at ust-app.c:1525) DEBUG3 - 14:17:36.220154 [7657/7660]: UST app shadow copy of channel channel0 done (in shadow_copy_channel() at ust-app.c:1575) DEBUG1 - 14:17:36.220177 [7657/7660]: UST app creating channel channel0 with per UID buffers (in create_channel_per_uid() at ust-app.c:2437) DEBUG3 - 14:17:36.220188 [7657/7660]: Buffer registry per UID find id: 0, ABI: 32, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.c:195) DEBUG2 - 14:17:36.220197 [7657/7660]: UST app creating buffer registry channel for channel0 (in create_buffer_reg_channel() at ust-app.c:2290) DEBUG3 - 14:17:36.220205 [7657/7660]: Buffer registry channel create with key: 0 (in buffer_reg_channel_create() at buffer-registry.c:326) DEBUG3 - 14:17:36.220214 [7657/7660]: Created hashtable size 4 at 0x7fe008012f60 of type 0 (in lttng_ht_new() at hashtable.c:127) Error: Consumer socket fd -1 not found in consumer obj 0x7fe00800b7a0 DEBUG3 - 14:17:36.220228 [7657/7660]: UST registry channel finding key 0 (in ust_registry_channel_find() at ust-registry.c:489) DEBUG3 - 14:17:36.220308 [7657/7660]: Buffer registry channel destroy with key 0 (in buffer_reg_channel_destroy() at buffer-registry.c:498) DEBUG3 - 14:17:36.220323 [7657/7660]: UST app deleting channel channel0 (in delete_ust_app_channel() at ust-app.c:374) DEBUG3 - 14:17:36.220333 [7657/7660]: Buffer registry per UID find id: 0, ABI: 32, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.c:195) DEBUG1 - 14:17:36.220395 [7657/7660]: Sending response (size: 16, retcode: UST create channel failed) (in thread_manage_clients() at main.c:4131) DEBUG3 - 14:17:36.220470 [7657/7658]: [ht-thread] Polling on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:64) DEBUG3 - 14:17:36.220496 [7657/7658]: [ht-thread] Polling on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:64) DEBUG3 - 14:17:36.220507 [7657/7658]: [ht-thread] Polling on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:64) DEBUG1 - 14:17:36.220782 [7657/7660]: Clean command context structure (in clean_command_ctx() at main.c:736) DEBUG1 - 14:17:36.220855 [7657/7660]: Accepting client command ... (in thread_manage_clients() at main.c:3995) DEBUG2 - 14:17:36.230673 [7657/7689]: Trace destroy UST channel channel0 (in _trace_ust_destroy_channel() at trace-ust.c:630) DEBUG3 - 14:17:36.230717 [7657/7658]: [ht-thread] Polling on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:64) DEBUG3 - 14:17:36.230743 [7657/7658]: [ht-thread] Polling on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:64) DEBUG3 - 14:17:36.230762 [7657/7658]: [ht-thread] Polling on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:64) DEBUG1 - 14:17:42.483429 [7657/7660]: Wait for client response (in thread_manage_clients() at main.c:4037) DEBUG1 - 14:17:42.483502 [7657/7660]: Receiving data from client ... (in thread_manage_clients() at main.c:4082) DEBUG1 - 14:17:42.483516 [7657/7660]: Nothing recv() from client... continuing (in thread_manage_clients() at main.c:4086) DEBUG1 - 14:17:42.483551 [7657/7660]: Clean command context structure (in clean_command_ctx() at main.c:736) DEBUG1 - 14:17:42.483562 [7657/7660]: Accepting client command ... (in thread_manage_clients() at main.c:3995) DEBUG1 - 14:17:42.483571 [7657/7660]: Wait for client response (in thread_manage_clients() at main.c:4037) DEBUG1 - 14:17:42.483586 [7657/7660]: Receiving data from client ... (in thread_manage_clients() at main.c:4082) DEBUG1 - 14:17:42.483607 [7657/7660]: Processing client command 6 (in process_client_msg() at main.c:2774) DEBUG1 - 14:17:42.483617 [7657/7660]: Getting session Jul7EIGHT by name (in process_client_msg() at main.c:2855) DEBUG2 - 14:17:42.483626 [7657/7660]: Trying to find session by name Jul7EIGHT (in session_find_by_name() at session.c:169) DEBUG3 - 14:17:42.483639 [7657/7660]: Consumer socket created (fd: 30) and added to output (in consumer_create_socket() at consumer.c:301) DEBUG1 - 14:17:42.483648 [7657/7660]: Setting relayd for session Jul7EIGHT (in cmd_setup_relayd() at cmd.c:727) DEBUG2 - 14:17:42.483657 [7657/7660]: Trace UST channel channel0 not found by name (in trace_ust_find_channel_by_name() at trace-ust.c:162) DEBUG1 - 14:17:42.483667 [7657/7660]: Enabling channel for session Jul7EIGHT (in cmd_enable_channel() at cmd.c:915) DEBUG2 - 14:17:42.483675 [7657/7660]: Trace UST channel channel0 not found by name (in trace_ust_find_channel_by_name() at trace-ust.c:162) DEBUG3 - 14:17:42.483686 [7657/7660]: Created hashtable size 4 at 0x7fe008005240 of type 0 (in lttng_ht_new() at hashtable.c:127) DEBUG3 - 14:17:42.483695 [7657/7660]: Created hashtable size 4 at 0x7fe008005680 of type 1 (in lttng_ht_new() at hashtable.c:127) DEBUG2 - 14:17:42.483707 [7657/7660]: Trace UST channel channel0 created (in trace_ust_create_channel() at trace-ust.c:331) DEBUG2 - 14:17:42.483714 [7657/7660]: Channel channel0 is being created for UST with buffer 1 and id 1 (in channel_ust_create() at channel.c:348) DEBUG2 - 14:17:42.483722 [7657/7660]: UST app adding channel channel0 to UST domain for session id 0 (in ust_app_create_channel_glb() at ust-app.c:3536) DEBUG2 - 14:17:42.483731 [7657/7660]: UST app pid: 6590 session id 0 not found, creating it (in create_ust_app_session() at ust-app.c:1842) DEBUG3 - 14:17:42.483741 [7657/7660]: Created hashtable size 4 at 0x7fe008012390 of type 0 (in lttng_ht_new() at hashtable.c:127) DEBUG2 - 14:17:42.483762 [7657/7660]: Shadow copy of session handle -1 (in shadow_copy_session() at ust-app.c:1598) DEBUG3 - 14:17:42.483773 [7657/7660]: Buffer registry per UID find id: 0, ABI: 32, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.c:195) DEBUG2 - 14:17:42.484675 [7657/7660]: UST app session created successfully with handle 3 (in create_ust_app_session() at ust-app.c:1910) DEBUG3 - 14:17:42.484710 [7657/7660]: Created hashtable size 4 at 0x7fe0080128e0 of type 1 (in lttng_ht_new() at hashtable.c:127) DEBUG3 - 14:17:42.484724 [7657/7660]: Created hashtable size 4 at 0x7fe008012d20 of type 0 (in lttng_ht_new() at hashtable.c:127) DEBUG3 - 14:17:42.484733 [7657/7660]: UST app channel channel0 allocated (in alloc_ust_app_channel() at ust-app.c:882) DEBUG2 - 14:17:42.484741 [7657/7660]: UST app shadow copy of channel channel0 started (in shadow_copy_channel() at ust-app.c:1525) DEBUG3 - 14:17:42.484750 [7657/7660]: UST app shadow copy of channel channel0 done (in shadow_copy_channel() at ust-app.c:1575) DEBUG1 - 14:17:42.484759 [7657/7660]: UST app creating channel channel0 with per UID buffers (in create_channel_per_uid() at ust-app.c:2437) DEBUG3 - 14:17:42.484767 [7657/7660]: Buffer registry per UID find id: 0, ABI: 32, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.c:195) DEBUG2 - 14:17:42.484786 [7657/7660]: UST app creating buffer registry channel for channel0 (in create_buffer_reg_channel() at ust-app.c:2290) DEBUG3 - 14:17:42.484795 [7657/7660]: Buffer registry channel create with key: 1 (in buffer_reg_channel_create() at buffer-registry.c:326) DEBUG3 - 14:17:42.484805 [7657/7660]: Created hashtable size 4 at 0x7fe0080146d0 of type 0 (in lttng_ht_new() at hashtable.c:127) Error: Consumer socket fd -1 not found in consumer obj 0x7fe00800b7a0 DEBUG3 - 14:17:42.484818 [7657/7660]: UST registry channel finding key 1 (in ust_registry_channel_find() at ust-registry.c:489) DEBUG3 - 14:17:42.484925 [7657/7660]: Buffer registry channel destroy with key 1 (in buffer_reg_channel_destroy() at buffer-registry.c:498) DEBUG3 - 14:17:42.484944 [7657/7660]: UST app deleting channel channel0 (in delete_ust_app_channel() at ust-app.c:374) DEBUG3 - 14:17:42.484955 [7657/7660]: Buffer registry per UID find id: 0, ABI: 32, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.c:195) DEBUG1 - 14:17:42.485108 [7657/7660]: Sending response (size: 16, retcode: UST create channel failed) (in thread_manage_clients() at main.c:4131) DEBUG1 - 14:17:42.485139 [7657/7660]: Clean command context structure (in clean_command_ctx() at main.c:736) DEBUG1 - 14:17:42.485149 [7657/7660]: Accepting client command ... (in thread_manage_clients() at main.c:3995) DEBUG3 - 14:17:42.495105 [7657/7658]: [ht-thread] Polling on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:64) DEBUG3 - 14:17:42.495162 [7657/7658]: [ht-thread] Polling on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:64) DEBUG3 - 14:17:42.495185 [7657/7658]: [ht-thread] Polling on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:64) DEBUG3 - 14:17:42.495206 [7657/7658]: [ht-thread] Polling on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:64) DEBUG2 - 14:17:42.495220 [7657/7689]: Trace destroy UST channel channel0 (in _trace_ust_destroy_channel() at trace-ust.c:630) DEBUG3 - 14:17:42.495239 [7657/7658]: [ht-thread] Polling on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:64) DEBUG3 - 14:17:42.495260 [7657/7658]: [ht-thread] Polling on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:64) DEBUG1 - 14:17:49.229924 [7657/7660]: Wait for client response (in thread_manage_clients() at main.c:4037) DEBUG1 - 14:17:49.229995 [7657/7660]: Receiving data from client ... (in thread_manage_clients() at main.c:4082) DEBUG1 - 14:17:49.230261 [7657/7660]: Nothing recv() from client... continuing (in thread_manage_clients() at main.c:4086) DEBUG1 - 14:17:49.230464 [7657/7660]: Clean command context structure (in clean_command_ctx() at main.c:736) DEBUG1 - 14:17:49.230478 [7657/7660]: Accepting client command ... (in thread_manage_clients() at main.c:3995) DEBUG1 - 14:17:49.230646 [7657/7660]: Wait for client response (in thread_manage_clients() at main.c:4037) DEBUG1 - 14:17:49.230671 [7657/7660]: Receiving data from client ... (in thread_manage_clients() at main.c:4082) DEBUG1 - 14:17:49.230710 [7657/7660]: Processing client command 0 (in process_client_msg() at main.c:2774) DEBUG1 - 14:17:49.230723 [7657/7660]: Getting session Jul7EIGHT by name (in process_client_msg() at main.c:2855) DEBUG2 - 14:17:49.230733 [7657/7660]: Trying to find session by name Jul7EIGHT (in session_find_by_name() at session.c:169) DEBUG3 - 14:17:49.230747 [7657/7660]: Consumer socket created (fd: 30) and added to output (in consumer_create_socket() at consumer.c:301) DEBUG1 - 14:17:49.230757 [7657/7660]: Setting relayd for session Jul7EIGHT (in cmd_setup_relayd() at cmd.c:727) DEBUG3 - 14:17:49.230772 [7657/7660]: Created hashtable size 4 at 0x7fe008005240 of type 0 (in lttng_ht_new() at hashtable.c:127) DEBUG3 - 14:17:49.230782 [7657/7660]: Created hashtable size 4 at 0x7fe008005680 of type 1 (in lttng_ht_new() at hashtable.c:127) DEBUG2 - 14:17:49.230791 [7657/7660]: Trace UST channel channel0 created (in trace_ust_create_channel() at trace-ust.c:331) DEBUG2 - 14:17:49.230799 [7657/7660]: Channel channel0 is being created for UST with buffer 1 and id 2 (in channel_ust_create() at channel.c:348) DEBUG2 - 14:17:49.230881 [7657/7660]: UST app adding channel channel0 to UST domain for session id 0 (in ust_app_create_channel_glb() at ust-app.c:3536) DEBUG2 - 14:17:49.230904 [7657/7660]: UST app pid: 6590 session id 0 not found, creating it (in create_ust_app_session() at ust-app.c:1842) DEBUG3 - 14:17:49.230916 [7657/7660]: Created hashtable size 4 at 0x7fe008012390 of type 0 (in lttng_ht_new() at hashtable.c:127) DEBUG2 - 14:17:49.230941 [7657/7660]: Shadow copy of session handle -1 (in shadow_copy_session() at ust-app.c:1598) DEBUG3 - 14:17:49.230952 [7657/7660]: Buffer registry per UID find id: 0, ABI: 32, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.c:195) DEBUG2 - 14:17:49.231103 [7657/7660]: UST app session created successfully with handle 3 (in create_ust_app_session() at ust-app.c:1910) DEBUG3 - 14:17:49.231120 [7657/7660]: Created hashtable size 4 at 0x7fe0080128e0 of type 1 (in lttng_ht_new() at hashtable.c:127) DEBUG3 - 14:17:49.231130 [7657/7660]: Created hashtable size 4 at 0x7fe008012d20 of type 0 (in lttng_ht_new() at hashtable.c:127) DEBUG3 - 14:17:49.231138 [7657/7660]: UST app channel channel0 allocated (in alloc_ust_app_channel() at ust-app.c:882) DEBUG2 - 14:17:49.231145 [7657/7660]: UST app shadow copy of channel channel0 started (in shadow_copy_channel() at ust-app.c:1525) DEBUG3 - 14:17:49.231153 [7657/7660]: UST app shadow copy of channel channel0 done (in shadow_copy_channel() at ust-app.c:1575) DEBUG1 - 14:17:49.231161 [7657/7660]: UST app creating channel channel0 with per UID buffers (in create_channel_per_uid() at ust-app.c:2437) DEBUG3 - 14:17:49.231169 [7657/7660]: Buffer registry per UID find id: 0, ABI: 32, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.c:195) DEBUG2 - 14:17:49.231177 [7657/7660]: UST app creating buffer registry channel for channel0 (in create_buffer_reg_channel() at ust-app.c:2290) DEBUG3 - 14:17:49.231185 [7657/7660]: Buffer registry channel create with key: 2 (in buffer_reg_channel_create() at buffer-registry.c:326) DEBUG3 - 14:17:49.231194 [7657/7660]: Created hashtable size 4 at 0x7fe0080146d0 of type 0 (in lttng_ht_new() at hashtable.c:127) Error: Consumer socket fd -1 not found in consumer obj 0x7fe00800b7a0 DEBUG3 - 14:17:49.231208 [7657/7660]: UST registry channel finding key 2 (in ust_registry_channel_find() at ust-registry.c:489) DEBUG3 - 14:17:49.231227 [7657/7660]: Buffer registry channel destroy with key 2 (in buffer_reg_channel_destroy() at buffer-registry.c:498) DEBUG3 - 14:17:49.231237 [7657/7660]: UST app deleting channel channel0 (in delete_ust_app_channel() at ust-app.c:374) DEBUG3 - 14:17:49.231246 [7657/7660]: Buffer registry per UID find id: 0, ABI: 32, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.c:195) DEBUG1 - 14:17:49.231306 [7657/7660]: Sending response (size: 16, retcode: UST create channel failed) (in thread_manage_clients() at main.c:4131) DEBUG1 - 14:17:49.231332 [7657/7660]: Clean command context structure (in clean_command_ctx() at main.c:736) DEBUG1 - 14:17:49.231342 [7657/7660]: Accepting client command ... (in thread_manage_clients() at main.c:3995) DEBUG1 - 14:17:49.231684 [7657/7660]: Wait for client response (in thread_manage_clients() at main.c:4037) DEBUG1 - 14:17:49.231712 [7657/7660]: Receiving data from client ... (in thread_manage_clients() at main.c:4082) DEBUG1 - 14:17:49.231747 [7657/7660]: Processing client command 0 (in process_client_msg() at main.c:2774) DEBUG1 - 14:17:49.231760 [7657/7660]: Getting session Jul7EIGHT by name (in process_client_msg() at main.c:2855) DEBUG2 - 14:17:49.231768 [7657/7660]: Trying to find session by name Jul7EIGHT (in session_find_by_name() at session.c:169) DEBUG3 - 14:17:49.231778 [7657/7660]: Consumer socket created (fd: 30) and added to output (in consumer_create_socket() at consumer.c:301) DEBUG1 - 14:17:49.231787 [7657/7660]: Setting relayd for session Jul7EIGHT (in cmd_setup_relayd() at cmd.c:727) DEBUG3 - 14:17:49.231799 [7657/7660]: Created hashtable size 4 at 0x7fe008014c20 of type 0 (in lttng_ht_new() at hashtable.c:127) DEBUG3 - 14:17:49.231886 [7657/7660]: Created hashtable size 4 at 0x7fe008014ec0 of type 1 (in lttng_ht_new() at hashtable.c:127) DEBUG2 - 14:17:49.231908 [7657/7660]: Trace UST channel channel0 created (in trace_ust_create_channel() at trace-ust.c:331) DEBUG2 - 14:17:49.231916 [7657/7660]: Channel channel0 is being created for UST with buffer 1 and id 3 (in channel_ust_create() at channel.c:348) DEBUG2 - 14:17:49.231924 [7657/7660]: UST app adding channel channel0 to UST domain for session id 0 (in ust_app_create_channel_glb() at ust-app.c:3536) DEBUG2 - 14:17:49.231950 [7657/7660]: UST app pid: 6590 session id 0 not found, creating it (in create_ust_app_session() at ust-app.c:1842) DEBUG3 - 14:17:49.231965 [7657/7660]: Created hashtable size 4 at 0x7fe008016370 of type 0 (in lttng_ht_new() at hashtable.c:127) DEBUG2 - 14:17:49.231987 [7657/7660]: Shadow copy of session handle -1 (in shadow_copy_session() at ust-app.c:1598) DEBUG3 - 14:17:49.231998 [7657/7660]: Buffer registry per UID find id: 0, ABI: 32, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.c:195) DEBUG2 - 14:17:49.232122 [7657/7660]: UST app session created successfully with handle 3 (in create_ust_app_session() at ust-app.c:1910) DEBUG3 - 14:17:49.232141 [7657/7660]: Created hashtable size 4 at 0x7fe008016940 of type 1 (in lttng_ht_new() at hashtable.c:127) DEBUG3 - 14:17:49.232156 [7657/7660]: Created hashtable size 4 at 0x7fe008016d40 of type 0 (in lttng_ht_new() at hashtable.c:127) DEBUG3 - 14:17:49.232165 [7657/7660]: UST app channel channel0 allocated (in alloc_ust_app_channel() at ust-app.c:882) DEBUG2 - 14:17:49.232173 [7657/7660]: UST app shadow copy of channel channel0 started (in shadow_copy_channel() at ust-app.c:1525) DEBUG3 - 14:17:49.232180 [7657/7660]: UST app shadow copy of channel channel0 done (in shadow_copy_channel() at ust-app.c:1575) DEBUG1 - 14:17:49.232188 [7657/7660]: UST app creating channel channel0 with per UID buffers (in create_channel_per_uid() at ust-app.c:2437) DEBUG3 - 14:17:49.232195 [7657/7660]: Buffer registry per UID find id: 0, ABI: 32, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.c:195) DEBUG2 - 14:17:49.232203 [7657/7660]: UST app creating buffer registry channel for channel0 (in create_buffer_reg_channel() at ust-app.c:2290) DEBUG3 - 14:17:49.232211 [7657/7660]: Buffer registry channel create with key: 3 (in buffer_reg_channel_create() at buffer-registry.c:326) DEBUG3 - 14:17:49.232220 [7657/7660]: Created hashtable size 4 at 0x7fe008017290 of type 0 (in lttng_ht_new() at hashtable.c:127) Error: Consumer socket fd -1 not found in consumer obj 0x7fe00800b7a0 DEBUG3 - 14:17:49.232232 [7657/7660]: UST registry channel finding key 3 (in ust_registry_channel_find() at ust-registry.c:489) DEBUG3 - 14:17:49.232242 [7657/7660]: Buffer registry channel destroy with key 3 (in buffer_reg_channel_destroy() at buffer-registry.c:498) DEBUG3 - 14:17:49.232251 [7657/7660]: UST app deleting channel channel0 (in delete_ust_app_channel() at ust-app.c:374) DEBUG3 - 14:17:49.232259 [7657/7660]: Buffer registry per UID find id: 0, ABI: 32, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.c:195) DEBUG1 - 14:17:49.232305 [7657/7660]: Sending response (size: 16, retcode: UST create channel failed) (in thread_manage_clients() at main.c:4131) DEBUG1 - 14:17:49.232330 [7657/7660]: Clean command context structure (in clean_command_ctx() at main.c:736) DEBUG1 - 14:17:49.232339 [7657/7660]: Accepting client command ... (in thread_manage_clients() at main.c:3995) DEBUG1 - 14:17:49.232620 [7657/7660]: Wait for client response (in thread_manage_clients() at main.c:4037) DEBUG1 - 14:17:49.232644 [7657/7660]: Receiving data from client ... (in thread_manage_clients() at main.c:4082) DEBUG1 - 14:17:49.232677 [7657/7660]: Processing client command 0 (in process_client_msg() at main.c:2774) DEBUG1 - 14:17:49.232690 [7657/7660]: Getting session Jul7EIGHT by name (in process_client_msg() at main.c:2855) DEBUG2 - 14:17:49.232698 [7657/7660]: Trying to find session by name Jul7EIGHT (in session_find_by_name() at session.c:169) DEBUG3 - 14:17:49.232715 [7657/7660]: Consumer socket created (fd: 30) and added to output (in consumer_create_socket() at consumer.c:301) DEBUG1 - 14:17:49.232724 [7657/7660]: Setting relayd for session Jul7EIGHT (in cmd_setup_relayd() at cmd.c:727) DEBUG3 - 14:17:49.232735 [7657/7660]: Created hashtable size 4 at 0x7fe008017960 of type 0 (in lttng_ht_new() at hashtable.c:127) DEBUG3 - 14:17:49.232748 [7657/7660]: Created hashtable size 4 at 0x7fe008017d30 of type 1 (in lttng_ht_new() at hashtable.c:127) DEBUG2 - 14:17:49.232757 [7657/7660]: Trace UST channel channel0 created (in trace_ust_create_channel() at trace-ust.c:331) DEBUG2 - 14:17:49.232765 [7657/7660]: Channel channel0 is being created for UST with buffer 1 and id 4 (in channel_ust_create() at channel.c:348) DEBUG2 - 14:17:49.232773 [7657/7660]: UST app adding channel channel0 to UST domain for session id 0 (in ust_app_create_channel_glb() at ust-app.c:3536) DEBUG2 - 14:17:49.232781 [7657/7660]: UST app pid: 6590 session id 0 not found, creating it (in create_ust_app_session() at ust-app.c:1842) DEBUG3 - 14:17:49.232793 [7657/7660]: Created hashtable size 4 at 0x7fe008019270 of type 0 (in lttng_ht_new() at hashtable.c:127) DEBUG2 - 14:17:49.232857 [7657/7660]: Shadow copy of session handle -1 (in shadow_copy_session() at ust-app.c:1598) DEBUG3 - 14:17:49.232879 [7657/7660]: Buffer registry per UID find id: 0, ABI: 32, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.c:195) DEBUG2 - 14:17:49.232938 [7657/7660]: UST app session created successfully with handle 3 (in create_ust_app_session() at ust-app.c:1910) DEBUG3 - 14:17:49.232953 [7657/7660]: Created hashtable size 4 at 0x7fe0080198d0 of type 1 (in lttng_ht_new() at hashtable.c:127) DEBUG3 - 14:17:49.232970 [7657/7660]: Created hashtable size 4 at 0x7fe008019d10 of type 0 (in lttng_ht_new() at hashtable.c:127) DEBUG3 - 14:17:49.232979 [7657/7660]: UST app channel channel0 allocated (in alloc_ust_app_channel() at ust-app.c:882) DEBUG2 - 14:17:49.232986 [7657/7660]: UST app shadow copy of channel channel0 started (in shadow_copy_channel() at ust-app.c:1525) DEBUG3 - 14:17:49.232994 [7657/7660]: UST app shadow copy of channel channel0 done (in shadow_copy_channel() at ust-app.c:1575) DEBUG1 - 14:17:49.233002 [7657/7660]: UST app creating channel channel0 with per UID buffers (in create_channel_per_uid() at ust-app.c:2437) DEBUG3 - 14:17:49.233009 [7657/7660]: Buffer registry per UID find id: 0, ABI: 32, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.c:195) DEBUG2 - 14:17:49.233017 [7657/7660]: UST app creating buffer registry channel for channel0 (in create_buffer_reg_channel() at ust-app.c:2290) DEBUG3 - 14:17:49.233025 [7657/7660]: Buffer registry channel create with key: 4 (in buffer_reg_channel_create() at buffer-registry.c:326) DEBUG3 - 14:17:49.233034 [7657/7660]: Created hashtable size 4 at 0x7fe00801a260 of type 0 (in lttng_ht_new() at hashtable.c:127) Error: Consumer socket fd -1 not found in consumer obj 0x7fe00800b7a0 DEBUG3 - 14:17:49.233046 [7657/7660]: UST registry channel finding key 4 (in ust_registry_channel_find() at ust-registry.c:489) DEBUG3 - 14:17:49.233055 [7657/7660]: Buffer registry channel destroy with key 4 (in buffer_reg_channel_destroy() at buffer-registry.c:498) DEBUG3 - 14:17:49.233064 [7657/7660]: UST app deleting channel channel0 (in delete_ust_app_channel() at ust-app.c:374) DEBUG3 - 14:17:49.233072 [7657/7660]: Buffer registry per UID find id: 0, ABI: 32, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.c:195) DEBUG1 - 14:17:49.233117 [7657/7660]: Sending response (size: 16, retcode: UST create channel failed) (in thread_manage_clients() at main.c:4131) DEBUG1 - 14:17:49.233140 [7657/7660]: Clean command context structure (in clean_command_ctx() at main.c:736) DEBUG1 - 14:17:49.233150 [7657/7660]: Accepting client command ... (in thread_manage_clients() at main.c:3995) DEBUG2 - 14:17:49.241932 [7657/7689]: Trace destroy UST channel channel0 (in _trace_ust_destroy_channel() at trace-ust.c:630) DEBUG2 - 14:17:49.242067 [7657/7689]: Trace destroy UST channel channel0 (in _trace_ust_destroy_channel() at trace-ust.c:630) DEBUG2 - 14:17:49.242085 [7657/7689]: Trace destroy UST channel channel0 (in _trace_ust_destroy_channel() at trace-ust.c:630) DEBUG3 - 14:17:49.241946 [7657/7658]: [ht-thread] Polling on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:64) DEBUG3 - 14:17:49.242202 [7657/7658]: [ht-thread] Polling on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:64) DEBUG3 - 14:17:49.242216 [7657/7658]: [ht-thread] Polling on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:64) DEBUG3 - 14:17:49.242227 [7657/7658]: [ht-thread] Polling on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:64) DEBUG3 - 14:17:49.242287 [7657/7658]: [ht-thread] Polling on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:64) DEBUG3 - 14:17:49.242301 [7657/7658]: [ht-thread] Polling on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:64) DEBUG3 - 14:17:49.242311 [7657/7658]: [ht-thread] Polling on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:64) DEBUG3 - 14:17:49.242321 [7657/7658]: [ht-thread] Polling on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:64) DEBUG3 - 14:17:49.242330 [7657/7658]: [ht-thread] Polling on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:64) DEBUG3 - 14:17:49.242340 [7657/7658]: [ht-thread] Polling on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:64) DEBUG3 - 14:17:49.242350 [7657/7658]: [ht-thread] Polling on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:64) DEBUG3 - 14:17:49.242359 [7657/7658]: [ht-thread] Polling on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:64) DEBUG3 - 14:17:49.242369 [7657/7658]: [ht-thread] Polling on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:64) DEBUG3 - 14:17:49.242378 [7657/7658]: [ht-thread] Polling on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:64) DEBUG3 - 14:17:49.242388 [7657/7658]: [ht-thread] Polling on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:64) DEBUG3 - 14:17:49.242397 [7657/7658]: [ht-thread] Polling on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:64) DEBUG3 - 14:17:49.242407 [7657/7658]: [ht-thread] Polling on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:64) DEBUG3 - 14:17:49.242417 [7657/7658]: [ht-thread] Polling on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:64) DEBUG1 - 14:18:02.442353 [7657/7657]: SIGINT caught (in sighandler() at main.c:4797) DEBUG1 - 14:18:02.442404 [7657/7657]: Terminating all threads (in stop_threads() at main.c:459) DEBUG1 - 14:18:02.442460 [7657/7657]: Futex n to 1 wake done (in futex_nto1_wake() at futex.c:104) DEBUG1 - 14:18:02.442626 [7657/7682]: consumer thread cleanup completed (in thread_manage_consumer() at main.c:1410) DEBUG1 - 14:18:02.442690 [7657/7659]: Health check thread dying (in thread_manage_health() at main.c:3921) DEBUG1 - 14:18:02.442769 [7657/7662]: Notifying applications of session daemon state: 0 (in notify_ust_apps() at main.c:756) DEBUG1 - 14:18:02.442860 [7657/7662]: Got the wait shm fd 6 (in get_wait_shm() at shm.c:115) DEBUG1 - 14:18:02.442893 [7657/7662]: Futex wait update active 0 (in futex_wait_update() at futex.c:63) DEBUG1 - 14:18:02.442924 [7657/7662]: UST Registration thread cleanup complete (in thread_registration_apps() at main.c:2123) DEBUG1 - 14:18:02.442991 [7657/7663]: Application communication apps thread cleanup complete (in thread_manage_apps() at main.c:1558) DEBUG3 - 14:18:02.443044 [7657/7665]: [jul-thread] 1 fd ready (in jul_thread_manage_registration() at jul-thread.c:303) DEBUG3 - 14:18:02.443062 [7657/7665]: [jul-thread] Destroy TCP socket on port 5345 (in destroy_tcp_socket() at jul-thread.c:176) DEBUG1 - 14:18:02.443076 [7657/7665]: [jul-thread] is cleaning up and stopping. (in jul_thread_manage_registration() at jul-thread.c:372) DEBUG3 - 14:18:02.443085 [7657/7665]: [jul-thread] Cleaning JUL apps ht (in clean_jul_apps_ht() at jul-thread.c:103) DEBUG1 - 14:18:02.443135 [7657/7664]: Application notify communication apps thread cleanup complete (in ust_thread_manage_notify() at ust-thread.c:181) DEBUG1 - 14:18:02.443175 [7657/7661]: Futex n to 1 wait done (in futex_nto1_wait() at futex.c:90) DEBUG1 - 14:18:02.443199 [7657/7661]: Dispatch thread dying (in thread_dispatch_ust_registration() at main.c:1912) DEBUG1 - 14:18:02.443268 [7657/7658]: [ust-thread] cleanup complete. (in thread_ht_cleanup() at ht-cleanup.c:136) DEBUG1 - 14:18:02.443312 [7657/7660]: Clean command context structure (in clean_command_ctx() at main.c:736) DEBUG1 - 14:18:02.443349 [7657/7660]: Client thread dying (in thread_manage_clients() at main.c:4178) DEBUG1 - 14:18:02.443538 [7657/7657]: Cleaning up (in cleanup() at main.c:545) DEBUG1 - 14:18:02.443574 [7657/7657]: Removing sessiond and consumerd content of directory /home/zhengd/.lttng (in cleanup() at main.c:564) DEBUG1 - 14:18:02.443587 [7657/7657]: Removing /home/zhengd/.lttng/lttng-sessiond.pid (in cleanup() at main.c:570) DEBUG1 - 14:18:02.443635 [7657/7657]: Removing /home/zhengd/.lttng/jul.port (in cleanup() at main.c:575) DEBUG1 - 14:18:02.443667 [7657/7657]: Removing /home/zhengd/.lttng/kconsumerd/error (in cleanup() at main.c:582) DEBUG1 - 14:18:02.443680 [7657/7657]: Removing directory /home/zhengd/.lttng/kconsumerd (in cleanup() at main.c:588) DEBUG1 - 14:18:02.443690 [7657/7657]: Removing /home/zhengd/.lttng/ustconsumerd32/error (in cleanup() at main.c:595) DEBUG1 - 14:18:02.443707 [7657/7657]: Removing directory /home/zhengd/.lttng/ustconsumerd32 (in cleanup() at main.c:601) DEBUG1 - 14:18:02.443724 [7657/7657]: Removing /home/zhengd/.lttng/ustconsumerd64/error (in cleanup() at main.c:608) DEBUG1 - 14:18:02.443735 [7657/7657]: Removing directory /home/zhengd/.lttng/ustconsumerd64 (in cleanup() at main.c:614) DEBUG1 - 14:18:02.443764 [7657/7657]: Cleaning up all sessions (in cleanup() at main.c:617) DEBUG3 - 14:18:02.443775 [7657/7657]: No kernel session when tearing down session (in kernel_destroy_session() at kernel.c:752) DEBUG1 - 14:18:02.443788 [7657/7657]: Destroy all UST traces (in ust_app_destroy_trace_all() at ust-app.c:4139) DEBUG1 - 14:18:02.443797 [7657/7657]: Destroy tracing for ust app pid 6590 (in destroy_trace() at ust-app.c:3992) DEBUG2 - 14:18:02.443857 [7657/7657]: Trace UST destroy session 0 (in trace_ust_destroy_session() at trace-ust.c:719) DEBUG3 - 14:18:02.443878 [7657/7657]: JUL destroy domain (in jul_destroy_domain() at jul.c:866) DEBUG3 - 14:18:02.443890 [7657/7657]: Buffer registry per UID destroy with id: 0, ABI: 32, uid: 1000 (in buffer_reg_uid_destroy() at buffer-registry.c:624) Error: Consumer socket fd -1 not found in consumer obj 0x7fe00800b7a0 DEBUG1 - 14:18:02.443969 [7657/7657]: Destroying session Jul7EIGHT (in session_destroy() at session.c:194) DEBUG1 - 14:18:02.443985 [7657/7657]: Closing all UST sockets (in cleanup() at main.c:630) DEBUG2 - 14:18:02.443993 [7657/7657]: UST app cleaning registered apps hash table (in ust_app_clean_list() at ust-app.c:3300) DEBUG3 - 14:18:02.444003 [7657/7657]: Buffer registry destroy all registry (in buffer_reg_destroy_registries() at buffer-registry.c:699) DEBUG1 - 14:18:02.444059 [7657/7657]: *** assert failed :-) *** ==> Matthew, BEET driven development works! (in cleanup() at main.c:712)