* Re: UST Create Channel Failed, Why?
[not found] ` <CA+jJMxs-379mROWBkiYxCZCc6J_GzC92TZzA8Ewpb+oHus1MTw@mail.gmail.com>
@ 2015-07-07 18:23 ` Dilong Zheng
[not found] ` <SN1PR12MB031997C0AB4ACEDCF5AC41429B920@SN1PR12MB0319.namprd12.prod.outlook.com>
1 sibling, 0 replies; 8+ messages in thread
From: Dilong Zheng @ 2015-07-07 18:23 UTC (permalink / raw)
To: Jérémie Galarneau; +Cc: lttng-dev
[-- Attachment #1.1: Type: text/plain, Size: 3332 bytes --]
Hi,
I'm using LTTng v2.5.1 - Fumisterie.
I launched the session daemon manually using: lttng-sessiond -vvv and attempted to enable my UST events in another terminal (unsuccessfully). I have attached the contents of the sessiond log (please see sessiondlog.txt).
Thanks,
Dilong
________________________________
From: jeremie.galarneau@gmail.com <jeremie.galarneau@gmail.com> on behalf of Jérémie Galarneau <jeremie.galarneau@efficios.com>
Sent: Tuesday, July 7, 2015 1:13 PM
To: Dilong Zheng
Cc: lttng-dev@lists.lttng.org
Subject: Re: [lttng-dev] UST Create Channel Failed, Why?
Which release of 2.5 are you using? You can find out using:
$ lttng version
Can you launch the session daemon manually in verbose-mode and provide the logs?
$ lttng-sessiond -vvv
and enable your events in another terminal.
Thanks,
Jérémie
On Tue, Jul 7, 2015 at 11:28 AM, Dilong Zheng <Dilong.Zheng@mitel.com<mailto:Dilong.Zheng@mitel.com>> wrote:
Hi Jeremie,
Had some grammatical mistakes in my last email.... this should be clearer.
I am using LTTng v2.5. I am not explicitly creating any channels. I am only creating a session via: lttng create [session-name] . I used to always just create a session and then enable whichever available user tracepoint that I need (without explicitly creating any channels).
Thanks,
Dilong
________________________________
From: Dilong Zheng
Sent: Tuesday, July 7, 2015 11:26 AM
To: Jérémie Galarneau
Cc: lttng-dev@lists.lttng.org<mailto:lttng-dev@lists.lttng.org>
Subject: Re: [lttng-dev] UST Create Channel Failed, Why?
Hi Jeremie,
I am using LTTng v2.5. I am not explicitly creating channels. I am only creating a session: lttng create [session-name] . It used to always just create a session and then enable whichever available user tracepoint that I need (which out explicitly creating any channels).
Thanks,
Dilong
________________________________
From: jeremie.galarneau@gmail.com<mailto:jeremie.galarneau@gmail.com> <jeremie.galarneau@gmail.com<mailto:jeremie.galarneau@gmail.com>> on behalf of Jérémie Galarneau <jeremie.galarneau@efficios.com<mailto:jeremie.galarneau@efficios.com>>
Sent: Tuesday, July 7, 2015 11:20 AM
To: Dilong Zheng
Cc: lttng-dev@lists.lttng.org<mailto:lttng-dev@lists.lttng.org>
Subject: Re: [lttng-dev] UST Create Channel Failed, Why?
Hi Dilong,
How do you create this channel and using which version of LTTng?
Jérémie
On Mon, Jul 6, 2015 at 2:11 PM, Dilong Zheng <Dilong.Zheng@mitel.com<mailto:Dilong.Zheng@mitel.com>> wrote:
Hi all,
While trying to enable UST events, I get the following error message:
Error: Event mitel:sem_wait_entry: UST create channel failed (channel channel0, session mcdUST3)
When I type: lttng list -u I am able to see a list of all my UST tracepoints.
Could someone please provide some insight as to why this error is appearing and steps I could take to fix this error. Thanks.
_______________________________________________
lttng-dev mailing list
lttng-dev@lists.lttng.org<mailto:lttng-dev@lists.lttng.org>
http://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev
--
Jérémie Galarneau
EfficiOS Inc.
http://www.efficios.com
--
Jérémie Galarneau
EfficiOS Inc.
http://www.efficios.com
[-- Attachment #1.2: Type: text/html, Size: 7293 bytes --]
[-- Attachment #2: sessiondlog.txt --]
[-- Type: text/plain, Size: 52277 bytes --]
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 <id> {
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 <id> {
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]: ^[[1;31m*** assert failed :-) *** ==> ^[[0m^[[1;33mMatthew, BEET driven development works!^[[0m (in cleanup() at main.c:712)
[-- Attachment #3: Type: text/plain, Size: 155 bytes --]
_______________________________________________
lttng-dev mailing list
lttng-dev@lists.lttng.org
http://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev
^ permalink raw reply [flat|nested] 8+ messages in thread