Project

General

Profile

Bug #1406 » sessiond.log

Kienan Stewart, 12/13/2023 11:42 AM

 
DBG1 - 11:26:52.365911091 [Main]: [sessiond configuration]
DBG1 - 11:26:52.365965127 [Main]: version 2.14.0-pre
DBG1 - 11:26:52.365971411 [Main]: git version v2.12.0-rc1-1558-g7d46777ba
DBG1 - 11:26:52.365976252 [Main]: verbose: 3
DBG1 - 11:26:52.365981086 [Main]: verbose consumer: 0
DBG1 - 11:26:52.365985795 [Main]: quiet mode: False
DBG1 - 11:26:52.365990459 [Main]: agent_tcp_port: [5345, 5354]
DBG1 - 11:26:52.365995217 [Main]: application socket timeout: -1
DBG1 - 11:26:52.365999938 [Main]: no-kernel: False
DBG1 - 11:26:52.366004574 [Main]: background: True
DBG1 - 11:26:52.366009207 [Main]: daemonize: False
DBG1 - 11:26:52.366013849 [Main]: signal parent on start: False
DBG1 - 11:26:52.366018555 [Main]: tracing group name: tracing
DBG1 - 11:26:52.366023165 [Main]: kmod_probe_list: None
DBG1 - 11:26:52.366027788 [Main]: kmod_extra_probe_list: None
DBG1 - 11:26:52.366032451 [Main]: rundir: /home/kstewart/src/efficios/lttng/master/home/.lttng
DBG1 - 11:26:52.366037079 [Main]: application socket path: /home/kstewart/src/efficios/lttng/master/home/.lttng/lttng-ust-sock-8
DBG1 - 11:26:52.366044350 [Main]: client socket path: /home/kstewart/src/efficios/lttng/master/home/.lttng/client-lttng-sessiond
DBG1 - 11:26:52.366062230 [Main]: wait shm path: /lttng-ust-wait-8-1000
DBG1 - 11:26:52.366067030 [Main]: health socket path: /home/kstewart/src/efficios/lttng/master/home/.lttng/sessiond-health
DBG1 - 11:26:52.366074232 [Main]: LTTNG_UST_CLOCK_PLUGIN: None
DBG1 - 11:26:52.366078870 [Main]: pid file path: /home/kstewart/src/efficios/lttng/master/home/.lttng/lttng-sessiond.pid
DBG1 - 11:26:52.366089349 [Main]: lock file path: /home/kstewart/src/efficios/lttng/master/home/.lttng/lttng-sessiond.lck
DBG1 - 11:26:52.366096604 [Main]: session load path: None
DBG1 - 11:26:52.366101272 [Main]: agent port file path: /home/kstewart/src/efficios/lttng/master/home/.lttng/agent.port
DBG1 - 11:26:52.366108410 [Main]: consumerd32 path: /home/kstewart/src/efficios/lttng/master/home/.lttng/ustconsumerd32
DBG1 - 11:26:52.366115582 [Main]: consumerd32 bin path: Unknown
DBG1 - 11:26:52.366120235 [Main]: consumerd32 lib dir: Unknown
DBG1 - 11:26:52.366124834 [Main]: consumerd32 err unix sock path:/home/kstewart/src/efficios/lttng/master/home/.lttng/ustconsumerd32/error
DBG1 - 11:26:52.366131973 [Main]: consumerd32 cmd unix sock path:/home/kstewart/src/efficios/lttng/master/home/.lttng/ustconsumerd32/command
DBG1 - 11:26:52.366139040 [Main]: consumerd64 path: /home/kstewart/src/efficios/lttng/master/home/.lttng/ustconsumerd64
DBG1 - 11:26:52.366146135 [Main]: consumerd64 bin path: /home/kstewart/src/efficios/lttng/master/src/lttng-tools/tests/../src/bin/lttng-consumerd/lttng-consumerd
DBG1 - 11:26:52.366153302 [Main]: consumerd64 lib dir: /home/kstewart/src/efficios/lttng/master/usr/lib
DBG1 - 11:26:52.366157989 [Main]: consumerd64 err unix sock path:/home/kstewart/src/efficios/lttng/master/home/.lttng/ustconsumerd64/error
DBG1 - 11:26:52.366165079 [Main]: consumerd64 cmd unix sock path:/home/kstewart/src/efficios/lttng/master/home/.lttng/ustconsumerd64/command
DBG1 - 11:26:52.366172257 [Main]: kconsumerd path: /home/kstewart/src/efficios/lttng/master/home/.lttng/kconsumerd
DBG1 - 11:26:52.366179426 [Main]: kconsumerd err unix sock path: /home/kstewart/src/efficios/lttng/master/home/.lttng/kconsumerd/error
DBG1 - 11:26:52.366186510 [Main]: kconsumerd cmd unix sock path: /home/kstewart/src/efficios/lttng/master/home/.lttng/kconsumerd/command
DBG1 - 11:26:52.366203981 [Main]: Starting lttng-sessiond {c597123e-ce69-4edf-b87a-d4c700406b50} (in sessiond_uuid_log() at main.cpp:1400)
DBG1 - 11:26:52.366218036 [Main]: System information: (in log_system_information() at logging-utils.cpp:23)
DBG1 - 11:26:52.366230007 [Main]: sysname: `Linux` (in log_system_information() at logging-utils.cpp:24)
DBG1 - 11:26:52.366234966 [Main]: nodename: `laptop-kstewart` (in log_system_information() at logging-utils.cpp:25)
DBG1 - 11:26:52.366239724 [Main]: release: `6.5.0-5-amd64` (in log_system_information() at logging-utils.cpp:26)
DBG1 - 11:26:52.366244450 [Main]: version: `#1 SMP PREEMPT_DYNAMIC Debian 6.5.13-1 (2023-11-29)` (in log_system_information() at logging-utils.cpp:27)
DBG1 - 11:26:52.366251748 [Main]: machine: `x86_64` (in log_system_information() at logging-utils.cpp:28)
DBG3 - 11:26:52.366256509 [Main]: Creating LTTng run directory: /home/kstewart/src/efficios/lttng/master/home/.lttng (in create_lttng_rundir() at main.cpp:1039)
DBG1 - 11:26:52.368633819 [Main]: Resetting run_as worker signal handlers to default (in reset_sighandler() at runas.cpp:1324)
DBG1 - 11:26:52.368847046 [Main]: run_as signal handler set for SIGTERM and SIGINT (in set_worker_sighandlers() at runas.cpp:1383)
DBG1 - 11:26:52.370518244 [Main]: Health check time delta in seconds set to 20 (in health_init() at health/health.cpp:60)
DBG3 - 11:26:52.370886861 [Main]: Created hashtable size 4 at 0x55c0f3ca1b50 of type ULONG (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:52.370906786 [Main]: Created hashtable size 4 at 0x55c0f3ca20e0 of type ULONG (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:52.370917951 [Main]: Created hashtable size 4 at 0x55c0f3ca2de0 of type ULONG (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:52.370931060 [Main]: Created hashtable size 16 at 0x55c0f3ca33a0 of type U64 (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:52.370941521 [Main]: Created hashtable size 16 at 0x55c0f3ca3a40 of type U64 (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:52.370949644 [Main]: Created hashtable size 16 at 0x55c0f3ca40b0 of type U64 (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:52.370961505 [Main]: Created hashtable size 4 at 0x55c0f3ca4720 of type ULONG (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:52.370971490 [Main]: Created hashtable size 4 at 0x55c0f3ca4cb0 of type U64 (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG2 - 11:26:52.370987285 [Main]: Creating consumer directory: /home/kstewart/src/efficios/lttng/master/home/.lttng/ustconsumerd64 (in set_consumer_sockets() at main.cpp:1081)
DBG2 - 11:26:52.371089793 [Main]: Creating consumer directory: /home/kstewart/src/efficios/lttng/master/home/.lttng/ustconsumerd32 (in set_consumer_sockets() at main.cpp:1081)
DBG3 - 11:26:52.371161611 [Main]: Created hashtable size 4 at 0x55c0f3ca5240 of type U64 (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:52.371172080 [Main]: Global buffer per UID registry initialized (in buffer_reg_init_uid_registry() at buffer-registry.cpp:90)
DBG3 - 11:26:52.371183973 [Main]: Created hashtable size 4 at 0x55c0f3ca57d0 of type U64 (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:52.371191368 [Main]: Global buffer per PID registry initialized (in buffer_reg_init_pid_registry() at buffer-registry.cpp:228)
DBG1 - 11:26:52.371198857 [Main]: Command subsystem initialized (in cmd_init() at cmd.cpp:5995)
DBG1 - 11:26:52.371230972 [Main]: '2152012' written in file /home/kstewart/src/efficios/lttng/master/home/.lttng/lttng-sessiond.pid (in utils_create_pid_file() at utils.cpp:247)
DBG1 - 11:26:52.371283503 [Main]: TCP inet operation timeout set to 216 sec (in lttcomm_inet_init() at sessiond-comm/inet.cpp:528)
DBG1 - 11:26:52.371344351 [Main]: Waiting for health management thread to be ready (in wait_until_thread_is_ready() at health.cpp:38)
DBG1 - 11:26:52.371396267 [Health management]: Entering thread entry point (in launch_thread() at thread.cpp:66)
DBG1 - 11:26:52.371411702 [Health management]: [thread] Manage health check started (in thread_manage_health() at health.cpp:67)
DBG1 - 11:26:52.371437473 [Health management]: epoll set max size is 3570688 (in compat_epoll_set_max_size() at compat/poll.cpp:340)
DBG1 - 11:26:52.371526624 [Health management]: Marking health management thread as ready (in mark_thread_as_ready() at health.cpp:32)
DBG1 - 11:26:52.371541596 [Health management]: Health check ready (in thread_manage_health() at health.cpp:139)
DBG1 - 11:26:52.371585506 [Main]: Health management thread is ready (in wait_until_thread_is_ready() at health.cpp:40)
DBG1 - 11:26:52.371819149 [Main]: Waiting for notification thread to be ready (in wait_until_thread_is_ready() at notification-thread.cpp:396)
DBG1 - 11:26:52.371862199 [Notification]: Entering thread entry point (in launch_thread() at thread.cpp:66)
DBG1 - 11:26:52.371875436 [Notification]: Started notification thread (in thread_notification() at notification-thread.cpp:616)
DBG1 - 11:26:52.371920655 [Notification]: Creating notification channel UNIX socket at /home/kstewart/src/efficios/lttng/master/home/.lttng/sessiond-notification (in notification_channel_socket_create() at notification-thread.cpp:222)
DBG1 - 11:26:52.371969136 [Notification]: Notification channel UNIX socket created (fd = 24) (in notification_channel_socket_create() at notification-thread.cpp:255)
DBG1 - 11:26:52.371989998 [Notification]: Listening on notification channel socket (in init_thread_state() at notification-thread.cpp:422)
DBG1 - 11:26:52.372050687 [Notification]: Marking notification thread as ready (in mark_thread_as_ready() at notification-thread.cpp:390)
DBG1 - 11:26:52.372063872 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG1 - 11:26:52.372100537 [Main]: Notification thread is ready (in wait_until_thread_is_ready() at notification-thread.cpp:398)
DBG1 - 11:26:52.372117349 [Action Executor]: Entering thread entry point (in launch_thread() at thread.cpp:66)
DBG1 - 11:26:52.372131485 [Action Executor]: Entering work execution loop (in action_executor_thread() at action-executor.cpp:742)
DBG1 - 11:26:52.372145100 [Action Executor]: No work items enqueued, entering wait (in action_executor_thread() at action-executor.cpp:751)
DBG1 - 11:26:52.372220213 [Timer]: Entering thread entry point (in launch_thread() at thread.cpp:66)
DBG1 - 11:26:52.372364322 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:26:52.372377235 [Notification]: Handling fd (24) activity (1) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:26:52.372385563 [Notification]: Handling new notification channel client connection (in handle_notification_thread_client_connect() at notification-thread-events.cpp:3383)
DBG1 - 11:26:52.372408160 [Notification]: Client socket (fd = 30) set as non-blocking (in socket_set_non_blocking() at notification-thread-events.cpp:3356)
DBG1 - 11:26:52.372423656 [Notification]: Added new notification channel client socket (30) to poll set (in handle_notification_thread_client_connect() at notification-thread-events.cpp:3436)
DBG1 - 11:26:52.372435108 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG1 - 11:26:52.372441755 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:26:52.372446562 [Notification]: Handling fd (30) activity (1) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:26:52.372458092 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG1 - 11:26:52.372463770 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:26:52.372468380 [Notification]: Handling fd (30) activity (1) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:26:52.372480020 [Notification]: Received handshake from client: uid = 1000, gid = 1000, protocol version = 1.1, client is sessiond = true (in client_handle_message_handshake() at notification-thread-events.cpp:3884)
DBG1 - 11:26:52.372488958 [Notification]: Send command reply (0) (in client_send_command_reply() at notification-thread-events.cpp:3769)
DBG1 - 11:26:52.372505654 [Notification]: Flushing client (socket fd = 30) outgoing queue (in client_flush_outgoing_queue() at notification-thread-events.cpp:3665)
DBG1 - 11:26:52.372518759 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG1 - 11:26:52.372706950 [Main]: Created client socket (fd = 34) (in create_client_sock() at client.cpp:2391)
DBG1 - 11:26:52.372715483 [Rotation]: Entering thread entry point (in launch_thread() at thread.cpp:66)
DBG1 - 11:26:52.372729202 [Rotation]: Started rotation thread (in _thread_function() at rotation-thread.cpp:702)
DBG1 - 11:26:52.372736169 [Rotation]: Entering poll wait (in _run() at rotation-thread.cpp:732)
DBG1 - 11:26:52.372753234 [Main]: Waiting for client thread to be ready (in wait_thread_status() at client.cpp:71)
DBG1 - 11:26:52.372766145 [Client management]: Entering thread entry point (in launch_thread() at thread.cpp:66)
DBG1 - 11:26:52.372783371 [Client management]: [thread] Manage client started (in thread_manage_clients() at client.cpp:2424)
DBG1 - 11:26:52.372822428 [Client management]: Marking client thread's state as running (in set_thread_status() at client.cpp:64)
DBG1 - 11:26:52.372835596 [Client management]: Accepting client command ... (in thread_manage_clients() at client.cpp:2489)
DBG1 - 11:26:52.372877228 [Main]: Client thread is ready (in wait_thread_status() at client.cpp:74)
DBG3 - 11:26:52.372971047 [Main]: Session daemon application socket created (fd = 38) (in create_application_socket() at register.cpp:72)
DBG1 - 11:26:52.372980622 [UST registration dispatch]: Entering thread entry point (in launch_thread() at thread.cpp:66)
DBG1 - 11:26:52.372994876 [UST registration dispatch]: [thread] Dispatch UST command started (in thread_dispatch_ust_registration() at dispatch.cpp:246)
DBG1 - 11:26:52.373003592 [UST registration dispatch]: Futex n to 1 prepare done (in futex_nto1_prepare() at futex.cpp:64)
DBG1 - 11:26:52.373021051 [Main]: Waiting for application registration thread to be ready (in wait_thread_status() at register.cpp:131)
DBG1 - 11:26:52.373021960 [UST registration dispatch]: Woken up but nothing in the UST command queue (in thread_dispatch_ust_registration() at dispatch.cpp:274)
DBG1 - 11:26:52.373070255 [UST application registration]: Entering thread entry point (in launch_thread() at thread.cpp:66)
DBG1 - 11:26:52.373083149 [UST application registration]: [thread] Manage application registration started (in thread_application_registration() at register.cpp:167)
DBG1 - 11:26:52.373119787 [UST application registration]: Marking application registration thread's state as running (in set_thread_status() at register.cpp:124)
DBG1 - 11:26:52.373132142 [UST application registration]: Accepting application registration (in thread_application_registration() at register.cpp:206)
DBG1 - 11:26:52.373177572 [Main]: Application registration thread is ready (in wait_thread_status() at register.cpp:134)
DBG1 - 11:26:52.373189522 [Main]: Notifying applications of session daemon state: 1 (in notify_ust_apps() at register.cpp:92)
DBG1 - 11:26:52.373218994 [Main]: Wait shared memory file descriptor created successfully: path = '/lttng-ust-wait-8-1000', mmap_size = 4096, global = false, fd = 40 (in get_wait_shm() at shm.cpp:139)
DBG1 - 11:26:52.373245490 [Main]: Futex wait update active 1 (in futex_wait_update() at futex.cpp:53)
DBG1 - 11:26:52.373520930 [UST application management]: Entering thread entry point (in launch_thread() at thread.cpp:66)
DBG1 - 11:26:52.373534474 [UST application management]: [thread] Manage application started (in thread_application_management() at manage-apps.cpp:55)
DBG1 - 11:26:52.373557438 [Main]: Waiting for agent management thread to be ready (in wait_until_thread_is_ready() at agent-thread.cpp:345)
DBG1 - 11:26:52.373567678 [Application notification]: Entering thread entry point (in launch_thread() at thread.cpp:66)
DBG1 - 11:26:52.373580121 [Application notification]: [ust-thread] Manage application notify command (in thread_application_notification() at notify-apps.cpp:42)
DBG1 - 11:26:52.373597260 [Agent management]: Entering thread entry point (in launch_thread() at thread.cpp:66)
DBG1 - 11:26:52.373611998 [Agent management]: Manage agent application registration. (in thread_agent_management() at agent-thread.cpp:362)
DBG3 - 11:26:52.373632151 [Application notification]: [ust-thread] Manage notify polling (in thread_application_notification() at notify-apps.cpp:75)
DBG3 - 11:26:52.373648792 [Agent management]: URI string: tcp://localhost (in uri_parse() at uri.cpp:329)
DBG1 - 11:26:52.373586186 [UST application management]: Apps thread polling (in thread_application_management() at manage-apps.cpp:90)
DBG2 - 11:26:52.373767683 [Agent management]: IP address resolved to 127.0.0.1 (in set_ip_address() at uri.cpp:185)
DBG3 - 11:26:52.373776426 [Agent management]: URI dtype: 1, proto: 1, host: localhost, subdir: , ctrl: 0, data: 0 (in uri_parse() at uri.cpp:540)
DBG3 - 11:26:52.373794711 [Agent management]: Trying to bind on port 5345 (in init_tcp_socket() at agent-thread.cpp:142)
DBG1 - 11:26:52.373810038 [Agent management]: Listening on TCP port 5345 and socket 49 (in init_tcp_socket() at agent-thread.cpp:177)
DBG1 - 11:26:52.373841875 [Agent management]: '5345' written in file /home/kstewart/src/efficios/lttng/master/home/.lttng/agent.port (in utils_create_pid_file() at utils.cpp:247)
DBG1 - 11:26:52.373864319 [Agent management]: Marking agent management thread as ready (in mark_thread_as_ready() at agent-thread.cpp:339)
DBG3 - 11:26:52.373877340 [Agent management]: Manage agent polling (in thread_agent_management() at agent-thread.cpp:415)
DBG1 - 11:26:52.373960124 [Main]: Agent management thread is ready (in wait_until_thread_is_ready() at agent-thread.cpp:347)
DBG1 - 11:26:52.388665506 [UST application registration]: UST registration received with pid:2152033 ppid:2151972 uid:1000 gid:1000 sock:51 name:gen-ust-events (version 10.0) (in thread_application_registration() at register.cpp:311)
DBG1 - 11:26:52.388696965 [UST application registration]: Futex n to 1 wake done (in futex_nto1_wake() at futex.cpp:116)
DBG1 - 11:26:52.388703172 [UST application registration]: Accepting application registration (in thread_application_registration() at register.cpp:206)
DBG1 - 11:26:52.388722691 [UST application registration]: UST registration received with pid:2152033 ppid:2151972 uid:1000 gid:1000 sock:52 name:gen-ust-events (version 10.0) (in thread_application_registration() at register.cpp:311)
DBG1 - 11:26:52.388731774 [UST application registration]: Futex n to 1 wake done (in futex_nto1_wake() at futex.cpp:116)
DBG1 - 11:26:52.388736457 [UST application registration]: Accepting application registration (in thread_application_registration() at register.cpp:206)
DBG1 - 11:26:52.388753691 [UST registration dispatch]: Futex n to 1 wait done (in futex_nto1_wait() at futex.cpp:100)
DBG1 - 11:26:52.388768868 [UST registration dispatch]: Futex n to 1 prepare done (in futex_nto1_prepare() at futex.cpp:64)
DBG1 - 11:26:52.388775170 [UST registration dispatch]: Dispatching UST registration pid:2152033 ppid:2151972 uid:1000 gid:1000 sock:51 name:gen-ust-events (version 10.0) (in thread_dispatch_ust_registration() at dispatch.cpp:281)
DBG3 - 11:26:52.388816190 [UST registration dispatch]: UST app creating application for socket 51 (in ust_app_create() at ust-app.cpp:4035)
DBG3 - 11:26:52.388841954 [UST registration dispatch]: Created hashtable size 4 at 0x7f2220000da0 of type U64 (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:52.388851821 [UST registration dispatch]: Created hashtable size 4 at 0x7f2220001330 of type ULONG (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:52.388859592 [UST registration dispatch]: Created hashtable size 4 at 0x7f22200018c0 of type ULONG (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:52.388869509 [UST registration dispatch]: Created hashtable size 4 at 0x7f2220001e50 of type U64 (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG1 - 11:26:52.388889920 [UST registration dispatch]: Dispatching UST registration pid:2152033 ppid:2151972 uid:1000 gid:1000 sock:52 name:gen-ust-events (version 10.0) (in thread_dispatch_ust_registration() at dispatch.cpp:281)
DBG3 - 11:26:52.388906259 [UST registration dispatch]: UST app notify socket 52 is set (in thread_dispatch_ust_registration() at dispatch.cpp:351)
DBG1 - 11:26:52.388919439 [UST registration dispatch]: App registered with pid:2152033 ppid:2151972 uid:1000 gid:1000 sock =51 name:gen-ust-events notify_sock =52 (version 10.0) (in ust_app_add() at ust-app.cpp:4158)
DBG1 - 11:26:52.389208863 [UST registration dispatch]: Beginning of waiter "wait" period (in wait() at waiter.cpp:48)
DBG1 - 11:26:52.389259563 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:26:52.389274318 [Notification]: Handling fd (23) activity (1) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:26:52.389285465 [Notification]: Received `ADD_TRACER_EVENT_SOURCE` command (in handle_notification_thread_command() at notification-thread-events.cpp:3191)
DBG3 - 11:26:52.389294712 [Notification]: Adding tracer event source fd to poll set: tracer_event_source_fd = 53, domain = 'ust' (in handle_notification_thread_command_add_tracer_event_source() at notification-thread-events.cpp:2071)
DBG1 - 11:26:52.389309110 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG1 - 11:26:52.389366399 [UST registration dispatch]: End of waiter "wait" period (in wait() at waiter.cpp:109)
DBG2 - 11:26:52.389837892 [UST registration dispatch]: UST application global event notifier rules update: app = 'gen-ust-events', pid = 2152033 (in ust_app_global_update_event_notifier_rules() at ust-app.cpp:6291)
DBG3 - 11:26:52.389843806 [Application notification]: [ust-thread] Manage notify return from poll on 2 fds (in thread_application_notification() at notify-apps.cpp:81)
DBG1 - 11:26:52.389855697 [UST registration dispatch]: Beginning of waiter "wait" period (in wait() at waiter.cpp:48)
DBG3 - 11:26:52.389879689 [Application notification]: UST thread notify added sock 52 to pollset (in thread_application_notification() at notify-apps.cpp:140)
DBG3 - 11:26:52.389889117 [Application notification]: [ust-thread] Manage notify polling (in thread_application_notification() at notify-apps.cpp:75)
DBG1 - 11:26:52.389897763 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:26:52.389931183 [Notification]: Handling fd (23) activity (1) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:26:52.389941895 [Notification]: Received `LIST_TRIGGERS` command (in handle_notification_thread_command() at notification-thread-events.cpp:3191)
DBG1 - 11:26:52.389955750 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG1 - 11:26:52.389958773 [UST registration dispatch]: End of waiter "wait" period (in wait() at waiter.cpp:109)
DBG1 - 11:26:52.390003504 [UST registration dispatch]: Woken up but nothing in the UST command queue (in thread_dispatch_ust_registration() at dispatch.cpp:274)
DBG1 - 11:26:52.390020472 [UST application management]: Apps thread return from poll on 2 fds (in thread_application_management() at manage-apps.cpp:96)
DBG1 - 11:26:52.390032965 [UST application management]: Apps with sock 51 added to poll set (in thread_application_management() at manage-apps.cpp:149)
DBG1 - 11:26:52.390041281 [UST application management]: Apps thread polling (in thread_application_management() at manage-apps.cpp:90)
DBG1 - 11:26:52.400600976 [Client management]: Wait for client response (in thread_manage_clients() at client.cpp:2534)
DBG1 - 11:26:52.400641906 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.cpp:2562)
DBG1 - 11:26:52.400651961 [Client management]: Incomplete recv() from client... continuing (in thread_manage_clients() at client.cpp:2566)
DBG1 - 11:26:52.400667302 [Client management]: Accepting client command ... (in thread_manage_clients() at client.cpp:2489)
DBG1 - 11:26:52.400806756 [Client management]: Wait for client response (in thread_manage_clients() at client.cpp:2534)
DBG1 - 11:26:52.400839221 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.cpp:2562)
DBG1 - 11:26:52.400854681 [Client management]: Processing client command 'CREATE_SESSION_EXT' (40) (in process_client_msg() at client.cpp:1007)
DBG2 - 11:26:52.400899424 [Client management]: Trying to find session by name oc4iKoCkS4oPhaVB (in session_find_by_name() at session.cpp:1114)
DBG3 - 11:26:52.400947012 [Client management]: Created hashtable size 4 at 0x7f22380150f0 of type ULONG (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:52.400962978 [Client management]: Created hashtable size 4 at 0x7f22380156a0 of type ULONG (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG1 - 11:26:52.400971232 [Client management]: Allocating ltt_sessions_ht_by_id (in ltt_sessions_ht_alloc() at session.cpp:307)
DBG3 - 11:26:52.400978764 [Client management]: Created hashtable size 4 at 0x7f2238015c30 of type U64 (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG1 - 11:26:52.400986656 [Client management]: Allocating ltt_sessions_ht_by_name (in ltt_sessions_ht_alloc() at session.cpp:315)
DBG3 - 11:26:52.400994326 [Client management]: Created hashtable size 4 at 0x7f22380161c0 of type STRING (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG1 - 11:26:52.401003240 [Client management]: Tracing session oc4iKoCkS4oPhaVB created with ID 0 by uid = 1000, gid = 1000 (in session_create() at session.cpp:1319)
DBG1 - 11:26:52.401015878 [Client management]: Beginning of waiter "wait" period (in wait() at waiter.cpp:48)
DBG1 - 11:26:52.401065153 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:26:52.401080622 [Notification]: Handling fd (23) activity (1) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:26:52.401091598 [Notification]: Received `ADD_SESSION` command (in handle_notification_thread_command() at notification-thread-events.cpp:3191)
DBG1 - 11:26:52.401099804 [Notification]: Adding session: session name = `oc4iKoCkS4oPhaVB`, session id = 0, session uid = 1000, session gid = 1000 (in handle_notification_thread_command_add_session() at notification-thread-events.cpp:1784)
DBG1 - 11:26:52.401110435 [Notification]: Found 0 triggers that apply to newly created session (in lttng_session_trigger_list_build() at notification-thread-events.cpp:1633)
DBG1 - 11:26:52.401128661 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG1 - 11:26:52.401170403 [Client management]: End of waiter "wait" period (in wait() at waiter.cpp:109)
DBG2 - 11:26:52.401195973 [Client management]: Setting network URI to consumer (in add_uri_to_consumer() at cmd.cpp:692)
DBG3 - 11:26:52.401202775 [Client management]: Consumer control URI set with port 5342 (in consumer_set_network_uri() at consumer.cpp:701)
DBG3 - 11:26:52.401227322 [Client management]: Consumer set network uri base_dir path /laptop-kstewart/oc4iKoCkS4oPhaVB-20231213-112652/ (in consumer_set_network_uri() at consumer.cpp:816)
DBG2 - 11:26:52.401235878 [Client management]: Setting network URI to consumer (in add_uri_to_consumer() at cmd.cpp:692)
DBG3 - 11:26:52.401240631 [Client management]: Consumer data URI set with port 5343 (in consumer_set_network_uri() at consumer.cpp:716)
DBG1 - 11:26:52.401269092 [Client management]: Sending response (size: 16476, retcode: Success (10)) (in thread_manage_clients() at client.cpp:2652)
DBG1 - 11:26:52.401289764 [Client management]: Accepting client command ... (in thread_manage_clients() at client.cpp:2489)
DBG1 - 11:26:52.401462454 [Client management]: Wait for client response (in thread_manage_clients() at client.cpp:2534)
DBG1 - 11:26:52.401483981 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.cpp:2562)
DBG1 - 11:26:52.401497832 [Client management]: Processing client command 'LIST_SESSIONS' (11) (in process_client_msg() at client.cpp:1007)
DBG1 - 11:26:52.401507230 [Client management]: Counting number of available session for UID 1000 (in lttng_sessions_count() at client.cpp:597)
DBG1 - 11:26:52.401523311 [Client management]: Getting all available session for UID 1000 GID 1000 (in cmd_list_lttng_sessions() at cmd.cpp:3971)
DBG1 - 11:26:52.401534409 [Client management]: Sending response (size: 4409, retcode: Success (10)) (in thread_manage_clients() at client.cpp:2652)
DBG1 - 11:26:52.401551855 [Client management]: Accepting client command ... (in thread_manage_clients() at client.cpp:2489)
DBG1 - 11:26:52.415245365 [Client management]: Wait for client response (in thread_manage_clients() at client.cpp:2534)
DBG1 - 11:26:52.415276029 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.cpp:2562)
DBG1 - 11:26:52.415290348 [Client management]: Processing client command 'ENABLE_CHANNEL' (5) (in process_client_msg() at client.cpp:1007)
DBG1 - 11:26:52.415300201 [Client management]: Getting session oc4iKoCkS4oPhaVB by name (in process_client_msg() at client.cpp:1122)
DBG2 - 11:26:52.415308333 [Client management]: Trying to find session by name oc4iKoCkS4oPhaVB (in session_find_by_name() at session.cpp:1114)
DBG1 - 11:26:52.415319579 [Client management]: Creating UST session (in create_ust_session() at client.cpp:514)
DBG3 - 11:26:52.415328918 [Client management]: Created hashtable size 4 at 0x7f2238002de0 of type STRING (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:52.415337868 [Client management]: Created hashtable size 4 at 0x7f2238003370 of type U64 (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:52.415357128 [Client management]: Created hashtable size 4 at 0x7f223800aa20 of type ULONG (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG2 - 11:26:52.415365200 [Client management]: UST trace session create successful (in trace_ust_create_session() at trace-ust.cpp:329)
DBG3 - 11:26:52.415372942 [Client management]: Copying tracing session consumer output in UST session (in copy_session_consumer() at client.cpp:463)
DBG3 - 11:26:52.415388978 [Client management]: Created hashtable size 4 at 0x7f223800afb0 of type ULONG (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:52.415399067 [Client management]: Copy session consumer subdir ust (in copy_session_consumer() at client.cpp:483)
DBG1 - 11:26:52.415406544 [Client management]: Spawning consumerd (in spawn_consumerd() at client.cpp:207)
DBG2 - 11:26:52.415740955 [Client management]: Consumer pid 2152064 (in start_consumerd() at client.cpp:402)
DBG2 - 11:26:52.415761671 [Client management]: Spawning consumer control thread (in start_consumerd() at client.cpp:405)
DBG1 - 11:26:52.415977708 [Client management]: Using 64-bit UST consumer at: /home/kstewart/src/efficios/lttng/master/src/lttng-tools/tests/../src/bin/lttng-consumerd/lttng-consumerd (in spawn_consumerd() at client.cpp:291)
DBG1 - 11:26:52.434004104 [Client management]: Waiting for consumer management thread to be ready (in wait_until_thread_is_ready() at manage-consumer.cpp:48)
DBG1 - 11:26:52.434050317 [Consumer management]: Entering thread entry point (in launch_thread() at thread.cpp:66)
DBG1 - 11:26:52.434064637 [Consumer management]: [thread] Manage consumer started (in thread_consumer_management() at manage-consumer.cpp:67)
DBG2 - 11:26:52.434130189 [Consumer management]: Receiving code from consumer err_sock (in thread_consumer_management() at manage-consumer.cpp:165)
DBG1 - 11:26:52.522441955 [Consumer management]: Consumer command socket ready (fd: 67) (in thread_consumer_management() at manage-consumer.cpp:202)
DBG1 - 11:26:52.522539511 [Consumer management]: Consumer metadata socket ready (fd: 68) (in thread_consumer_management() at manage-consumer.cpp:203)
DBG1 - 11:26:52.522640421 [Consumer management]: Sending consumer initialization command (in consumer_init() at consumer.cpp:1797)
DBG3 - 11:26:52.522951266 [Consumer management]: Sending SET_CHANNEL_MONITOR_PIPE command to consumer (in consumer_send_pipe() at consumer.cpp:1229)
DBG3 - 11:26:52.523295370 [Consumer management]: Sending channel monitor pipe 12 to consumer on socket 67 (in consumer_send_pipe() at consumer.cpp:1235)
DBG2 - 11:26:52.523589424 [Consumer management]: channel monitor pipe successfully sent (in consumer_send_pipe() at consumer.cpp:1241)
DBG1 - 11:26:52.523893016 [Consumer management]: Marking consumer management thread as ready (in mark_thread_as_ready() at manage-consumer.cpp:34)
DBG1 - 11:26:52.524041892 [Client management]: Consumer management thread is ready (in wait_until_thread_is_ready() at manage-consumer.cpp:50)
DBG3 - 11:26:52.524120686 [Client management]: Consumer socket created (fd: 67) and added to output (in consumer_create_socket() at consumer.cpp:347)
DBG1 - 11:26:52.524153168 [Client management]: Setting relayd for session oc4iKoCkS4oPhaVB (in cmd_setup_relayd() at cmd.cpp:1029)
DBG3 - 11:26:52.524224407 [Client management]: Relayd connect ... (in relayd_connect() at relayd/relayd.cpp:783)
DBG3 - 11:26:52.524383636 [Client management]: Creating relayd stream socket from URI (in create_connect_relayd() at cmd.cpp:812)
DBG1 - 11:26:52.524424147 [Client management]: Relayd version check for major.minor 2.14 (in relayd_version_check() at relayd/relayd.cpp:679)
DBG3 - 11:26:52.524453267 [Client management]: Relayd sending command RELAYD_VERSION of size 32 (in send_command() at relayd/relayd.cpp:89)
DBG3 - 11:26:52.524536095 [Client management]: Relayd waiting for reply of size 8 (in recv_reply() at relayd/relayd.cpp:119)
DBG2 - 11:26:52.525362413 [Client management]: Relayd version is compatible, using protocol version 2.14 (in relayd_version_check() at relayd/relayd.cpp:727)
DBG3 - 11:26:52.525443313 [Client management]: Relayd sending command RELAYD_GET_CONFIGURATION of size 32 (in send_command() at relayd/relayd.cpp:89)
DBG3 - 11:26:52.525522329 [Client management]: Relayd waiting for reply of size 12 (in recv_reply() at relayd/relayd.cpp:119)
DBG1 - 11:26:52.525952798 [Client management]: Relayd successfully got configuration: query_flags = 0, results_flags = 1 (in relayd_get_configuration() at relayd/relayd.cpp:1594)
DBG1 - 11:26:52.526032661 [Client management]: Relayd create session (in relayd_create_session() at relayd/relayd.cpp:345)
DBG3 - 11:26:52.526056307 [Client management]: Relayd sending command RELAYD_CREATE_SESSION of size 117 (in send_command() at relayd/relayd.cpp:89)
DBG3 - 11:26:52.526123961 [Client management]: Relayd waiting for reply of size 16 (in recv_reply() at relayd/relayd.cpp:119)
DBG3 - 11:26:52.527062980 [Client management]: Relayd waiting for reply of size 49 (in recv_reply() at relayd/relayd.cpp:119)
DBG1 - 11:26:52.527126330 [Client management]: Relayd session created with id 1 (in relayd_create_session() at relayd/relayd.cpp:385)
DBG1 - 11:26:52.527159626 [Client management]: Created session on relay, output path reply: laptop-kstewart/oc4iKoCkS4oPhaVB-20231213-112652 (in consumer_send_relayd_socket() at consumer.cpp:1170)
DBG3 - 11:26:52.527187073 [Client management]: Sending relayd sock info to consumer on 67 (in consumer_send_relayd_socket() at consumer.cpp:1186)
DBG3 - 11:26:52.527519079 [Client management]: Sending relayd socket file descriptor to consumer (in consumer_send_relayd_socket() at consumer.cpp:1192)
DBG2 - 11:26:52.527812716 [Client management]: Consumer relayd socket sent (in consumer_send_relayd_socket() at consumer.cpp:1199)
DBG3 - 11:26:52.527875703 [Client management]: Relayd closing socket 69 (in relayd_close() at relayd/relayd.cpp:814)
DBG3 - 11:26:52.527935108 [Client management]: Relayd connect ... (in relayd_connect() at relayd/relayd.cpp:783)
DBG3 - 11:26:52.528061300 [Client management]: Creating relayd data socket from URI (in create_connect_relayd() at cmd.cpp:836)
DBG3 - 11:26:52.528093795 [Client management]: Sending relayd sock info to consumer on 67 (in consumer_send_relayd_socket() at consumer.cpp:1186)
DBG3 - 11:26:52.528265873 [Client management]: Sending relayd socket file descriptor to consumer (in consumer_send_relayd_socket() at consumer.cpp:1192)
DBG2 - 11:26:52.528523026 [Client management]: Consumer relayd socket sent (in consumer_send_relayd_socket() at consumer.cpp:1199)
DBG3 - 11:26:52.528583585 [Client management]: Relayd closing socket 69 (in relayd_close() at relayd/relayd.cpp:814)
DBG1 - 11:26:52.528658240 [Client management]: Enabling channel chan for session oc4iKoCkS4oPhaVB (in cmd_enable_channel_internal() at cmd.cpp:1359)
DBG2 - 11:26:52.528696193 [Client management]: Trace UST channel chan not found by name (in trace_ust_find_channel_by_name() at trace-ust.cpp:187)
DBG3 - 11:26:52.528734937 [Client management]: Created hashtable size 4 at 0x7f223800c340 of type STRING (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:52.528774329 [Client management]: Created hashtable size 4 at 0x7f223800c8d0 of type ULONG (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG2 - 11:26:52.528802074 [Client management]: Trace UST channel chan created (in trace_ust_create_channel() at trace-ust.cpp:407)
DBG2 - 11:26:52.528828779 [Client management]: Channel chan is being created for UST with buffer 1 and id 0 (in channel_ust_create() at channel.cpp:437)
DBG2 - 11:26:52.528863292 [Client management]: Channel chan created successfully (in channel_ust_create() at channel.cpp:465)
DBG1 - 11:26:52.528898297 [Client management]: Sending response (size: 24, retcode: Success (10)) (in thread_manage_clients() at client.cpp:2652)
DBG1 - 11:26:52.528960908 [Client management]: Accepting client command ... (in thread_manage_clients() at client.cpp:2489)
DBG1 - 11:26:52.578650272 [Client management]: Wait for client response (in thread_manage_clients() at client.cpp:2534)
DBG1 - 11:26:52.578796870 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.cpp:2562)
DBG1 - 11:26:52.578868840 [Client management]: Processing client command 'ENABLE_EVENT' (6) (in process_client_msg() at client.cpp:1007)
DBG1 - 11:26:52.578906533 [Client management]: Getting session oc4iKoCkS4oPhaVB by name (in process_client_msg() at client.cpp:1122)
DBG2 - 11:26:52.578936148 [Client management]: Trying to find session by name oc4iKoCkS4oPhaVB (in session_find_by_name() at session.cpp:1114)
DBG3 - 11:26:52.578971933 [Client management]: Consumer socket created (fd: 67) and added to output (in consumer_create_socket() at consumer.cpp:347)
DBG1 - 11:26:52.579000821 [Client management]: Setting relayd for session oc4iKoCkS4oPhaVB (in cmd_setup_relayd() at cmd.cpp:1029)
DBG2 - 11:26:52.579063242 [Client management]: Trace UST channel chan found by name (in trace_ust_find_channel_by_name() at trace-ust.cpp:182)
DBG2 - 11:26:52.579098753 [Client management]: Trace UST event tp:tptest NOT found (in trace_ust_find_event() at trace-ust.cpp:231)
DBG2 - 11:26:52.579127434 [Client management]: Trace UST event tp:tptest, loglevel (0,-1) created (in trace_ust_create_event() at trace-ust.cpp:526)
DBG1 - 11:26:52.579162742 [Client management]: Sending response (size: 24, retcode: Success (10)) (in thread_manage_clients() at client.cpp:2652)
DBG1 - 11:26:52.579223948 [Client management]: Accepting client command ... (in thread_manage_clients() at client.cpp:2489)
DBG1 - 11:26:52.608136322 [Client management]: Wait for client response (in thread_manage_clients() at client.cpp:2534)
DBG1 - 11:26:52.608204228 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.cpp:2562)
DBG1 - 11:26:52.608232998 [Client management]: Processing client command 'LIST_SESSIONS' (11) (in process_client_msg() at client.cpp:1007)
DBG1 - 11:26:52.608251670 [Client management]: Counting number of available session for UID 1000 (in lttng_sessions_count() at client.cpp:597)
DBG1 - 11:26:52.608283644 [Client management]: Getting all available session for UID 1000 GID 1000 (in cmd_list_lttng_sessions() at cmd.cpp:3971)
DBG1 - 11:26:52.608311296 [Client management]: Sending response (size: 4409, retcode: Success (10)) (in thread_manage_clients() at client.cpp:2652)
DBG1 - 11:26:52.608344773 [Client management]: Accepting client command ... (in thread_manage_clients() at client.cpp:2489)
DBG1 - 11:26:52.608569173 [Client management]: Wait for client response (in thread_manage_clients() at client.cpp:2534)
DBG1 - 11:26:52.608624094 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.cpp:2562)
DBG1 - 11:26:52.608648637 [Client management]: Processing client command 'START_TRACE' (14) (in process_client_msg() at client.cpp:1007)
DBG1 - 11:26:52.608665451 [Client management]: Getting session oc4iKoCkS4oPhaVB by name (in process_client_msg() at client.cpp:1122)
DBG2 - 11:26:52.608934617 [Client management]: Trying to find session by name oc4iKoCkS4oPhaVB (in session_find_by_name() at session.cpp:1114)
DBG1 - 11:26:52.608961800 [Client management]: Creating initial trace chunk of session "oc4iKoCkS4oPhaVB" (in cmd_start_trace() at cmd.cpp:2779)
DBG1 - 11:26:52.608980033 [Client management]: Creating trace chunk: chunk_id = 0, creation time = 20231213-112652 (in lttng_trace_chunk_create() at trace-chunk.cpp:419)
DBG1 - 11:26:52.608995890 [Client management]: Chunk name set to "(none)" (in lttng_trace_chunk_create() at trace-chunk.cpp:450)
DBG1 - 11:26:52.609017280 [Client management]: Sending consumer create trace chunk command: relayd_id = 2, session_id = 0, chunk_id = 0, creation_timestamp = 20231213T112652-0500 (in consumer_create_trace_chunk() at consumer.cpp:1939)
DBG1 - 11:26:52.609545948 [Client management]: Starting all UST traces (in ust_app_start_trace_all() at ust-app.cpp:5836)
DBG1 - 11:26:52.609564933 [Client management]: Clearing stream quiescent state for all ust apps (in ust_app_clear_quiescent_session() at ust-app.cpp:5702)
DBG2 - 11:26:52.609581171 [Client management]: UST app global update for app sock 51 for session id 0 (in ust_app_global_update() at ust-app.cpp:6262)
DBG2 - 11:26:52.609597220 [Client management]: UST app pid: 2152033 session id 0 not found, creating it (in find_or_create_ust_app_session() at ust-app.cpp:2722)
DBG3 - 11:26:52.609638646 [Client management]: Created hashtable size 4 at 0x7f2238022160 of type STRING (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG2 - 11:26:52.609671426 [Client management]: Shadow copy of session handle -1 (in shadow_copy_session() at ust-app.cpp:2433)
DBG3 - 11:26:52.609684081 [Client management]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:26:52.609715101 [Client management]: Created hashtable size 4 at 0x7f2238024770 of type U64 (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:52.609729938 [Client management]: Buffer registry per UID created id: 0, ABI: 64, uid: 1000, domain: 2 (in buffer_reg_uid_create() at buffer-registry.cpp:147)
DBG3 - 11:26:52.609874809 [Client management]: Created hashtable size 4 at 0x7f22380254d0 of type STRING (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:52.609907359 [Client management]: Created hashtable size 4 at 0x7f2238025a60 of type U64 (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:52.610025792 [Client management]: Session 0 found by id. (in session_find_by_id() at session.cpp:1152)
DBG3 - 11:26:52.610085556 [Client management]: Buffer registry per UID adding to global registry with id: 0 (in buffer_reg_uid_add() at buffer-registry.cpp:172)
DBG3 - 11:26:52.610106882 [Client management]: UST app buffer registry per UID created successfully (in setup_buffer_reg_uid() at ust-app.cpp:2686)
DBG2 - 11:26:52.610361274 [Client management]: UST app session created successfully with handle 3 (in find_or_create_ust_app_session() at ust-app.cpp:2800)
DBG3 - 11:26:52.610397255 [Client management]: Created hashtable size 4 at 0x7f2238027390 of type ULONG (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:52.610413689 [Client management]: Created hashtable size 4 at 0x7f2238027920 of type STRING (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:52.610427516 [Client management]: UST app channel chan allocated (in alloc_ust_app_channel() at ust-app.cpp:1231)
DBG2 - 11:26:52.610436525 [Client management]: UST app shadow copy of channel chan started (in shadow_copy_channel() at ust-app.cpp:2389)
DBG3 - 11:26:52.610463271 [Client management]: UST app shadow copy of channel chan done (in shadow_copy_channel() at ust-app.cpp:2415)
DBG1 - 11:26:52.610477691 [Client management]: UST app creating channel chan with per UID buffers (in create_channel_per_uid() at ust-app.cpp:3456)
DBG3 - 11:26:52.610491237 [Client management]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG2 - 11:26:52.610506092 [Client management]: UST app creating buffer registry channel for chan (in create_buffer_reg_channel() at ust-app.cpp:3267)
DBG3 - 11:26:52.610519450 [Client management]: Buffer registry channel create with key: 0 (in buffer_reg_channel_create() at buffer-registry.cpp:381)
DBG3 - 11:26:52.610550888 [Client management]: Created hashtable size 4 at 0x7f2238027f50 of type STRING (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:52.610579447 [Client management]: Session 0 found by id. (in session_find_by_id() at session.cpp:1152)
DBG2 - 11:26:52.610596474 [Client management]: Asking UST consumer for channel (in ask_channel_creation() at ust-consumer.cpp:58)
DBG3 - 11:26:52.610620727 [Client management]: Consumer trace path relative to current trace chunk: "ust/uid/1000/64-bit" (in setup_channel_trace_path() at consumer.cpp:75)
DBG2 - 11:26:52.622455810 [Client management]: UST ask channel 1 successfully done with 4 stream(s) (in ask_channel_creation() at ust-consumer.cpp:178)
DBG2 - 11:26:52.624473412 [Client management]: UST app stream 1 received successfully (in ust_consumer_get_channel() at ust-consumer.cpp:301)
DBG2 - 11:26:52.624523489 [Client management]: UST app stream 2 received successfully (in ust_consumer_get_channel() at ust-consumer.cpp:301)
DBG2 - 11:26:52.624559075 [Client management]: UST app stream 3 received successfully (in ust_consumer_get_channel() at ust-consumer.cpp:301)
DBG2 - 11:26:52.624593843 [Client management]: UST app stream 4 received successfully (in ust_consumer_get_channel() at ust-consumer.cpp:301)
DBG3 - 11:26:52.624621943 [Client management]: UST app consumer has no more stream available (in ust_consumer_get_channel() at ust-consumer.cpp:284)
DBG2 - 11:26:52.624641879 [Client management]: UST app setup buffer registry channel for chan (in setup_buffer_reg_channel() at ust-app.cpp:3322)
DBG2 - 11:26:52.624656605 [Client management]: UST app setup buffer registry stream (in setup_buffer_reg_streams() at ust-app.cpp:3221)
DBG3 - 11:26:52.624669949 [Client management]: Buffer registry creating stream (in buffer_reg_stream_create() at buffer-registry.cpp:411)
DBG3 - 11:26:52.624684299 [Client management]: Buffer registry creating stream (in buffer_reg_stream_create() at buffer-registry.cpp:411)
DBG3 - 11:26:52.624697568 [Client management]: Buffer registry creating stream (in buffer_reg_stream_create() at buffer-registry.cpp:411)
DBG3 - 11:26:52.624710622 [Client management]: Buffer registry creating stream (in buffer_reg_stream_create() at buffer-registry.cpp:411)
DBG1 - 11:26:52.624732963 [Client management]: Beginning of waiter "wait" period (in wait() at waiter.cpp:48)
DBG1 - 11:26:52.624796599 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:26:52.624824486 [Notification]: Handling fd (23) activity (1) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:26:52.624844379 [Notification]: Received `ADD_CHANNEL` command (in handle_notification_thread_command() at notification-thread-events.cpp:3191)
DBG1 - 11:26:52.624859604 [Notification]: Adding channel: channel name = `chan`, session id = 0, channel key = 1, domain = ust (in handle_notification_thread_command_add_channel() at notification-thread-events.cpp:1704)
DBG1 - 11:26:52.624882680 [Notification]: Found 0 triggers that apply to newly added channel (in handle_notification_thread_command_add_channel() at notification-thread-events.cpp:1745)
DBG1 - 11:26:52.624908501 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG1 - 11:26:52.624916043 [Client management]: End of waiter "wait" period (in wait() at waiter.cpp:109)
DBG1 - 11:26:52.624938224 [Client management]: UST app sending buffer registry channel to ust sock 51 (in send_channel_uid_to_ust() at ust-app.cpp:3359)
DBG2 - 11:26:52.624956495 [Client management]: UST app send channel to sock 51 pid 2152033 (name: chan, key: 0) (in ust_consumer_send_channel_to_ust() at ust-consumer.cpp:416)
DBG2 - 11:26:52.625112526 [Client management]: UST consumer send stream to app 51 (in ust_consumer_send_stream_to_ust() at ust-consumer.cpp:370)
DBG2 - 11:26:52.625596852 [Client management]: UST consumer send stream to app 51 (in ust_consumer_send_stream_to_ust() at ust-consumer.cpp:370)
DBG2 - 11:26:52.626046588 [Client management]: UST consumer send stream to app 51 (in ust_consumer_send_stream_to_ust() at ust-consumer.cpp:370)
DBG2 - 11:26:52.626490483 [Client management]: UST consumer send stream to app 51 (in ust_consumer_send_stream_to_ust() at ust-consumer.cpp:370)
DBG3 - 11:26:52.626905259 [Client management]: UST app event tp:tptest allocated (in alloc_ust_app_event() at ust-app.cpp:1285)
DBG2 - 11:26:52.626987361 [Client management]: UST app event tp:tptest created successfully for pid:2152033 object = 0x7f223802ea40 (in create_ust_event() at ust-app.cpp:2075)
DBG2 - 11:26:52.627056370 [Client management]: UST app object 0x7f223802ea40 enabled successfully for app: pid = 2152033 (in enable_ust_object() at ust-app.cpp:1955)
DBG2 - 11:26:52.627077644 [Client management]: UST app create event completed: app = 'gen-ust-events' pid = 2152033 (in create_ust_app_event() at ust-app.cpp:3817)
DBG3 - 11:26:52.627092789 [Client management]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:26:52.627112308 [Client management]: Created hashtable size 4 at 0x7f223802a630 of type ULONG (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:52.627127380 [Client management]: Created hashtable size 4 at 0x7f223802abc0 of type STRING (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:52.627141065 [Client management]: UST app channel metadata allocated (in alloc_ust_app_channel() at ust-app.cpp:1231)
DBG3 - 11:26:52.627156527 [Client management]: Session 0 found by id. (in session_find_by_id() at session.cpp:1152)
DBG2 - 11:26:52.627166889 [Client management]: Asking UST consumer for channel (in ask_channel_creation() at ust-consumer.cpp:58)
DBG3 - 11:26:52.627182084 [Client management]: Consumer trace path relative to current trace chunk: "ust/uid/1000/64-bit" (in setup_channel_trace_path() at consumer.cpp:75)
DBG2 - 11:26:52.627465318 [Client management]: UST ask channel 2 successfully done with 1 stream(s) (in ask_channel_creation() at ust-consumer.cpp:178)
DBG2 - 11:26:52.627496813 [Client management]: Consumer setup metadata channel key 2 (in consumer_setup_metadata() at consumer.cpp:1420)
DBG2 - 11:26:52.628087837 [Client management]: UST metadata with key 2 created for app pid 2152033 (in create_ust_app_metadata() at ust-app.cpp:3982)
DBG3 - 11:26:52.628119763 [Client management]: UST app deleting channel metadata (in delete_ust_app_channel() at ust-app.cpp:575)
DBG1 - 11:26:52.628144169 [Client management]: Starting tracing for ust app pid 2152033 (in ust_app_start_trace() at ust-app.cpp:5282)
DBG3 - 11:26:52.628276761 [Application notification]: [ust-thread] Manage notify return from poll on 3 fds (in thread_application_notification() at notify-apps.cpp:81)
DBG3 - 11:26:52.628300608 [Application notification]: UST app receiving notify from sock 52 (in ust_app_recv_notify() at ust-app.cpp:6900)
DBG2 - 11:26:52.628321538 [Application notification]: UST app ustctl register enum received (in ust_app_recv_notify() at ust-app.cpp:7032)
DBG3 - 11:26:52.628360312 [Application notification]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG1 - 11:26:52.628385013 [Application notification]: UST registry creating enum: tp_tptest_enum, sess_objd: 3 (in create_or_find_enum() at ust-registry-session.cpp:825)
DBG1 - 11:26:52.628415763 [Application notification]: UST registry reply with enum tp_tptest_enum with id 0 in sess_objd: 3 (in create_or_find_enum() at ust-registry-session.cpp:841)
DBG3 - 11:26:52.628439401 [Application notification]: UST registry enum tp_tptest_enum added successfully or already found (in add_enum_ust_registry() at ust-app.cpp:6886)
DBG3 - 11:26:52.628455483 [Application notification]: [ust-thread] Manage notify polling (in thread_application_notification() at notify-apps.cpp:75)
DBG3 - 11:26:52.628608397 [Application notification]: [ust-thread] Manage notify return from poll on 3 fds (in thread_application_notification() at notify-apps.cpp:81)
DBG3 - 11:26:52.628625678 [Application notification]: UST app receiving notify from sock 52 (in ust_app_recv_notify() at ust-app.cpp:6900)
DBG2 - 11:26:52.628642496 [Application notification]: UST app ustctl register event received (in ust_app_recv_notify() at ust-app.cpp:6922)
DBG3 - 11:26:52.628720470 [Application notification]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:26:52.628811824 [Application notification]: UST registry creating event: event = { name = `tp:tptest`, signature = `int, anint, int, netint, long *, values, char *, text, size_t, textlen, char *, etext, uint32_t *, net_values, double, doublearg, float, floatarg`, id = 0, session objd = 3, channel objd = 4 } (in add_event() at ust-registry-channel.cpp:421)
DBG3 - 11:26:52.628842683 [Application notification]: UST registry event tp:tptest with id 0 added successfully (in add_event_ust_registry() at ust-app.cpp:6789)
DBG3 - 11:26:52.628858408 [Application notification]: [ust-thread] Manage notify polling (in thread_application_notification() at notify-apps.cpp:75)
DBG3 - 11:26:52.628954132 [Application notification]: [ust-thread] Manage notify return from poll on 3 fds (in thread_application_notification() at notify-apps.cpp:81)
DBG3 - 11:26:52.628968677 [Application notification]: UST app receiving notify from sock 52 (in ust_app_recv_notify() at ust-app.cpp:6900)
DBG2 - 11:26:52.628985081 [Application notification]: UST app ustctl register channel received (in ust_app_recv_notify() at ust-app.cpp:6993)
DBG3 - 11:26:52.629004646 [Application notification]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:26:52.629021117 [Application notification]: UST app replying to register channel key 0 with id 0, ret = 0 (in handle_app_register_channel_notification() at ust-app.cpp:6626)
DBG3 - 11:26:52.629237242 [Application notification]: [ust-thread] Manage notify polling (in thread_application_notification() at notify-apps.cpp:75)
DBG1 - 11:26:52.632207758 [Client management]: Opening packets of session channels: session name = oc4iKoCkS4oPhaVB, session id = 0 (in session_open_packets() at session.cpp:878)
DBG1 - 11:26:52.632241321 [Client management]: Consumer open channel packets: channel key = 1 (in consumer_open_channel_packets() at consumer.cpp:1743)
DBG1 - 11:26:52.632396587 [Client management]: Sending response (size: 24, retcode: Success (10)) (in thread_manage_clients() at client.cpp:2652)
DBG1 - 11:26:52.632454537 [Client management]: Accepting client command ... (in thread_manage_clients() at client.cpp:2489)
DBG1 - 11:26:53.623055602 [Consumer management]: Metadata request received for session 0, key 2 (in ust_consumer_metadata_request() at ust-consumer.cpp:476)
DBG3 - 11:26:53.623155920 [Consumer management]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG2 - 11:26:53.623223824 [Consumer management]: Consumer push metadata to consumer socket 68 (in consumer_push_metadata() at consumer.cpp:1459)
DBG3 - 11:26:53.623498210 [Consumer management]: Consumer pushing metadata on sock 68 of len 4983 (in consumer_push_metadata() at consumer.cpp:1476)
DBG1 - 11:26:53.623810130 [Consumer management]: UST Consumer metadata pushed successfully (in ust_consumer_metadata_request() at ust-consumer.cpp:518)
DBG1 - 11:26:53.624274812 [Consumer management]: Metadata request received for session 0, key 2 (in ust_consumer_metadata_request() at ust-consumer.cpp:476)
DBG3 - 11:26:53.624322160 [Consumer management]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:26:53.624355344 [Consumer management]: No metadata to push for metadata key 2 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG1 - 11:26:53.624384047 [Consumer management]: No metadata to push (in ust_app_push_metadata() at ust-app.cpp:723)
DBG2 - 11:26:53.624401823 [Consumer management]: Consumer push metadata to consumer socket 68 (in consumer_push_metadata() at consumer.cpp:1459)
DBG1 - 11:26:53.624632347 [Consumer management]: UST Consumer metadata pushed successfully (in ust_consumer_metadata_request() at ust-consumer.cpp:518)
DBG1 - 11:26:53.667309802 [Consumer management]: Metadata request received for session 0, key 2 (in ust_consumer_metadata_request() at ust-consumer.cpp:476)
DBG3 - 11:26:53.667388767 [Consumer management]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:26:53.667424747 [Consumer management]: No metadata to push for metadata key 2 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG1 - 11:26:53.667460961 [Consumer management]: No metadata to push (in ust_app_push_metadata() at ust-app.cpp:723)
DBG2 - 11:26:53.667482072 [Consumer management]: Consumer push metadata to consumer socket 68 (in consumer_push_metadata() at consumer.cpp:1459)
DBG1 - 11:26:53.667714654 [Consumer management]: UST Consumer metadata pushed successfully (in ust_consumer_metadata_request() at ust-consumer.cpp:518)
DBG1 - 11:26:53.668802259 [Consumer management]: Metadata request received for session 0, key 2 (in ust_consumer_metadata_request() at ust-consumer.cpp:476)
DBG3 - 11:26:53.668871775 [Consumer management]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:26:53.668908093 [Consumer management]: No metadata to push for metadata key 2 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG1 - 11:26:53.668938570 [Consumer management]: No metadata to push (in ust_app_push_metadata() at ust-app.cpp:723)
DBG2 - 11:26:53.668956806 [Consumer management]: Consumer push metadata to consumer socket 68 (in consumer_push_metadata() at consumer.cpp:1459)
DBG1 - 11:26:53.669186293 [Consumer management]: UST Consumer metadata pushed successfully (in ust_consumer_metadata_request() at ust-consumer.cpp:518)
DBG1 - 11:26:53.670307467 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:26:53.670369804 [Notification]: Handling fd (11) activity (1) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:26:53.670407917 [Consumer management]: Metadata request received for session 0, key 2 (in ust_consumer_metadata_request() at ust-consumer.cpp:476)
DBG3 - 11:26:53.670488506 [Consumer management]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:26:53.670528755 [Consumer management]: No metadata to push for metadata key 2 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG1 - 11:26:53.670565235 [Consumer management]: No metadata to push (in ust_app_push_metadata() at ust-app.cpp:723)
DBG1 - 11:26:53.670418226 [Notification]: Handling channel sample for channel chan (key = 1) in session oc4iKoCkS4oPhaVB (highest usage = 524288, lowest usage = 0, consumed since last sample = 252) (in handle_notification_thread_channel_sample() at notification-thread-events.cpp:4944)
DBG1 - 11:26:53.670673478 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG2 - 11:26:53.670584989 [Consumer management]: Consumer push metadata to consumer socket 68 (in consumer_push_metadata() at consumer.cpp:1459)
DBG1 - 11:26:53.670979230 [Consumer management]: UST Consumer metadata pushed successfully (in ust_consumer_metadata_request() at ust-consumer.cpp:518)
DBG1 - 11:26:54.322060988 [UST application registration]: UST registration received with pid:2152120 ppid:2151972 uid:1000 gid:1000 sock:62 name:gen-ust-events (version 10.0) (in thread_application_registration() at register.cpp:311)
DBG1 - 11:26:54.322157541 [UST application registration]: Futex n to 1 wake done (in futex_nto1_wake() at futex.cpp:116)
DBG1 - 11:26:54.322178381 [UST application registration]: Accepting application registration (in thread_application_registration() at register.cpp:206)
DBG1 - 11:26:54.322258812 [UST application registration]: UST registration received with pid:2152120 ppid:2151972 uid:1000 gid:1000 sock:79 name:gen-ust-events (version 10.0) (in thread_application_registration() at register.cpp:311)
DBG1 - 11:26:54.322301277 [UST application registration]: Futex n to 1 wake done (in futex_nto1_wake() at futex.cpp:116)
DBG1 - 11:26:54.322258860 [UST registration dispatch]: Futex n to 1 wait done (in futex_nto1_wait() at futex.cpp:100)
DBG1 - 11:26:54.322382307 [UST registration dispatch]: Futex n to 1 prepare done (in futex_nto1_prepare() at futex.cpp:64)
DBG1 - 11:26:54.322408187 [UST registration dispatch]: Dispatching UST registration pid:2152120 ppid:2151972 uid:1000 gid:1000 sock:62 name:gen-ust-events (version 10.0) (in thread_dispatch_ust_registration() at dispatch.cpp:281)
DBG1 - 11:26:54.322318965 [UST application registration]: Accepting application registration (in thread_application_registration() at register.cpp:206)
DBG3 - 11:26:54.322462316 [UST registration dispatch]: UST app creating application for socket 62 (in ust_app_create() at ust-app.cpp:4035)
DBG3 - 11:26:54.322702524 [UST registration dispatch]: Created hashtable size 4 at 0x7f2220003ba0 of type U64 (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:54.322746224 [UST registration dispatch]: Created hashtable size 4 at 0x7f2220004130 of type ULONG (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:54.322775547 [UST registration dispatch]: Created hashtable size 4 at 0x7f22200046c0 of type ULONG (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:54.322813061 [UST registration dispatch]: Created hashtable size 4 at 0x7f2220004c50 of type U64 (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG1 - 11:26:54.322884703 [UST registration dispatch]: Dispatching UST registration pid:2152120 ppid:2151972 uid:1000 gid:1000 sock:79 name:gen-ust-events (version 10.0) (in thread_dispatch_ust_registration() at dispatch.cpp:281)
DBG3 - 11:26:54.322919996 [UST registration dispatch]: UST app notify socket 79 is set (in thread_dispatch_ust_registration() at dispatch.cpp:351)
DBG1 - 11:26:54.322970090 [UST registration dispatch]: App registered with pid:2152120 ppid:2151972 uid:1000 gid:1000 sock =62 name:gen-ust-events notify_sock =79 (version 10.0) (in ust_app_add() at ust-app.cpp:4158)
DBG1 - 11:26:54.323494718 [UST registration dispatch]: Beginning of waiter "wait" period (in wait() at waiter.cpp:48)
DBG1 - 11:26:54.323577132 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:26:54.323634652 [Notification]: Handling fd (23) activity (1) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:26:54.323675495 [Notification]: Received `ADD_TRACER_EVENT_SOURCE` command (in handle_notification_thread_command() at notification-thread-events.cpp:3191)
DBG3 - 11:26:54.323706874 [Notification]: Adding tracer event source fd to poll set: tracer_event_source_fd = 80, domain = 'ust' (in handle_notification_thread_command_add_tracer_event_source() at notification-thread-events.cpp:2071)
DBG1 - 11:26:54.323761057 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG1 - 11:26:54.323773368 [UST registration dispatch]: End of waiter "wait" period (in wait() at waiter.cpp:109)
DBG2 - 11:26:54.324839614 [UST registration dispatch]: UST application global event notifier rules update: app = 'gen-ust-events', pid = 2152120 (in ust_app_global_update_event_notifier_rules() at ust-app.cpp:6291)
DBG1 - 11:26:54.324921044 [UST registration dispatch]: Beginning of waiter "wait" period (in wait() at waiter.cpp:48)
DBG1 - 11:26:54.324946567 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:26:54.325006082 [Notification]: Handling fd (23) activity (1) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:26:54.325046801 [Notification]: Received `LIST_TRIGGERS` command (in handle_notification_thread_command() at notification-thread-events.cpp:3191)
DBG3 - 11:26:54.324921907 [Application notification]: [ust-thread] Manage notify return from poll on 3 fds (in thread_application_notification() at notify-apps.cpp:81)
DBG1 - 11:26:54.325087808 [UST registration dispatch]: End of waiter "wait" period (in wait() at waiter.cpp:109)
DBG3 - 11:26:54.325166351 [Application notification]: UST thread notify added sock 79 to pollset (in thread_application_notification() at notify-apps.cpp:140)
DBG3 - 11:26:54.325210236 [Application notification]: [ust-thread] Manage notify polling (in thread_application_notification() at notify-apps.cpp:75)
DBG1 - 11:26:54.325087991 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG2 - 11:26:54.325170622 [UST registration dispatch]: UST app global update for app sock 62 for session id 0 (in ust_app_global_update() at ust-app.cpp:6262)
DBG2 - 11:26:54.325328738 [UST registration dispatch]: UST app pid: 2152120 session id 0 not found, creating it (in find_or_create_ust_app_session() at ust-app.cpp:2722)
DBG3 - 11:26:54.325399030 [UST registration dispatch]: Created hashtable size 4 at 0x7f2220008c80 of type STRING (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG2 - 11:26:54.325465420 [UST registration dispatch]: Shadow copy of session handle -1 (in shadow_copy_session() at ust-app.cpp:2433)
DBG3 - 11:26:54.325509449 [UST registration dispatch]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG2 - 11:26:54.326087375 [UST registration dispatch]: UST app session created successfully with handle 3 (in find_or_create_ust_app_session() at ust-app.cpp:2800)
DBG3 - 11:26:54.326143870 [UST registration dispatch]: Created hashtable size 4 at 0x7f2220009440 of type ULONG (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:54.326173382 [UST registration dispatch]: Created hashtable size 4 at 0x7f22200099d0 of type STRING (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:54.326200501 [UST registration dispatch]: UST app channel chan allocated (in alloc_ust_app_channel() at ust-app.cpp:1231)
DBG2 - 11:26:54.326227169 [UST registration dispatch]: UST app shadow copy of channel chan started (in shadow_copy_channel() at ust-app.cpp:2389)
DBG3 - 11:26:54.326253985 [UST registration dispatch]: UST app shadow copy of channel chan done (in shadow_copy_channel() at ust-app.cpp:2415)
DBG1 - 11:26:54.326281399 [UST registration dispatch]: UST app creating channel chan with per UID buffers (in create_channel_per_uid() at ust-app.cpp:3456)
DBG3 - 11:26:54.326307866 [UST registration dispatch]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG1 - 11:26:54.326337307 [UST registration dispatch]: UST app sending buffer registry channel to ust sock 62 (in send_channel_uid_to_ust() at ust-app.cpp:3359)
DBG2 - 11:26:54.326383287 [UST registration dispatch]: UST app send channel to sock 62 pid 2152120 (name: chan, key: 0) (in ust_consumer_send_channel_to_ust() at ust-consumer.cpp:416)
DBG2 - 11:26:54.326829520 [UST registration dispatch]: UST consumer send stream to app 62 (in ust_consumer_send_stream_to_ust() at ust-consumer.cpp:370)
DBG2 - 11:26:54.327727557 [UST registration dispatch]: UST consumer send stream to app 62 (in ust_consumer_send_stream_to_ust() at ust-consumer.cpp:370)
DBG2 - 11:26:54.328635791 [UST registration dispatch]: UST consumer send stream to app 62 (in ust_consumer_send_stream_to_ust() at ust-consumer.cpp:370)
DBG2 - 11:26:54.329447006 [UST registration dispatch]: UST consumer send stream to app 62 (in ust_consumer_send_stream_to_ust() at ust-consumer.cpp:370)
DBG3 - 11:26:54.330329491 [UST registration dispatch]: UST app event tp:tptest allocated (in alloc_ust_app_event() at ust-app.cpp:1285)
DBG2 - 11:26:54.330573912 [UST registration dispatch]: UST app event tp:tptest created successfully for pid:2152120 object = 0x7f222000ad70 (in create_ust_event() at ust-app.cpp:2075)
DBG2 - 11:26:54.330743418 [UST registration dispatch]: UST app object 0x7f222000ad70 enabled successfully for app: pid = 2152120 (in enable_ust_object() at ust-app.cpp:1955)
DBG2 - 11:26:54.330791517 [UST registration dispatch]: UST app create event completed: app = 'gen-ust-events' pid = 2152120 (in create_ust_app_event() at ust-app.cpp:3817)
DBG3 - 11:26:54.330821873 [UST registration dispatch]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG1 - 11:26:54.330854395 [UST registration dispatch]: Starting tracing for ust app pid 2152120 (in ust_app_start_trace() at ust-app.cpp:5282)
DBG3 - 11:26:54.330965434 [Application notification]: [ust-thread] Manage notify return from poll on 4 fds (in thread_application_notification() at notify-apps.cpp:81)
DBG3 - 11:26:54.331010035 [Application notification]: UST app receiving notify from sock 79 (in ust_app_recv_notify() at ust-app.cpp:6900)
DBG2 - 11:26:54.331045280 [Application notification]: UST app ustctl register channel received (in ust_app_recv_notify() at ust-app.cpp:6993)
DBG3 - 11:26:54.331083636 [Application notification]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:26:54.331119104 [Application notification]: UST app replying to register channel key 0 with id 0, ret = 0 (in handle_app_register_channel_notification() at ust-app.cpp:6626)
DBG3 - 11:26:54.331160674 [Application notification]: [ust-thread] Manage notify polling (in thread_application_notification() at notify-apps.cpp:75)
DBG1 - 11:26:54.337692026 [UST registration dispatch]: Woken up but nothing in the UST command queue (in thread_dispatch_ust_registration() at dispatch.cpp:274)
DBG3 - 11:26:54.337766557 [Application notification]: [ust-thread] Manage notify return from poll on 4 fds (in thread_application_notification() at notify-apps.cpp:81)
DBG3 - 11:26:54.337837652 [Application notification]: UST app receiving notify from sock 79 (in ust_app_recv_notify() at ust-app.cpp:6900)
DBG1 - 11:26:54.337712291 [UST application management]: Apps thread return from poll on 3 fds (in thread_application_management() at manage-apps.cpp:96)
DBG2 - 11:26:54.337880983 [Application notification]: UST app ustctl register enum received (in ust_app_recv_notify() at ust-app.cpp:7032)
DBG3 - 11:26:54.338077122 [Application notification]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG1 - 11:26:54.337965226 [UST application management]: Apps with sock 62 added to poll set (in thread_application_management() at manage-apps.cpp:149)
DBG1 - 11:26:54.338211891 [UST application management]: Apps thread polling (in thread_application_management() at manage-apps.cpp:90)
DBG1 - 11:26:54.338148203 [Application notification]: enum tp_tptest_enum already in sess_objd: 3 (in create_or_find_enum() at ust-registry-session.cpp:820)
DBG1 - 11:26:54.338347425 [Application notification]: UST registry reply with enum tp_tptest_enum with id 0 in sess_objd: 3 (in create_or_find_enum() at ust-registry-session.cpp:841)
DBG3 - 11:26:54.338408736 [Application notification]: UST registry enum tp_tptest_enum added successfully or already found (in add_enum_ust_registry() at ust-app.cpp:6886)
DBG3 - 11:26:54.338444880 [Application notification]: [ust-thread] Manage notify polling (in thread_application_notification() at notify-apps.cpp:75)
DBG3 - 11:26:54.338624703 [Application notification]: [ust-thread] Manage notify return from poll on 4 fds (in thread_application_notification() at notify-apps.cpp:81)
DBG3 - 11:26:54.338716237 [Application notification]: UST app receiving notify from sock 79 (in ust_app_recv_notify() at ust-app.cpp:6900)
DBG2 - 11:26:54.338757854 [Application notification]: UST app ustctl register event received (in ust_app_recv_notify() at ust-app.cpp:6922)
DBG3 - 11:26:54.338934826 [Application notification]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:26:54.339181725 [Application notification]: UST registry creating event: event = { name = `tp:tptest`, signature = `int, anint, int, netint, long *, values, char *, text, size_t, textlen, char *, etext, uint32_t *, net_values, double, doublearg, float, floatarg`, id = 1, session objd = 3, channel objd = 4 } (in add_event() at ust-registry-channel.cpp:421)
DBG3 - 11:26:54.339313806 [Application notification]: UST registry event tp:tptest with id 0 added successfully (in add_event_ust_registry() at ust-app.cpp:6789)
DBG3 - 11:26:54.339353310 [Application notification]: [ust-thread] Manage notify polling (in thread_application_notification() at notify-apps.cpp:75)
DBG1 - 11:26:54.624123168 [Consumer management]: Metadata request received for session 0, key 2 (in ust_consumer_metadata_request() at ust-consumer.cpp:476)
DBG3 - 11:26:54.624201660 [Consumer management]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:26:54.624237196 [Consumer management]: No metadata to push for metadata key 2 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG1 - 11:26:54.624265517 [Consumer management]: No metadata to push (in ust_app_push_metadata() at ust-app.cpp:723)
DBG2 - 11:26:54.624285650 [Consumer management]: Consumer push metadata to consumer socket 68 (in consumer_push_metadata() at consumer.cpp:1459)
DBG1 - 11:26:54.624500986 [Consumer management]: UST Consumer metadata pushed successfully (in ust_consumer_metadata_request() at ust-consumer.cpp:518)
DBG1 - 11:26:54.625380799 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:26:54.625441512 [Notification]: Handling fd (11) activity (1) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:26:54.625489025 [Notification]: Handling channel sample for channel chan (key = 1) in session oc4iKoCkS4oPhaVB (highest usage = 0, lowest usage = 0, consumed since last sample = 2216) (in handle_notification_thread_channel_sample() at notification-thread-events.cpp:4944)
DBG1 - 11:26:54.625531300 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG1 - 11:26:54.886334277 [Client management]: Wait for client response (in thread_manage_clients() at client.cpp:2534)
DBG1 - 11:26:54.886385845 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.cpp:2562)
DBG1 - 11:26:54.886408126 [Client management]: Processing client command 'LIST_SESSIONS' (11) (in process_client_msg() at client.cpp:1007)
DBG1 - 11:26:54.886424481 [Client management]: Counting number of available session for UID 1000 (in lttng_sessions_count() at client.cpp:597)
DBG1 - 11:26:54.886439924 [Client management]: Getting all available session for UID 1000 GID 1000 (in cmd_list_lttng_sessions() at cmd.cpp:3971)
DBG1 - 11:26:54.886459816 [Client management]: Sending response (size: 4409, retcode: Success (10)) (in thread_manage_clients() at client.cpp:2652)
DBG1 - 11:26:54.886488235 [Client management]: Accepting client command ... (in thread_manage_clients() at client.cpp:2489)
DBG1 - 11:26:54.886685140 [Client management]: Wait for client response (in thread_manage_clients() at client.cpp:2534)
DBG1 - 11:26:54.886720515 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.cpp:2562)
DBG1 - 11:26:54.886742784 [Client management]: Processing client command 'STOP_TRACE' (15) (in process_client_msg() at client.cpp:1007)
DBG1 - 11:26:54.886757990 [Client management]: Getting session oc4iKoCkS4oPhaVB by name (in process_client_msg() at client.cpp:1122)
DBG2 - 11:26:54.886783728 [Client management]: Trying to find session by name oc4iKoCkS4oPhaVB (in session_find_by_name() at session.cpp:1114)
DBG1 - 11:26:54.886796970 [Client management]: Begin stop session "oc4iKoCkS4oPhaVB" (id 0) (in cmd_stop_trace() at cmd.cpp:2888)
DBG1 - 11:26:54.886809934 [Client management]: Stopping all UST traces (in ust_app_stop_trace_all() at ust-app.cpp:5873)
DBG1 - 11:26:54.886819220 [Client management]: Stopping tracing for ust app pid 2152033 (in ust_app_stop_trace() at ust-app.cpp:5390)
DBG3 - 11:26:54.887026051 [Client management]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:26:54.887056001 [Client management]: No metadata to push for metadata key 2 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG1 - 11:26:54.887069848 [Client management]: Stopping tracing for ust app pid 2152120 (in ust_app_stop_trace() at ust-app.cpp:5390)
DBG3 - 11:26:54.887289448 [Client management]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:26:54.887317746 [Client management]: No metadata to push for metadata key 2 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG1 - 11:26:54.887331223 [Client management]: Flushing session buffers for all ust apps (in ust_app_flush_session() at ust-app.cpp:5562)
DBG2 - 11:26:54.887344382 [Client management]: Consumer flush channel key 1 (in consumer_flush_channel() at consumer.cpp:1323)
DBG1 - 11:26:54.887489351 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:26:54.887501321 [Notification]: Handling fd (11) activity (1) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:26:54.887520133 [Notification]: Handling channel sample for channel chan (key = 1) in session oc4iKoCkS4oPhaVB (highest usage = 524288, lowest usage = 524288, consumed since last sample = 252) (in handle_notification_thread_channel_sample() at notification-thread-events.cpp:4944)
DBG1 - 11:26:54.887538805 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG3 - 11:26:54.887540999 [Client management]: No metadata to push for metadata key 2 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG1 - 11:26:54.887575495 [Client management]: Completed stop session "oc4iKoCkS4oPhaVB" (id 0) (in cmd_stop_trace() at cmd.cpp:2912)
DBG1 - 11:26:54.887590377 [Client management]: Sending response (size: 24, retcode: Success (10)) (in thread_manage_clients() at client.cpp:2652)
DBG1 - 11:26:54.887594867 [Consumer management]: Metadata request received for session 0, key 2 (in ust_consumer_metadata_request() at ust-consumer.cpp:476)
DBG3 - 11:26:54.887644137 [Consumer management]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:26:54.887660150 [Consumer management]: No metadata to push for metadata key 2 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG1 - 11:26:54.887674689 [Consumer management]: No metadata to push (in ust_app_push_metadata() at ust-app.cpp:723)
DBG2 - 11:26:54.887690038 [Consumer management]: Consumer push metadata to consumer socket 68 (in consumer_push_metadata() at consumer.cpp:1459)
DBG1 - 11:26:54.887624412 [Client management]: Accepting client command ... (in thread_manage_clients() at client.cpp:2489)
DBG1 - 11:26:54.887788368 [Consumer management]: UST Consumer metadata pushed successfully (in ust_consumer_metadata_request() at ust-consumer.cpp:518)
DBG1 - 11:26:54.887816509 [Client management]: Wait for client response (in thread_manage_clients() at client.cpp:2534)
DBG1 - 11:26:54.887870449 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.cpp:2562)
DBG1 - 11:26:54.887894635 [Client management]: Processing client command 'DATA_PENDING' (20) (in process_client_msg() at client.cpp:1007)
DBG1 - 11:26:54.887910862 [Client management]: Getting session oc4iKoCkS4oPhaVB by name (in process_client_msg() at client.cpp:1122)
DBG2 - 11:26:54.887936283 [Client management]: Trying to find session by name oc4iKoCkS4oPhaVB (in session_find_by_name() at session.cpp:1114)
DBG1 - 11:26:54.887950749 [Client management]: Data pending for session oc4iKoCkS4oPhaVB (in cmd_data_pending() at cmd.cpp:4032)
DBG3 - 11:26:54.887963752 [Client management]: Consumer data pending for id 0 (in consumer_is_data_pending() at consumer.cpp:1266)
DBG1 - 11:26:54.888034220 [Client management]: Consumer data is pending for session id 0 (in consumer_is_data_pending() at consumer.cpp:1302)
DBG1 - 11:26:54.888066119 [Client management]: Sending response (size: 25, retcode: Success (10)) (in thread_manage_clients() at client.cpp:2652)
DBG1 - 11:26:54.888097317 [Client management]: Accepting client command ... (in thread_manage_clients() at client.cpp:2489)
DBG1 - 11:26:54.888134171 [Consumer management]: Metadata request received for session 0, key 2 (in ust_consumer_metadata_request() at ust-consumer.cpp:476)
DBG3 - 11:26:54.888155667 [Consumer management]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:26:54.888170976 [Consumer management]: No metadata to push for metadata key 2 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG1 - 11:26:54.888183477 [Consumer management]: No metadata to push (in ust_app_push_metadata() at ust-app.cpp:723)
DBG2 - 11:26:54.888191470 [Consumer management]: Consumer push metadata to consumer socket 68 (in consumer_push_metadata() at consumer.cpp:1459)
DBG1 - 11:26:54.888237957 [Consumer management]: UST Consumer metadata pushed successfully (in ust_consumer_metadata_request() at ust-consumer.cpp:518)
DBG1 - 11:26:54.888515865 [Consumer management]: Metadata request received for session 0, key 2 (in ust_consumer_metadata_request() at ust-consumer.cpp:476)
DBG3 - 11:26:54.888530471 [Consumer management]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:26:54.888544257 [Consumer management]: No metadata to push for metadata key 2 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG1 - 11:26:54.888556593 [Consumer management]: No metadata to push (in ust_app_push_metadata() at ust-app.cpp:723)
DBG2 - 11:26:54.888566616 [Consumer management]: Consumer push metadata to consumer socket 68 (in consumer_push_metadata() at consumer.cpp:1459)
DBG1 - 11:26:54.888609882 [Consumer management]: UST Consumer metadata pushed successfully (in ust_consumer_metadata_request() at ust-consumer.cpp:518)
DBG1 - 11:26:54.888893195 [Consumer management]: Metadata request received for session 0, key 2 (in ust_consumer_metadata_request() at ust-consumer.cpp:476)
DBG3 - 11:26:54.888909853 [Consumer management]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:26:54.888923188 [Consumer management]: No metadata to push for metadata key 2 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG1 - 11:26:54.888935428 [Consumer management]: No metadata to push (in ust_app_push_metadata() at ust-app.cpp:723)
DBG2 - 11:26:54.888943136 [Consumer management]: Consumer push metadata to consumer socket 68 (in consumer_push_metadata() at consumer.cpp:1459)
DBG1 - 11:26:54.889027021 [Consumer management]: UST Consumer metadata pushed successfully (in ust_consumer_metadata_request() at ust-consumer.cpp:518)
DBG1 - 11:26:55.088799250 [Client management]: Wait for client response (in thread_manage_clients() at client.cpp:2534)
DBG1 - 11:26:55.088935941 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.cpp:2562)
DBG1 - 11:26:55.089004684 [Client management]: Processing client command 'DATA_PENDING' (20) (in process_client_msg() at client.cpp:1007)
DBG1 - 11:26:55.089047806 [Client management]: Getting session oc4iKoCkS4oPhaVB by name (in process_client_msg() at client.cpp:1122)
DBG2 - 11:26:55.089117878 [Client management]: Trying to find session by name oc4iKoCkS4oPhaVB (in session_find_by_name() at session.cpp:1114)
DBG1 - 11:26:55.089191722 [Client management]: Data pending for session oc4iKoCkS4oPhaVB (in cmd_data_pending() at cmd.cpp:4032)
DBG3 - 11:26:55.089227205 [Client management]: Consumer data pending for id 0 (in consumer_is_data_pending() at consumer.cpp:1266)
DBG1 - 11:26:55.093683003 [Client management]: Consumer data is NOT pending for session id 0 (in consumer_is_data_pending() at consumer.cpp:1302)
DBG1 - 11:26:55.093795546 [Client management]: Sending response (size: 25, retcode: Success (10)) (in thread_manage_clients() at client.cpp:2652)
DBG1 - 11:26:55.093883503 [Client management]: Accepting client command ... (in thread_manage_clients() at client.cpp:2489)
DBG1 - 11:26:55.094266969 [Client management]: Wait for client response (in thread_manage_clients() at client.cpp:2534)
DBG1 - 11:26:55.094373407 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.cpp:2562)
DBG1 - 11:26:55.094438768 [Client management]: Processing client command 'LIST_SESSIONS' (11) (in process_client_msg() at client.cpp:1007)
DBG1 - 11:26:55.094479259 [Client management]: Counting number of available session for UID 1000 (in lttng_sessions_count() at client.cpp:597)
DBG1 - 11:26:55.094515426 [Client management]: Getting all available session for UID 1000 GID 1000 (in cmd_list_lttng_sessions() at cmd.cpp:3971)
DBG1 - 11:26:55.094561981 [Client management]: Sending response (size: 4409, retcode: Success (10)) (in thread_manage_clients() at client.cpp:2652)
DBG1 - 11:26:55.094640020 [Client management]: Accepting client command ... (in thread_manage_clients() at client.cpp:2489)
DBG1 - 11:26:55.094983884 [Client management]: Wait for client response (in thread_manage_clients() at client.cpp:2534)
DBG1 - 11:26:55.095117166 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.cpp:2562)
DBG1 - 11:26:55.095176331 [Client management]: Processing client command 'LIST_DOMAINS' (9) (in process_client_msg() at client.cpp:1007)
DBG1 - 11:26:55.095211528 [Client management]: Getting session oc4iKoCkS4oPhaVB by name (in process_client_msg() at client.cpp:1122)
DBG2 - 11:26:55.095239911 [Client management]: Trying to find session by name oc4iKoCkS4oPhaVB (in session_find_by_name() at session.cpp:1114)
DBG3 - 11:26:55.095269208 [Client management]: Listing domains found UST global domain (in cmd_list_domains() at cmd.cpp:3669)
DBG1 - 11:26:55.095296138 [Client management]: Sending response (size: 332, retcode: Success (10)) (in thread_manage_clients() at client.cpp:2652)
DBG1 - 11:26:55.095359075 [Client management]: Accepting client command ... (in thread_manage_clients() at client.cpp:2489)
DBG1 - 11:26:55.095742027 [Client management]: Wait for client response (in thread_manage_clients() at client.cpp:2534)
DBG1 - 11:26:55.095827547 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.cpp:2562)
DBG1 - 11:26:55.095882834 [Client management]: Processing client command 'LIST_CHANNELS' (8) (in process_client_msg() at client.cpp:1007)
DBG1 - 11:26:55.095917293 [Client management]: Getting session oc4iKoCkS4oPhaVB by name (in process_client_msg() at client.cpp:1122)
DBG2 - 11:26:55.095945827 [Client management]: Trying to find session by name oc4iKoCkS4oPhaVB (in session_find_by_name() at session.cpp:1114)
DBG3 - 11:26:55.095978552 [Client management]: Consumer socket created (fd: 67) and added to output (in consumer_create_socket() at consumer.cpp:347)
DBG1 - 11:26:55.096007732 [Client management]: Setting relayd for session oc4iKoCkS4oPhaVB (in cmd_setup_relayd() at cmd.cpp:1029)
DBG1 - 11:26:55.096038328 [Client management]: Listing channels for session oc4iKoCkS4oPhaVB (in cmd_list_channels() at cmd.cpp:3744)
DBG3 - 11:26:55.096116507 [Client management]: Consumer discarded events id 0 (in consumer_get_discarded_events() at consumer.cpp:1576)
DBG1 - 11:26:55.096343662 [Client management]: Consumer discarded 0 events in session id 0 (in consumer_get_discarded_events() at consumer.cpp:1617)
DBG1 - 11:26:55.096416700 [Client management]: Sending response (size: 116, retcode: Success (10)) (in thread_manage_clients() at client.cpp:2652)
DBG1 - 11:26:55.096511582 [Client management]: Accepting client command ... (in thread_manage_clients() at client.cpp:2489)
DBG1 - 11:26:55.144807880 [Client management]: Wait for client response (in thread_manage_clients() at client.cpp:2534)
DBG1 - 11:26:55.144881874 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.cpp:2562)
DBG1 - 11:26:55.144918521 [Client management]: Processing client command 'LIST_SESSIONS' (11) (in process_client_msg() at client.cpp:1007)
DBG1 - 11:26:55.144942938 [Client management]: Counting number of available session for UID 1000 (in lttng_sessions_count() at client.cpp:597)
DBG1 - 11:26:55.144966923 [Client management]: Getting all available session for UID 1000 GID 1000 (in cmd_list_lttng_sessions() at cmd.cpp:3971)
DBG1 - 11:26:55.144996897 [Client management]: Sending response (size: 4409, retcode: Success (10)) (in thread_manage_clients() at client.cpp:2652)
DBG1 - 11:26:55.145041871 [Client management]: Accepting client command ... (in thread_manage_clients() at client.cpp:2489)
DBG1 - 11:26:55.145326132 [Client management]: Wait for client response (in thread_manage_clients() at client.cpp:2534)
DBG1 - 11:26:55.145382065 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.cpp:2562)
DBG1 - 11:26:55.145416598 [Client management]: Processing client command 'STOP_TRACE' (15) (in process_client_msg() at client.cpp:1007)
DBG1 - 11:26:55.145439388 [Client management]: Getting session oc4iKoCkS4oPhaVB by name (in process_client_msg() at client.cpp:1122)
DBG2 - 11:26:55.145459211 [Client management]: Trying to find session by name oc4iKoCkS4oPhaVB (in session_find_by_name() at session.cpp:1114)
DBG1 - 11:26:55.145479887 [Client management]: Begin stop session "oc4iKoCkS4oPhaVB" (id 0) (in cmd_stop_trace() at cmd.cpp:2888)
DBG1 - 11:26:55.145501522 [Client management]: Sending response (size: 24, retcode: Tracing has already been stopped (81)) (in thread_manage_clients() at client.cpp:2652)
DBG1 - 11:26:55.145543071 [Client management]: Accepting client command ... (in thread_manage_clients() at client.cpp:2489)
DBG1 - 11:26:55.145773858 [Client management]: Wait for client response (in thread_manage_clients() at client.cpp:2534)
DBG1 - 11:26:55.145811717 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.cpp:2562)
DBG1 - 11:26:55.145839725 [Client management]: Processing client command 'DATA_PENDING' (20) (in process_client_msg() at client.cpp:1007)
DBG1 - 11:26:55.145859909 [Client management]: Getting session oc4iKoCkS4oPhaVB by name (in process_client_msg() at client.cpp:1122)
DBG2 - 11:26:55.145878923 [Client management]: Trying to find session by name oc4iKoCkS4oPhaVB (in session_find_by_name() at session.cpp:1114)
DBG1 - 11:26:55.145916911 [Client management]: Data pending for session oc4iKoCkS4oPhaVB (in cmd_data_pending() at cmd.cpp:4032)
DBG3 - 11:26:55.145938981 [Client management]: Consumer data pending for id 0 (in consumer_is_data_pending() at consumer.cpp:1266)
DBG1 - 11:26:55.148030189 [Client management]: Consumer data is NOT pending for session id 0 (in consumer_is_data_pending() at consumer.cpp:1302)
DBG1 - 11:26:55.148084321 [Client management]: Sending response (size: 25, retcode: Success (10)) (in thread_manage_clients() at client.cpp:2652)
DBG1 - 11:26:55.148133010 [Client management]: Accepting client command ... (in thread_manage_clients() at client.cpp:2489)
DBG1 - 11:26:55.148360089 [Client management]: Wait for client response (in thread_manage_clients() at client.cpp:2534)
DBG1 - 11:26:55.148398184 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.cpp:2562)
DBG1 - 11:26:55.148473532 [Client management]: Processing client command 'DESTROY_SESSION' (7) (in process_client_msg() at client.cpp:1007)
DBG1 - 11:26:55.148497167 [Client management]: Getting session oc4iKoCkS4oPhaVB by name (in process_client_msg() at client.cpp:1122)
DBG2 - 11:26:55.148533883 [Client management]: Trying to find session by name oc4iKoCkS4oPhaVB (in session_find_by_name() at session.cpp:1114)
DBG1 - 11:26:55.148556231 [Client management]: Begin destroy session oc4iKoCkS4oPhaVB (id 0) (in cmd_destroy_session() at cmd.cpp:3419)
DBG1 - 11:26:55.148581208 [Client management]: Consumer rotate channel key 1 (in consumer_rotate_channel() at consumer.cpp:1699)
DBG3 - 11:26:55.149457232 [Client management]: No metadata to push for metadata key 2 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG1 - 11:26:55.149495363 [Client management]: Consumer rotate channel key 2 (in consumer_rotate_channel() at consumer.cpp:1699)
DBG1 - 11:26:55.149841053 [Client management]: Setting trace chunk close command to "no operation" (in lttng_trace_chunk_set_close_command() at trace-chunk.cpp:1719)
DBG1 - 11:26:55.149864503 [Client management]: lttng_trace_chunk_rename_path from to (in lttng_trace_chunk_rename_path_no_lock() at trace-chunk.cpp:732)
DBG1 - 11:26:55.149886929 [Client management]: Sending consumer close trace chunk command: relayd_id = 2, session_id = 0, chunk_id = 0, close command = "none" (in consumer_close_trace_chunk() at consumer.cpp:2038)
DBG1 - 11:26:55.150735135 [Client management]: Enabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_start() at timer.cpp:211)
DBG1 - 11:26:55.150787279 [Client management]: Cmd rotate session oc4iKoCkS4oPhaVB, archive_id 0 sent (in cmd_rotate_session() at cmd.cpp:5627)
DBG1 - 11:26:55.150816492 [Client management]: Accepting client command ... (in thread_manage_clients() at client.cpp:2489)
DBG1 - 11:26:55.624597525 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:26:55.624654203 [Notification]: Handling fd (11) activity (1) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:26:55.624700912 [Notification]: Handling channel sample for channel chan (key = 1) in session oc4iKoCkS4oPhaVB (highest usage = 0, lowest usage = 0, consumed since last sample = 2552) (in handle_notification_thread_channel_sample() at notification-thread-events.cpp:4944)
DBG1 - 11:26:55.624742937 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG1 - 11:26:55.651245852 [Rotation]: Poll wait returned: ret=1 (in _run() at rotation-thread.cpp:734)
DBG1 - 11:26:55.651324051 [Rotation]: Handling descriptor activity: fd=9, events=1 (in _run() at rotation-thread.cpp:752)
DBG1 - 11:26:55.651348860 [Rotation]: Checking for pending rotation on session "oc4iKoCkS4oPhaVB", trace archive 0 (in check_session_rotation_pending() at rotation-thread.cpp:234)
DBG1 - 11:26:55.651378762 [Rotation]: Disabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_stop() at timer.cpp:242)
DBG1 - 11:26:55.651570097 [Rotation]: Sending consumer trace chunk exists command: relayd_id = 2, session_id = 0, chunk_id = 0 (in consumer_trace_chunk_exists() at consumer.cpp:2137)
DBG1 - 11:26:55.652394284 [Rotation]: Consumer ret code -128 (in consumer_recv_status_reply() at consumer.cpp:202)
DBG1 - 11:26:55.652448600 [Rotation]: Consumer reply to TRACE_CHUNK_EXISTS command: unknown trace chunk (in consumer_trace_chunk_exists() at consumer.cpp:2163)
DBG1 - 11:26:55.652482546 [Rotation]: Rotation of trace archive 0 of session "oc4iKoCkS4oPhaVB" is complete on all consumers (in check_session_rotation_pending_on_consumers() at rotation-thread.cpp:195)
DBG3 - 11:26:55.652523372 [Rotation]: No kernel session when tearing down session (in kernel_destroy_session() at kernel.cpp:1600)
DBG2 - 11:26:55.652553473 [Rotation]: Sending destroy relayd command to consumer sock 67 (in consumer_send_destroy_relayd() at consumer.cpp:260)
DBG2 - 11:26:55.652800362 [Rotation]: Consumer send destroy relayd command done (in consumer_send_destroy_relayd() at consumer.cpp:275)
DBG1 - 11:26:55.652864529 [Rotation]: Destroy all UST traces (in ust_app_destroy_trace_all() at ust-app.cpp:5907)
DBG1 - 11:26:55.652886193 [Rotation]: Destroy tracing for ust app pid 2152033 (in destroy_trace() at ust-app.cpp:5782)
DBG3 - 11:26:55.652941479 [Rotation]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:26:55.652975688 [Rotation]: No metadata to push for metadata key 2 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG3 - 11:26:55.652996117 [Rotation]: UST app deleting channel chan (in delete_ust_app_channel() at ust-app.cpp:575)
DBG1 - 11:26:55.654827168 [Rotation]: Destroy tracing for ust app pid 2152120 (in destroy_trace() at ust-app.cpp:5782)
DBG3 - 11:26:55.654885789 [Rotation]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:26:55.654920807 [Rotation]: No metadata to push for metadata key 2 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG3 - 11:26:55.654941498 [Rotation]: UST app deleting channel chan (in delete_ust_app_channel() at ust-app.cpp:575)
DBG2 - 11:26:55.656368228 [Rotation]: Trace UST destroy session 0 (in trace_ust_destroy_session() at trace-ust.cpp:1415)
DBG3 - 11:26:55.656441955 [Rotation]: Buffer registry per UID destroy with id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_destroy() at buffer-registry.cpp:664)
DBG2 - 11:26:55.656478409 [Rotation]: Consumer close metadata channel key 2 (in consumer_close_metadata() at consumer.cpp:1388)
DBG1 - 11:26:55.656860621 [Rotation]: Destroying session oc4iKoCkS4oPhaVB (id 0) (in session_release() at session.cpp:986)
DBG1 - 11:26:55.656928784 [Rotation]: Empty ltt_sessions_ht_by_id/name, destroying hast tables (in del_session_ht() at session.cpp:441)
DBG1 - 11:26:55.656985743 [Rotation]: Beginning of waiter "wait" period (in wait() at waiter.cpp:48)
DBG1 - 11:26:55.657070730 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:26:55.657128719 [Notification]: Handling fd (23) activity (1) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:26:55.657174769 [Notification]: Received `REMOVE_SESSION` command (in handle_notification_thread_command() at notification-thread-events.cpp:3191)
DBG1 - 11:26:55.657204828 [Notification]: Removing session: session id = 0 (in handle_notification_thread_command_remove_session() at notification-thread-events.cpp:1824)
DBG1 - 11:26:55.657245591 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG1 - 11:26:55.657266250 [Rotation]: End of waiter "wait" period (in wait() at waiter.cpp:109)
DBG1 - 11:26:55.657293354 [Rotation]: No implicit rotation performed during the destruction of session "oc4iKoCkS4oPhaVB", sending reply (in cmd_destroy_session_reply() at cmd.cpp:3352)
DBG1 - 11:26:55.657404764 [Rotation]: Entering poll wait (in _run() at rotation-thread.cpp:732)
DBG2 - 11:26:55.663642856 [2152012/2152074]: Trace destroy UST event tp:tptest (in trace_ust_destroy_event() at trace-ust.cpp:1235)
DBG2 - 11:26:55.663758970 [2152012/2152074]: Trace destroy UST channel chan (in _trace_ust_destroy_channel() at trace-ust.cpp:1300)
DBG3 - 11:26:55.663789895 [2152012/2152074]: Buffer registry session destroy (in buffer_reg_session_destroy() at buffer-registry.cpp:590)
DBG3 - 11:26:55.663820718 [2152012/2152074]: Buffer registry channel destroy with key 0 (in buffer_reg_channel_destroy() at buffer-registry.cpp:546)
DBG3 - 11:26:55.663848825 [2152012/2152074]: Buffer registry stream destroy with handle -1 (in buffer_reg_stream_destroy() at buffer-registry.cpp:495)
DBG3 - 11:26:55.663885971 [2152012/2152074]: Buffer registry stream destroy with handle -1 (in buffer_reg_stream_destroy() at buffer-registry.cpp:495)
DBG3 - 11:26:55.663918855 [2152012/2152074]: Buffer registry stream destroy with handle -1 (in buffer_reg_stream_destroy() at buffer-registry.cpp:495)
DBG3 - 11:26:55.663951583 [2152012/2152074]: Buffer registry stream destroy with handle -1 (in buffer_reg_stream_destroy() at buffer-registry.cpp:495)
DBG1 - 11:26:55.664037105 [2152012/2152074]: Beginning of waiter "wait" period (in wait() at waiter.cpp:48)
DBG1 - 11:26:55.664057260 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:26:55.664138377 [Notification]: Handling fd (23) activity (1) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:26:55.664178393 [Notification]: Received `REMOVE_CHANNEL` command (in handle_notification_thread_command() at notification-thread-events.cpp:3191)
DBG1 - 11:26:55.664207451 [Notification]: Removing channel key = 1 in ust domain (in handle_notification_thread_command_remove_channel() at notification-thread-events.cpp:1866)
DBG1 - 11:26:55.664267711 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG1 - 11:26:55.664286406 [2152012/2152074]: End of waiter "wait" period (in wait() at waiter.cpp:109)
DBG1 - 11:26:55.671241045 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:26:55.671335862 [Notification]: Handling fd (80) activity (16) (in thread_notification() at notification-thread.cpp:668)
DBG3 - 11:26:55.671374056 [Notification]: Removing tracer event source from poll set: tracer_event_source_fd = 80, domain = 'ust' (in remove_tracer_event_source_from_pollset() at notification-thread-events.cpp:2170)
DBG1 - 11:26:55.671451743 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG1 - 11:26:55.672104874 [UST application management]: Apps thread return from poll on 4 fds (in thread_application_management() at manage-apps.cpp:96)
DBG3 - 11:26:55.672142348 [Application notification]: [ust-thread] Manage notify return from poll on 4 fds (in thread_application_notification() at notify-apps.cpp:81)
DBG1 - 11:26:55.672203790 [UST application management]: Application unregistering after socket activity: pid=2152120, socket_fd=62 (in ust_app_unregister_by_socket() at ust-app.cpp:4452)
DBG1 - 11:26:55.672318772 [UST application management]: Apps thread polling (in thread_application_management() at manage-apps.cpp:90)
DBG3 - 11:26:55.672268162 [Application notification]: UST app receiving notify from sock 79 (in ust_app_recv_notify() at ust-app.cpp:6900)
DBG3 - 11:26:55.672414280 [Application notification]: UST app recv notify failed. Application died: sock = 79 (in ust_app_recv_notify() at ust-app.cpp:6905)
DBG1 - 11:26:55.672461924 [Application notification]: UST app notify socket unregister 79 (in ust_app_notify_sock_unregister() at ust-app.cpp:7103)
DBG2 - 11:26:55.672495636 [Application notification]: UST app find by notify sock 79 not found (in find_app_by_notify_sock() at ust-app.cpp:1483)
DBG3 - 11:26:55.672526252 [Application notification]: [ust-thread] Manage notify polling (in thread_application_notification() at notify-apps.cpp:75)
DBG3 - 11:26:55.674512750 [2152012/2152074]: Call RCU deleting app PID 2152120 (in delete_ust_app_rcu() at ust-app.cpp:1129)
DBG1 - 11:26:55.674597659 [2152012/2152074]: Beginning of waiter "wait" period (in wait() at waiter.cpp:48)
DBG1 - 11:26:55.674677185 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:26:55.674726547 [Notification]: Handling fd (23) activity (1) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:26:55.674766457 [Notification]: Received `REMOVE_TRACER_EVENT_SOURCE` command (in handle_notification_thread_command() at notification-thread-events.cpp:3191)
DBG1 - 11:26:55.674802799 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG1 - 11:26:55.674802942 [2152012/2152074]: End of waiter "wait" period (in wait() at waiter.cpp:109)
DBG2 - 11:26:55.674952668 [2152012/2152074]: UST app pid 2152120 deleted (in delete_ust_app() at ust-app.cpp:1115)
DBG1 - 11:26:55.745405021 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:26:55.745528009 [Notification]: Handling fd (53) activity (16) (in thread_notification() at notification-thread.cpp:668)
DBG3 - 11:26:55.745546254 [Notification]: Removing tracer event source from poll set: tracer_event_source_fd = 53, domain = 'ust' (in remove_tracer_event_source_from_pollset() at notification-thread-events.cpp:2170)
DBG1 - 11:26:55.745604430 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG3 - 11:26:55.745805034 [Application notification]: [ust-thread] Manage notify return from poll on 3 fds (in thread_application_notification() at notify-apps.cpp:81)
DBG1 - 11:26:55.745834151 [UST application management]: Apps thread return from poll on 3 fds (in thread_application_management() at manage-apps.cpp:96)
DBG3 - 11:26:55.745838795 [Application notification]: UST app receiving notify from sock 52 (in ust_app_recv_notify() at ust-app.cpp:6900)
DBG1 - 11:26:55.745882679 [UST application management]: Application unregistering after socket activity: pid=2152033, socket_fd=51 (in ust_app_unregister_by_socket() at ust-app.cpp:4452)
DBG3 - 11:26:55.745914317 [Application notification]: UST app recv notify failed. Application died: sock = 52 (in ust_app_recv_notify() at ust-app.cpp:6905)
DBG1 - 11:26:55.745942597 [UST application management]: Apps thread polling (in thread_application_management() at manage-apps.cpp:90)
DBG1 - 11:26:55.745958413 [Application notification]: UST app notify socket unregister 52 (in ust_app_notify_sock_unregister() at ust-app.cpp:7103)
DBG2 - 11:26:55.745991165 [Application notification]: UST app find by notify sock 52 not found (in find_app_by_notify_sock() at ust-app.cpp:1483)
DBG3 - 11:26:55.746007052 [Application notification]: [ust-thread] Manage notify polling (in thread_application_notification() at notify-apps.cpp:75)
DBG3 - 11:26:55.756106404 [2152012/2152074]: Call RCU deleting app PID 2152033 (in delete_ust_app_rcu() at ust-app.cpp:1129)
DBG1 - 11:26:55.756163523 [2152012/2152074]: Beginning of waiter "wait" period (in wait() at waiter.cpp:48)
DBG1 - 11:26:55.756229065 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:26:55.756255446 [Notification]: Handling fd (23) activity (1) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:26:55.756275088 [Notification]: Received `REMOVE_TRACER_EVENT_SOURCE` command (in handle_notification_thread_command() at notification-thread-events.cpp:3191)
DBG1 - 11:26:55.756294401 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG1 - 11:26:55.756311006 [2152012/2152074]: End of waiter "wait" period (in wait() at waiter.cpp:109)
DBG2 - 11:26:55.756377186 [2152012/2152074]: UST app pid 2152033 deleted (in delete_ust_app() at ust-app.cpp:1115)
DBG1 - 11:26:55.769624938 [UST application registration]: UST registration received with pid:2152177 ppid:2151972 uid:1000 gid:1000 sock:51 name:gen-ust-events (version 10.0) (in thread_application_registration() at register.cpp:311)
DBG1 - 11:26:55.769702133 [UST application registration]: Futex n to 1 wake done (in futex_nto1_wake() at futex.cpp:116)
DBG1 - 11:26:55.769716590 [UST application registration]: Accepting application registration (in thread_application_registration() at register.cpp:206)
DBG1 - 11:26:55.769753915 [UST application registration]: UST registration received with pid:2152177 ppid:2151972 uid:1000 gid:1000 sock:52 name:gen-ust-events (version 10.0) (in thread_application_registration() at register.cpp:311)
DBG1 - 11:26:55.769770646 [UST application registration]: Futex n to 1 wake done (in futex_nto1_wake() at futex.cpp:116)
DBG1 - 11:26:55.769779090 [UST application registration]: Accepting application registration (in thread_application_registration() at register.cpp:206)
DBG1 - 11:26:55.769703854 [UST registration dispatch]: Futex n to 1 wait done (in futex_nto1_wait() at futex.cpp:100)
DBG1 - 11:26:55.770791590 [UST registration dispatch]: Futex n to 1 prepare done (in futex_nto1_prepare() at futex.cpp:64)
DBG1 - 11:26:55.770805084 [UST registration dispatch]: Dispatching UST registration pid:2152177 ppid:2151972 uid:1000 gid:1000 sock:51 name:gen-ust-events (version 10.0) (in thread_dispatch_ust_registration() at dispatch.cpp:281)
DBG3 - 11:26:55.770836608 [UST registration dispatch]: UST app creating application for socket 51 (in ust_app_create() at ust-app.cpp:4035)
DBG3 - 11:26:55.770871714 [UST registration dispatch]: Created hashtable size 4 at 0x7f22200099d0 of type U64 (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:55.770888801 [UST registration dispatch]: Created hashtable size 4 at 0x7f2220008c80 of type ULONG (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:55.770903012 [UST registration dispatch]: Created hashtable size 4 at 0x7f2220003ba0 of type ULONG (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:55.770916905 [UST registration dispatch]: Created hashtable size 4 at 0x7f22200046c0 of type U64 (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG1 - 11:26:55.770949387 [UST registration dispatch]: Dispatching UST registration pid:2152177 ppid:2151972 uid:1000 gid:1000 sock:52 name:gen-ust-events (version 10.0) (in thread_dispatch_ust_registration() at dispatch.cpp:281)
DBG3 - 11:26:55.770965765 [UST registration dispatch]: UST app notify socket 52 is set (in thread_dispatch_ust_registration() at dispatch.cpp:351)
DBG1 - 11:26:55.770983669 [UST registration dispatch]: App registered with pid:2152177 ppid:2151972 uid:1000 gid:1000 sock =51 name:gen-ust-events notify_sock =52 (version 10.0) (in ust_app_add() at ust-app.cpp:4158)
DBG1 - 11:26:55.771265143 [UST registration dispatch]: Beginning of waiter "wait" period (in wait() at waiter.cpp:48)
DBG1 - 11:26:55.771314696 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:26:55.771340613 [Notification]: Handling fd (23) activity (1) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:26:55.771360358 [Notification]: Received `ADD_TRACER_EVENT_SOURCE` command (in handle_notification_thread_command() at notification-thread-events.cpp:3191)
DBG3 - 11:26:55.771376250 [Notification]: Adding tracer event source fd to poll set: tracer_event_source_fd = 53, domain = 'ust' (in handle_notification_thread_command_add_tracer_event_source() at notification-thread-events.cpp:2071)
DBG1 - 11:26:55.771402019 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG1 - 11:26:55.771408360 [UST registration dispatch]: End of waiter "wait" period (in wait() at waiter.cpp:109)
DBG2 - 11:26:55.772231313 [UST registration dispatch]: UST application global event notifier rules update: app = 'gen-ust-events', pid = 2152177 (in ust_app_global_update_event_notifier_rules() at ust-app.cpp:6291)
DBG3 - 11:26:55.772236126 [Application notification]: [ust-thread] Manage notify return from poll on 2 fds (in thread_application_notification() at notify-apps.cpp:81)
DBG1 - 11:26:55.772286376 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:26:55.772297655 [Notification]: Handling fd (23) activity (1) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:26:55.772317072 [Notification]: Received `LIST_TRIGGERS` command (in handle_notification_thread_command() at notification-thread-events.cpp:3191)
DBG3 - 11:26:55.772305165 [Application notification]: UST thread notify added sock 52 to pollset (in thread_application_notification() at notify-apps.cpp:140)
DBG3 - 11:26:55.772355612 [Application notification]: [ust-thread] Manage notify polling (in thread_application_notification() at notify-apps.cpp:75)
DBG1 - 11:26:55.772273600 [UST registration dispatch]: Beginning of waiter "wait" period (in wait() at waiter.cpp:48)
DBG1 - 11:26:55.772386078 [UST registration dispatch]: End of waiter "wait" period (in wait() at waiter.cpp:109)
DBG1 - 11:26:55.772339197 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG1 - 11:26:55.772463472 [UST registration dispatch]: Woken up but nothing in the UST command queue (in thread_dispatch_ust_registration() at dispatch.cpp:274)
DBG1 - 11:26:55.772491438 [UST application management]: Apps thread return from poll on 2 fds (in thread_application_management() at manage-apps.cpp:96)
DBG1 - 11:26:55.772528128 [UST application management]: Apps with sock 51 added to poll set (in thread_application_management() at manage-apps.cpp:149)
DBG1 - 11:26:55.772543262 [UST application management]: Apps thread polling (in thread_application_management() at manage-apps.cpp:90)
DBG1 - 11:26:55.786830954 [Client management]: Wait for client response (in thread_manage_clients() at client.cpp:2534)
DBG1 - 11:26:55.786896593 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.cpp:2562)
DBG1 - 11:26:55.786913466 [Client management]: Incomplete recv() from client... continuing (in thread_manage_clients() at client.cpp:2566)
DBG1 - 11:26:55.786940125 [Client management]: Accepting client command ... (in thread_manage_clients() at client.cpp:2489)
DBG1 - 11:26:55.787218281 [Client management]: Wait for client response (in thread_manage_clients() at client.cpp:2534)
DBG1 - 11:26:55.787258563 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.cpp:2562)
DBG1 - 11:26:55.787285240 [Client management]: Processing client command 'CREATE_SESSION_EXT' (40) (in process_client_msg() at client.cpp:1007)
DBG2 - 11:26:55.787342289 [Client management]: Trying to find session by name drHn2XSuuqUB7ASL (in session_find_by_name() at session.cpp:1114)
DBG3 - 11:26:55.787382511 [Client management]: Created hashtable size 4 at 0x7f2238027390 of type ULONG (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:55.787402590 [Client management]: Created hashtable size 4 at 0x7f2238003900 of type ULONG (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG1 - 11:26:55.787416567 [Client management]: Allocating ltt_sessions_ht_by_id (in ltt_sessions_ht_alloc() at session.cpp:307)
DBG3 - 11:26:55.787426508 [Client management]: Created hashtable size 4 at 0x7f2238027920 of type U64 (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG1 - 11:26:55.787439982 [Client management]: Allocating ltt_sessions_ht_by_name (in ltt_sessions_ht_alloc() at session.cpp:315)
DBG3 - 11:26:55.787454393 [Client management]: Created hashtable size 4 at 0x7f223800af90 of type STRING (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG1 - 11:26:55.787469893 [Client management]: Tracing session drHn2XSuuqUB7ASL created with ID 1 by uid = 1000, gid = 1000 (in session_create() at session.cpp:1319)
DBG1 - 11:26:55.787490674 [Client management]: Beginning of waiter "wait" period (in wait() at waiter.cpp:48)
DBG1 - 11:26:55.787548739 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:26:55.787576051 [Notification]: Handling fd (23) activity (1) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:26:55.787596024 [Notification]: Received `ADD_SESSION` command (in handle_notification_thread_command() at notification-thread-events.cpp:3191)
DBG1 - 11:26:55.787610862 [Notification]: Adding session: session name = `drHn2XSuuqUB7ASL`, session id = 1, session uid = 1000, session gid = 1000 (in handle_notification_thread_command_add_session() at notification-thread-events.cpp:1784)
DBG1 - 11:26:55.787628501 [Notification]: Found 0 triggers that apply to newly created session (in lttng_session_trigger_list_build() at notification-thread-events.cpp:1633)
DBG1 - 11:26:55.787650733 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG1 - 11:26:55.787702981 [Client management]: End of waiter "wait" period (in wait() at waiter.cpp:109)
DBG2 - 11:26:55.787729321 [Client management]: Setting network URI to consumer (in add_uri_to_consumer() at cmd.cpp:692)
DBG3 - 11:26:55.787741081 [Client management]: Consumer control URI set with port 5342 (in consumer_set_network_uri() at consumer.cpp:701)
DBG3 - 11:26:55.787771688 [Client management]: Consumer set network uri base_dir path /laptop-kstewart/drHn2XSuuqUB7ASL-20231213-112655/ (in consumer_set_network_uri() at consumer.cpp:816)
DBG2 - 11:26:55.787786507 [Client management]: Setting network URI to consumer (in add_uri_to_consumer() at cmd.cpp:692)
DBG3 - 11:26:55.787812108 [Client management]: Consumer data URI set with port 5343 (in consumer_set_network_uri() at consumer.cpp:716)
DBG1 - 11:26:55.787847228 [Client management]: Sending response (size: 16476, retcode: Success (10)) (in thread_manage_clients() at client.cpp:2652)
DBG1 - 11:26:55.787884021 [Client management]: Accepting client command ... (in thread_manage_clients() at client.cpp:2489)
DBG1 - 11:26:55.788156131 [Client management]: Wait for client response (in thread_manage_clients() at client.cpp:2534)
DBG1 - 11:26:55.788195229 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.cpp:2562)
DBG1 - 11:26:55.788220582 [Client management]: Processing client command 'LIST_SESSIONS' (11) (in process_client_msg() at client.cpp:1007)
DBG1 - 11:26:55.788237739 [Client management]: Counting number of available session for UID 1000 (in lttng_sessions_count() at client.cpp:597)
DBG1 - 11:26:55.788253791 [Client management]: Getting all available session for UID 1000 GID 1000 (in cmd_list_lttng_sessions() at cmd.cpp:3971)
DBG1 - 11:26:55.788273753 [Client management]: Sending response (size: 4409, retcode: Success (10)) (in thread_manage_clients() at client.cpp:2652)
DBG1 - 11:26:55.788305519 [Client management]: Accepting client command ... (in thread_manage_clients() at client.cpp:2489)
DBG1 - 11:26:55.813868102 [Client management]: Wait for client response (in thread_manage_clients() at client.cpp:2534)
DBG1 - 11:26:55.813937901 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.cpp:2562)
DBG1 - 11:26:55.813966485 [Client management]: Processing client command 'ENABLE_CHANNEL' (5) (in process_client_msg() at client.cpp:1007)
DBG1 - 11:26:55.813983834 [Client management]: Getting session drHn2XSuuqUB7ASL by name (in process_client_msg() at client.cpp:1122)
DBG2 - 11:26:55.813998593 [Client management]: Trying to find session by name drHn2XSuuqUB7ASL (in session_find_by_name() at session.cpp:1114)
DBG1 - 11:26:55.814013188 [Client management]: Creating UST session (in create_ust_session() at client.cpp:514)
DBG3 - 11:26:55.814030676 [Client management]: Created hashtable size 4 at 0x7f2238024360 of type STRING (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:55.814047334 [Client management]: Created hashtable size 4 at 0x7f22380248f0 of type U64 (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:55.814076766 [Client management]: Created hashtable size 4 at 0x7f2238025430 of type ULONG (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG2 - 11:26:55.814107324 [Client management]: UST trace session create successful (in trace_ust_create_session() at trace-ust.cpp:329)
DBG3 - 11:26:55.814121090 [Client management]: Copying tracing session consumer output in UST session (in copy_session_consumer() at client.cpp:463)
DBG3 - 11:26:55.814147494 [Client management]: Created hashtable size 4 at 0x7f2238025970 of type ULONG (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:55.814165146 [Client management]: Copy session consumer subdir ust (in copy_session_consumer() at client.cpp:483)
DBG3 - 11:26:55.814176809 [Client management]: Consumer socket created (fd: 67) and added to output (in consumer_create_socket() at consumer.cpp:347)
DBG1 - 11:26:55.814191298 [Client management]: Setting relayd for session drHn2XSuuqUB7ASL (in cmd_setup_relayd() at cmd.cpp:1029)
DBG3 - 11:26:55.814224630 [Client management]: Relayd connect ... (in relayd_connect() at relayd/relayd.cpp:783)
DBG3 - 11:26:55.814304666 [Client management]: Creating relayd stream socket from URI (in create_connect_relayd() at cmd.cpp:812)
DBG1 - 11:26:55.814324304 [Client management]: Relayd version check for major.minor 2.14 (in relayd_version_check() at relayd/relayd.cpp:679)
DBG3 - 11:26:55.814339054 [Client management]: Relayd sending command RELAYD_VERSION of size 32 (in send_command() at relayd/relayd.cpp:89)
DBG3 - 11:26:55.814373530 [Client management]: Relayd waiting for reply of size 8 (in recv_reply() at relayd/relayd.cpp:119)
DBG2 - 11:26:55.814785566 [Client management]: Relayd version is compatible, using protocol version 2.14 (in relayd_version_check() at relayd/relayd.cpp:727)
DBG3 - 11:26:55.814821267 [Client management]: Relayd sending command RELAYD_GET_CONFIGURATION of size 32 (in send_command() at relayd/relayd.cpp:89)
DBG3 - 11:26:55.814859349 [Client management]: Relayd waiting for reply of size 12 (in recv_reply() at relayd/relayd.cpp:119)
DBG1 - 11:26:55.815055851 [Client management]: Relayd successfully got configuration: query_flags = 0, results_flags = 1 (in relayd_get_configuration() at relayd/relayd.cpp:1594)
DBG1 - 11:26:55.815106694 [Client management]: Relayd create session (in relayd_create_session() at relayd/relayd.cpp:345)
DBG3 - 11:26:55.815118670 [Client management]: Relayd sending command RELAYD_CREATE_SESSION of size 117 (in send_command() at relayd/relayd.cpp:89)
DBG3 - 11:26:55.815155497 [Client management]: Relayd waiting for reply of size 16 (in recv_reply() at relayd/relayd.cpp:119)
DBG3 - 11:26:55.815577814 [Client management]: Relayd waiting for reply of size 49 (in recv_reply() at relayd/relayd.cpp:119)
DBG1 - 11:26:55.815608290 [Client management]: Relayd session created with id 2 (in relayd_create_session() at relayd/relayd.cpp:385)
DBG1 - 11:26:55.815624710 [Client management]: Created session on relay, output path reply: laptop-kstewart/drHn2XSuuqUB7ASL-20231213-112655 (in consumer_send_relayd_socket() at consumer.cpp:1170)
DBG3 - 11:26:55.815638592 [Client management]: Sending relayd sock info to consumer on 67 (in consumer_send_relayd_socket() at consumer.cpp:1186)
DBG3 - 11:26:55.815776874 [Client management]: Sending relayd socket file descriptor to consumer (in consumer_send_relayd_socket() at consumer.cpp:1192)
DBG2 - 11:26:55.815927282 [Client management]: Consumer relayd socket sent (in consumer_send_relayd_socket() at consumer.cpp:1199)
DBG3 - 11:26:55.815957913 [Client management]: Relayd closing socket 69 (in relayd_close() at relayd/relayd.cpp:814)
DBG3 - 11:26:55.815987794 [Client management]: Relayd connect ... (in relayd_connect() at relayd/relayd.cpp:783)
DBG3 - 11:26:55.816050749 [Client management]: Creating relayd data socket from URI (in create_connect_relayd() at cmd.cpp:836)
DBG3 - 11:26:55.816066392 [Client management]: Sending relayd sock info to consumer on 67 (in consumer_send_relayd_socket() at consumer.cpp:1186)
DBG3 - 11:26:55.816161784 [Client management]: Sending relayd socket file descriptor to consumer (in consumer_send_relayd_socket() at consumer.cpp:1192)
DBG2 - 11:26:55.816276974 [Client management]: Consumer relayd socket sent (in consumer_send_relayd_socket() at consumer.cpp:1199)
DBG3 - 11:26:55.816294636 [Client management]: Relayd closing socket 69 (in relayd_close() at relayd/relayd.cpp:814)
DBG1 - 11:26:55.816316897 [Client management]: Enabling channel chan for session drHn2XSuuqUB7ASL (in cmd_enable_channel_internal() at cmd.cpp:1359)
DBG2 - 11:26:55.816333565 [Client management]: Trace UST channel chan not found by name (in trace_ust_find_channel_by_name() at trace-ust.cpp:187)
DBG3 - 11:26:55.816350531 [Client management]: Created hashtable size 4 at 0x7f2238021980 of type STRING (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:55.816366058 [Client management]: Created hashtable size 4 at 0x7f2238015680 of type ULONG (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG2 - 11:26:55.816379340 [Client management]: Trace UST channel chan created (in trace_ust_create_channel() at trace-ust.cpp:407)
DBG2 - 11:26:55.816392549 [Client management]: Channel chan is being created for UST with buffer 0 and id 0 (in channel_ust_create() at channel.cpp:437)
DBG2 - 11:26:55.816407068 [Client management]: Channel chan created successfully (in channel_ust_create() at channel.cpp:465)
DBG1 - 11:26:55.816418770 [Client management]: Sending response (size: 24, retcode: Success (10)) (in thread_manage_clients() at client.cpp:2652)
DBG1 - 11:26:55.816447684 [Client management]: Accepting client command ... (in thread_manage_clients() at client.cpp:2489)
DBG1 - 11:26:55.836258241 [Client management]: Wait for client response (in thread_manage_clients() at client.cpp:2534)
DBG1 - 11:26:55.836302307 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.cpp:2562)
DBG1 - 11:26:55.836322683 [Client management]: Processing client command 'ENABLE_EVENT' (6) (in process_client_msg() at client.cpp:1007)
DBG1 - 11:26:55.836336599 [Client management]: Getting session drHn2XSuuqUB7ASL by name (in process_client_msg() at client.cpp:1122)
DBG2 - 11:26:55.836348419 [Client management]: Trying to find session by name drHn2XSuuqUB7ASL (in session_find_by_name() at session.cpp:1114)
DBG3 - 11:26:55.836363295 [Client management]: Consumer socket created (fd: 67) and added to output (in consumer_create_socket() at consumer.cpp:347)
DBG1 - 11:26:55.836374966 [Client management]: Setting relayd for session drHn2XSuuqUB7ASL (in cmd_setup_relayd() at cmd.cpp:1029)
DBG2 - 11:26:55.836397739 [Client management]: Trace UST channel chan found by name (in trace_ust_find_channel_by_name() at trace-ust.cpp:182)
DBG2 - 11:26:55.836411050 [Client management]: Trace UST event tp:tptest NOT found (in trace_ust_find_event() at trace-ust.cpp:231)
DBG2 - 11:26:55.836422608 [Client management]: Trace UST event tp:tptest, loglevel (0,-1) created (in trace_ust_create_event() at trace-ust.cpp:526)
DBG1 - 11:26:55.836437250 [Client management]: Sending response (size: 24, retcode: Success (10)) (in thread_manage_clients() at client.cpp:2652)
DBG1 - 11:26:55.836461323 [Client management]: Accepting client command ... (in thread_manage_clients() at client.cpp:2489)
DBG1 - 11:26:55.855909296 [Client management]: Wait for client response (in thread_manage_clients() at client.cpp:2534)
DBG1 - 11:26:55.855960900 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.cpp:2562)
DBG1 - 11:26:55.855976997 [Client management]: Processing client command 'LIST_SESSIONS' (11) (in process_client_msg() at client.cpp:1007)
DBG1 - 11:26:55.855988341 [Client management]: Counting number of available session for UID 1000 (in lttng_sessions_count() at client.cpp:597)
DBG1 - 11:26:55.856000106 [Client management]: Getting all available session for UID 1000 GID 1000 (in cmd_list_lttng_sessions() at cmd.cpp:3971)
DBG1 - 11:26:55.856015876 [Client management]: Sending response (size: 4409, retcode: Success (10)) (in thread_manage_clients() at client.cpp:2652)
DBG1 - 11:26:55.856036057 [Client management]: Accepting client command ... (in thread_manage_clients() at client.cpp:2489)
DBG1 - 11:26:55.856180789 [Client management]: Wait for client response (in thread_manage_clients() at client.cpp:2534)
DBG1 - 11:26:55.856203632 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.cpp:2562)
DBG1 - 11:26:55.856217918 [Client management]: Processing client command 'START_TRACE' (14) (in process_client_msg() at client.cpp:1007)
DBG1 - 11:26:55.856227723 [Client management]: Getting session drHn2XSuuqUB7ASL by name (in process_client_msg() at client.cpp:1122)
DBG2 - 11:26:55.856235832 [Client management]: Trying to find session by name drHn2XSuuqUB7ASL (in session_find_by_name() at session.cpp:1114)
DBG1 - 11:26:55.856245278 [Client management]: Creating initial trace chunk of session "drHn2XSuuqUB7ASL" (in cmd_start_trace() at cmd.cpp:2779)
DBG1 - 11:26:55.856255052 [Client management]: Creating trace chunk: chunk_id = 0, creation time = 20231213-112655 (in lttng_trace_chunk_create() at trace-chunk.cpp:419)
DBG1 - 11:26:55.856264678 [Client management]: Chunk name set to "(none)" (in lttng_trace_chunk_create() at trace-chunk.cpp:450)
DBG1 - 11:26:55.856276080 [Client management]: Sending consumer create trace chunk command: relayd_id = 3, session_id = 1, chunk_id = 0, creation_timestamp = 20231213T112655-0500 (in consumer_create_trace_chunk() at consumer.cpp:1939)
DBG1 - 11:26:55.856563445 [Client management]: Starting all UST traces (in ust_app_start_trace_all() at ust-app.cpp:5836)
DBG1 - 11:26:55.856577808 [Client management]: Clearing stream quiescent state for all ust apps (in ust_app_clear_quiescent_session() at ust-app.cpp:5702)
DBG2 - 11:26:55.856588578 [Client management]: UST app global update for app sock 51 for session id 1 (in ust_app_global_update() at ust-app.cpp:6262)
DBG2 - 11:26:55.856597451 [Client management]: UST app pid: 2152177 session id 1 not found, creating it (in find_or_create_ust_app_session() at ust-app.cpp:2722)
DBG3 - 11:26:55.856622834 [Client management]: Created hashtable size 4 at 0x7f2238015eb0 of type STRING (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG2 - 11:26:55.856641454 [Client management]: Shadow copy of session handle -1 (in shadow_copy_session() at ust-app.cpp:2433)
DBG3 - 11:26:55.856648784 [Client management]: Buffer registry per PID find id: 3 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG3 - 11:26:55.856662055 [Client management]: Created hashtable size 4 at 0x7f2238016420 of type U64 (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:55.856670121 [Client management]: Buffer registry per PID created with session id: 3 (in buffer_reg_pid_create() at buffer-registry.cpp:280)
DBG3 - 11:26:55.856713110 [Client management]: Created hashtable size 4 at 0x7f2238015100 of type STRING (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:55.856724340 [Client management]: Created hashtable size 4 at 0x7f223802c900 of type U64 (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:55.856753729 [Client management]: Session 1 found by id. (in session_find_by_id() at session.cpp:1152)
DBG3 - 11:26:55.856769562 [Client management]: Buffer registry per PID adding to global registry with id: 3 (in buffer_reg_pid_add() at buffer-registry.cpp:298)
DBG3 - 11:26:55.856778287 [Client management]: UST app buffer registry per PID created successfully (in setup_buffer_reg_pid() at ust-app.cpp:2610)
DBG2 - 11:26:55.856881803 [Client management]: UST app session created successfully with handle 3 (in find_or_create_ust_app_session() at ust-app.cpp:2800)
DBG3 - 11:26:55.856894325 [Client management]: Created hashtable size 4 at 0x7f223802d610 of type ULONG (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:55.856902951 [Client management]: Created hashtable size 4 at 0x7f223802b910 of type STRING (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:55.856910567 [Client management]: UST app channel chan allocated (in alloc_ust_app_channel() at ust-app.cpp:1231)
DBG2 - 11:26:55.856915679 [Client management]: UST app shadow copy of channel chan started (in shadow_copy_channel() at ust-app.cpp:2389)
DBG3 - 11:26:55.856923412 [Client management]: UST app shadow copy of channel chan done (in shadow_copy_channel() at ust-app.cpp:2415)
DBG1 - 11:26:55.856931191 [Client management]: UST app creating channel chan with per PID buffers (in create_channel_per_pid() at ust-app.cpp:3578)
DBG3 - 11:26:55.856938981 [Client management]: Buffer registry per PID find id: 3 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG3 - 11:26:55.856947967 [Client management]: Created hashtable size 4 at 0x7f223802bea0 of type STRING (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:55.856964348 [Client management]: Session 1 found by id. (in session_find_by_id() at session.cpp:1152)
DBG2 - 11:26:55.856971138 [Client management]: Asking UST consumer for channel (in ask_channel_creation() at ust-consumer.cpp:58)
DBG3 - 11:26:55.856980239 [Client management]: Consumer trace path relative to current trace chunk: "ust/pid/gen-ust-events-2152177-20231213-112655" (in setup_channel_trace_path() at consumer.cpp:75)
DBG2 - 11:26:55.857408358 [Client management]: UST ask channel 4 successfully done with 4 stream(s) (in ask_channel_creation() at ust-consumer.cpp:178)
DBG2 - 11:26:55.858437886 [Client management]: UST app stream 1 received successfully (in ust_consumer_get_channel() at ust-consumer.cpp:301)
DBG2 - 11:26:55.858476231 [Client management]: UST app stream 2 received successfully (in ust_consumer_get_channel() at ust-consumer.cpp:301)
DBG2 - 11:26:55.858503138 [Client management]: UST app stream 3 received successfully (in ust_consumer_get_channel() at ust-consumer.cpp:301)
DBG2 - 11:26:55.858523515 [Client management]: UST app stream 4 received successfully (in ust_consumer_get_channel() at ust-consumer.cpp:301)
DBG3 - 11:26:55.858539811 [Client management]: UST app consumer has no more stream available (in ust_consumer_get_channel() at ust-consumer.cpp:284)
DBG1 - 11:26:55.858551867 [Client management]: UST app sending channel chan to UST app sock 51 (in send_channel_pid_to_ust() at ust-app.cpp:1980)
DBG2 - 11:26:55.858560285 [Client management]: UST app send channel to sock 51 pid 2152177 (name: chan, key: 0) (in ust_consumer_send_channel_to_ust() at ust-consumer.cpp:416)
DBG2 - 11:26:55.858656080 [Client management]: UST consumer send stream to app 51 (in ust_consumer_send_stream_to_ust() at ust-consumer.cpp:370)
DBG2 - 11:26:55.858761570 [Client management]: UST consumer send stream to app 51 (in ust_consumer_send_stream_to_ust() at ust-consumer.cpp:370)
DBG2 - 11:26:55.858840739 [Client management]: UST consumer send stream to app 51 (in ust_consumer_send_stream_to_ust() at ust-consumer.cpp:370)
DBG2 - 11:26:55.858914506 [Client management]: UST consumer send stream to app 51 (in ust_consumer_send_stream_to_ust() at ust-consumer.cpp:370)
DBG1 - 11:26:55.858999813 [Client management]: Beginning of waiter "wait" period (in wait() at waiter.cpp:48)
DBG1 - 11:26:55.859042474 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:26:55.859058251 [Notification]: Handling fd (23) activity (1) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:26:55.859069949 [Notification]: Received `ADD_CHANNEL` command (in handle_notification_thread_command() at notification-thread-events.cpp:3191)
DBG1 - 11:26:55.859078667 [Notification]: Adding channel: channel name = `chan`, session id = 1, channel key = 4, domain = ust (in handle_notification_thread_command_add_channel() at notification-thread-events.cpp:1704)
DBG1 - 11:26:55.859089819 [Notification]: Found 0 triggers that apply to newly added channel (in handle_notification_thread_command_add_channel() at notification-thread-events.cpp:1745)
DBG1 - 11:26:55.859101206 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG1 - 11:26:55.859104620 [Client management]: End of waiter "wait" period (in wait() at waiter.cpp:109)
DBG3 - 11:26:55.859114686 [Client management]: UST app event tp:tptest allocated (in alloc_ust_app_event() at ust-app.cpp:1285)
DBG2 - 11:26:55.859150605 [Client management]: UST app event tp:tptest created successfully for pid:2152177 object = 0x7f2238029d50 (in create_ust_event() at ust-app.cpp:2075)
DBG2 - 11:26:55.859180320 [Client management]: UST app object 0x7f2238029d50 enabled successfully for app: pid = 2152177 (in enable_ust_object() at ust-app.cpp:1955)
DBG2 - 11:26:55.859190119 [Client management]: UST app create event completed: app = 'gen-ust-events' pid = 2152177 (in create_ust_app_event() at ust-app.cpp:3817)
DBG3 - 11:26:55.859198472 [Client management]: Buffer registry per PID find id: 3 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG3 - 11:26:55.859208722 [Client management]: Created hashtable size 4 at 0x7f2238000b90 of type ULONG (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:55.859217163 [Client management]: Created hashtable size 4 at 0x7f2238001120 of type STRING (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:55.859224835 [Client management]: UST app channel metadata allocated (in alloc_ust_app_channel() at ust-app.cpp:1231)
DBG3 - 11:26:55.859234320 [Client management]: Session 1 found by id. (in session_find_by_id() at session.cpp:1152)
DBG2 - 11:26:55.859240213 [Client management]: Asking UST consumer for channel (in ask_channel_creation() at ust-consumer.cpp:58)
DBG3 - 11:26:55.859248690 [Client management]: Consumer trace path relative to current trace chunk: "ust/pid/gen-ust-events-2152177-20231213-112655" (in setup_channel_trace_path() at consumer.cpp:75)
DBG2 - 11:26:55.859381519 [Client management]: UST ask channel 5 successfully done with 1 stream(s) (in ask_channel_creation() at ust-consumer.cpp:178)
DBG2 - 11:26:55.859391719 [Client management]: Consumer setup metadata channel key 5 (in consumer_setup_metadata() at consumer.cpp:1420)
DBG2 - 11:26:55.859635468 [Client management]: UST metadata with key 5 created for app pid 2152177 (in create_ust_app_metadata() at ust-app.cpp:3982)
DBG3 - 11:26:55.859651280 [Client management]: UST app deleting channel metadata (in delete_ust_app_channel() at ust-app.cpp:575)
DBG1 - 11:26:55.859794389 [Client management]: Could not find channel for removal: Invalid channel key provided: channel key = 5 [channel() ust-registry-session.cpp:499] (in delete_ust_app_channel() at ust-app.cpp:604)
DBG1 - 11:26:55.859813920 [Client management]: Starting tracing for ust app pid 2152177 (in ust_app_start_trace() at ust-app.cpp:5282)
DBG3 - 11:26:55.859860775 [Application notification]: [ust-thread] Manage notify return from poll on 3 fds (in thread_application_notification() at notify-apps.cpp:81)
DBG3 - 11:26:55.859879731 [Application notification]: UST app receiving notify from sock 52 (in ust_app_recv_notify() at ust-app.cpp:6900)
DBG2 - 11:26:55.859891608 [Application notification]: UST app ustctl register enum received (in ust_app_recv_notify() at ust-app.cpp:7032)
DBG3 - 11:26:55.859912498 [Application notification]: Buffer registry per PID find id: 3 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG1 - 11:26:55.859925741 [Application notification]: UST registry creating enum: tp_tptest_enum, sess_objd: 3 (in create_or_find_enum() at ust-registry-session.cpp:825)
DBG1 - 11:26:55.859934392 [Application notification]: UST registry reply with enum tp_tptest_enum with id 0 in sess_objd: 3 (in create_or_find_enum() at ust-registry-session.cpp:841)
DBG3 - 11:26:55.859947055 [Application notification]: UST registry enum tp_tptest_enum added successfully or already found (in add_enum_ust_registry() at ust-app.cpp:6886)
DBG3 - 11:26:55.859956539 [Application notification]: [ust-thread] Manage notify polling (in thread_application_notification() at notify-apps.cpp:75)
DBG3 - 11:26:55.860025650 [Application notification]: [ust-thread] Manage notify return from poll on 3 fds (in thread_application_notification() at notify-apps.cpp:81)
DBG3 - 11:26:55.860041451 [Application notification]: UST app receiving notify from sock 52 (in ust_app_recv_notify() at ust-app.cpp:6900)
DBG2 - 11:26:55.860052763 [Application notification]: UST app ustctl register event received (in ust_app_recv_notify() at ust-app.cpp:6922)
DBG3 - 11:26:55.860080664 [Application notification]: Buffer registry per PID find id: 3 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG3 - 11:26:55.860111174 [Application notification]: UST registry creating event: event = { name = `tp:tptest`, signature = `int, anint, int, netint, long *, values, char *, text, size_t, textlen, char *, etext, uint32_t *, net_values, double, doublearg, float, floatarg`, id = 0, session objd = 3, channel objd = 4 } (in add_event() at ust-registry-channel.cpp:421)
DBG3 - 11:26:55.860128475 [Application notification]: UST registry event tp:tptest with id 0 added successfully (in add_event_ust_registry() at ust-app.cpp:6789)
DBG3 - 11:26:55.860137776 [Application notification]: [ust-thread] Manage notify polling (in thread_application_notification() at notify-apps.cpp:75)
DBG3 - 11:26:55.860159954 [Application notification]: [ust-thread] Manage notify return from poll on 3 fds (in thread_application_notification() at notify-apps.cpp:81)
DBG3 - 11:26:55.860169348 [Application notification]: UST app receiving notify from sock 52 (in ust_app_recv_notify() at ust-app.cpp:6900)
DBG2 - 11:26:55.860179086 [Application notification]: UST app ustctl register channel received (in ust_app_recv_notify() at ust-app.cpp:6993)
DBG3 - 11:26:55.860190243 [Application notification]: Buffer registry per PID find id: 3 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG3 - 11:26:55.860206792 [Application notification]: UST app replying to register channel key 4 with id 0, ret = 0 (in handle_app_register_channel_notification() at ust-app.cpp:6626)
DBG3 - 11:26:55.860281319 [Application notification]: [ust-thread] Manage notify polling (in thread_application_notification() at notify-apps.cpp:75)
DBG1 - 11:26:55.862174856 [Client management]: Opening packets of session channels: session name = drHn2XSuuqUB7ASL, session id = 1 (in session_open_packets() at session.cpp:878)
DBG3 - 11:26:55.862196721 [Client management]: Buffer registry per PID find id: 3 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG1 - 11:26:55.862206374 [Client management]: Consumer open channel packets: channel key = 4 (in consumer_open_channel_packets() at consumer.cpp:1743)
DBG1 - 11:26:55.862245770 [Client management]: Sending response (size: 24, retcode: Success (10)) (in thread_manage_clients() at client.cpp:2652)
DBG1 - 11:26:55.862270418 [Client management]: Accepting client command ... (in thread_manage_clients() at client.cpp:2489)
DBG1 - 11:26:56.858007467 [Consumer management]: Metadata request received for session 1, key 5 (in ust_consumer_metadata_request() at ust-consumer.cpp:476)
DBG3 - 11:26:56.858090668 [Consumer management]: Buffer registry per UID find id: 1, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:26:56.858125679 [Consumer management]: Buffer registry per PID find id: 3 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG2 - 11:26:56.858169397 [Consumer management]: Consumer push metadata to consumer socket 68 (in consumer_push_metadata() at consumer.cpp:1459)
DBG3 - 11:26:56.858403549 [Consumer management]: Consumer pushing metadata on sock 68 of len 5098 (in consumer_push_metadata() at consumer.cpp:1476)
DBG1 - 11:26:56.858774520 [Consumer management]: UST Consumer metadata pushed successfully (in ust_consumer_metadata_request() at ust-consumer.cpp:518)
DBG1 - 11:26:56.859216128 [Consumer management]: Metadata request received for session 1, key 5 (in ust_consumer_metadata_request() at ust-consumer.cpp:476)
DBG3 - 11:26:56.859283190 [Consumer management]: Buffer registry per UID find id: 1, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:26:56.859315441 [Consumer management]: Buffer registry per PID find id: 3 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG3 - 11:26:56.859345163 [Consumer management]: No metadata to push for metadata key 5 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG1 - 11:26:56.859372771 [Consumer management]: No metadata to push (in ust_app_push_metadata() at ust-app.cpp:723)
DBG2 - 11:26:56.859390479 [Consumer management]: Consumer push metadata to consumer socket 68 (in consumer_push_metadata() at consumer.cpp:1459)
DBG1 - 11:26:56.859609123 [Consumer management]: UST Consumer metadata pushed successfully (in ust_consumer_metadata_request() at ust-consumer.cpp:518)
DBG1 - 11:26:56.903128947 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:26:56.903195713 [Notification]: Handling fd (11) activity (1) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:26:56.903245179 [Notification]: Handling channel sample for channel chan (key = 4) in session drHn2XSuuqUB7ASL (highest usage = 16384, lowest usage = 0, consumed since last sample = 84) (in handle_notification_thread_channel_sample() at notification-thread-events.cpp:4944)
DBG1 - 11:26:56.903267437 [Consumer management]: Metadata request received for session 1, key 5 (in ust_consumer_metadata_request() at ust-consumer.cpp:476)
DBG3 - 11:26:56.903396746 [Consumer management]: Buffer registry per UID find id: 1, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:26:56.903432100 [Consumer management]: Buffer registry per PID find id: 3 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG1 - 11:26:56.903321828 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG3 - 11:26:56.903464092 [Consumer management]: No metadata to push for metadata key 5 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG1 - 11:26:56.903691186 [Consumer management]: No metadata to push (in ust_app_push_metadata() at ust-app.cpp:723)
DBG2 - 11:26:56.903716946 [Consumer management]: Consumer push metadata to consumer socket 68 (in consumer_push_metadata() at consumer.cpp:1459)
DBG1 - 11:26:56.903876429 [Consumer management]: UST Consumer metadata pushed successfully (in ust_consumer_metadata_request() at ust-consumer.cpp:518)
DBG1 - 11:26:56.904702195 [Consumer management]: Metadata request received for session 1, key 5 (in ust_consumer_metadata_request() at ust-consumer.cpp:476)
DBG3 - 11:26:56.904773504 [Consumer management]: Buffer registry per UID find id: 1, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:26:56.904805995 [Consumer management]: Buffer registry per PID find id: 3 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG3 - 11:26:56.904839072 [Consumer management]: No metadata to push for metadata key 5 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG1 - 11:26:56.904869974 [Consumer management]: No metadata to push (in ust_app_push_metadata() at ust-app.cpp:723)
DBG2 - 11:26:56.904888818 [Consumer management]: Consumer push metadata to consumer socket 68 (in consumer_push_metadata() at consumer.cpp:1459)
DBG1 - 11:26:56.905021782 [Consumer management]: UST Consumer metadata pushed successfully (in ust_consumer_metadata_request() at ust-consumer.cpp:518)
DBG1 - 11:26:56.905993041 [Consumer management]: Metadata request received for session 1, key 5 (in ust_consumer_metadata_request() at ust-consumer.cpp:476)
DBG3 - 11:26:56.906064380 [Consumer management]: Buffer registry per UID find id: 1, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:26:56.906100368 [Consumer management]: Buffer registry per PID find id: 3 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG3 - 11:26:56.906130500 [Consumer management]: No metadata to push for metadata key 5 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG1 - 11:26:56.906160403 [Consumer management]: No metadata to push (in ust_app_push_metadata() at ust-app.cpp:723)
DBG2 - 11:26:56.906180372 [Consumer management]: Consumer push metadata to consumer socket 68 (in consumer_push_metadata() at consumer.cpp:1459)
DBG1 - 11:26:56.906299931 [Consumer management]: UST Consumer metadata pushed successfully (in ust_consumer_metadata_request() at ust-consumer.cpp:518)
DBG1 - 11:26:57.547696821 [UST application registration]: UST registration received with pid:2152252 ppid:2151972 uid:1000 gid:1000 sock:62 name:gen-ust-events (version 10.0) (in thread_application_registration() at register.cpp:311)
DBG1 - 11:26:57.547732380 [UST application registration]: Futex n to 1 wake done (in futex_nto1_wake() at futex.cpp:116)
DBG1 - 11:26:57.547739650 [UST application registration]: Accepting application registration (in thread_application_registration() at register.cpp:206)
DBG1 - 11:26:57.547761605 [UST application registration]: UST registration received with pid:2152252 ppid:2151972 uid:1000 gid:1000 sock:70 name:gen-ust-events (version 10.0) (in thread_application_registration() at register.cpp:311)
DBG1 - 11:26:57.547773096 [UST application registration]: Futex n to 1 wake done (in futex_nto1_wake() at futex.cpp:116)
DBG1 - 11:26:57.547775938 [UST registration dispatch]: Futex n to 1 wait done (in futex_nto1_wait() at futex.cpp:100)
DBG1 - 11:26:57.547797842 [UST registration dispatch]: Futex n to 1 prepare done (in futex_nto1_prepare() at futex.cpp:64)
DBG1 - 11:26:57.547806159 [UST registration dispatch]: Dispatching UST registration pid:2152252 ppid:2151972 uid:1000 gid:1000 sock:62 name:gen-ust-events (version 10.0) (in thread_dispatch_ust_registration() at dispatch.cpp:281)
DBG3 - 11:26:57.547817722 [UST registration dispatch]: UST app creating application for socket 62 (in ust_app_create() at ust-app.cpp:4035)
DBG1 - 11:26:57.547778911 [UST application registration]: Accepting application registration (in thread_application_registration() at register.cpp:206)
DBG3 - 11:26:57.547843055 [UST registration dispatch]: Created hashtable size 4 at 0x7f2220004c30 of type U64 (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:57.547931487 [UST registration dispatch]: Created hashtable size 4 at 0x7f2220009440 of type ULONG (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:57.547943977 [UST registration dispatch]: Created hashtable size 4 at 0x7f22200033f0 of type ULONG (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:57.547954568 [UST registration dispatch]: Created hashtable size 4 at 0x7f2220002c10 of type U64 (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG1 - 11:26:57.547981163 [UST registration dispatch]: Dispatching UST registration pid:2152252 ppid:2151972 uid:1000 gid:1000 sock:70 name:gen-ust-events (version 10.0) (in thread_dispatch_ust_registration() at dispatch.cpp:281)
DBG3 - 11:26:57.547993350 [UST registration dispatch]: UST app notify socket 70 is set (in thread_dispatch_ust_registration() at dispatch.cpp:351)
DBG1 - 11:26:57.548006227 [UST registration dispatch]: App registered with pid:2152252 ppid:2151972 uid:1000 gid:1000 sock =62 name:gen-ust-events notify_sock =70 (version 10.0) (in ust_app_add() at ust-app.cpp:4158)
DBG1 - 11:26:57.548303472 [UST registration dispatch]: Beginning of waiter "wait" period (in wait() at waiter.cpp:48)
DBG1 - 11:26:57.548311714 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:26:57.548341730 [Notification]: Handling fd (23) activity (1) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:26:57.548355658 [Notification]: Received `ADD_TRACER_EVENT_SOURCE` command (in handle_notification_thread_command() at notification-thread-events.cpp:3191)
DBG3 - 11:26:57.548366655 [Notification]: Adding tracer event source fd to poll set: tracer_event_source_fd = 71, domain = 'ust' (in handle_notification_thread_command_add_tracer_event_source() at notification-thread-events.cpp:2071)
DBG1 - 11:26:57.548383317 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG1 - 11:26:57.548383622 [UST registration dispatch]: End of waiter "wait" period (in wait() at waiter.cpp:109)
DBG2 - 11:26:57.548710447 [UST registration dispatch]: UST application global event notifier rules update: app = 'gen-ust-events', pid = 2152252 (in ust_app_global_update_event_notifier_rules() at ust-app.cpp:6291)
DBG1 - 11:26:57.548727127 [UST registration dispatch]: Beginning of waiter "wait" period (in wait() at waiter.cpp:48)
DBG1 - 11:26:57.548732850 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:26:57.548744773 [Notification]: Handling fd (23) activity (1) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:26:57.548758627 [Notification]: Received `LIST_TRIGGERS` command (in handle_notification_thread_command() at notification-thread-events.cpp:3191)
DBG1 - 11:26:57.548774115 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG3 - 11:26:57.548747765 [Application notification]: [ust-thread] Manage notify return from poll on 3 fds (in thread_application_notification() at notify-apps.cpp:81)
DBG1 - 11:26:57.548774184 [UST registration dispatch]: End of waiter "wait" period (in wait() at waiter.cpp:109)
DBG3 - 11:26:57.548810818 [Application notification]: UST thread notify added sock 70 to pollset (in thread_application_notification() at notify-apps.cpp:140)
DBG3 - 11:26:57.548824423 [Application notification]: [ust-thread] Manage notify polling (in thread_application_notification() at notify-apps.cpp:75)
DBG2 - 11:26:57.548812386 [UST registration dispatch]: UST app global update for app sock 62 for session id 1 (in ust_app_global_update() at ust-app.cpp:6262)
DBG2 - 11:26:57.548849000 [UST registration dispatch]: UST app pid: 2152252 session id 1 not found, creating it (in find_or_create_ust_app_session() at ust-app.cpp:2722)
DBG3 - 11:26:57.548884033 [UST registration dispatch]: Created hashtable size 4 at 0x7f2220005e10 of type STRING (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG2 - 11:26:57.548905166 [UST registration dispatch]: Shadow copy of session handle -1 (in shadow_copy_session() at ust-app.cpp:2433)
DBG3 - 11:26:57.548917162 [UST registration dispatch]: Buffer registry per PID find id: 4 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG3 - 11:26:57.548929452 [UST registration dispatch]: Created hashtable size 4 at 0x7f22200083c0 of type U64 (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:57.548939049 [UST registration dispatch]: Buffer registry per PID created with session id: 4 (in buffer_reg_pid_create() at buffer-registry.cpp:280)
DBG3 - 11:26:57.548999861 [UST registration dispatch]: Created hashtable size 4 at 0x7f222000e600 of type STRING (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:57.549014765 [UST registration dispatch]: Created hashtable size 4 at 0x7f222000eb00 of type U64 (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:57.549059823 [UST registration dispatch]: Session 1 found by id. (in session_find_by_id() at session.cpp:1152)
DBG3 - 11:26:57.549082799 [UST registration dispatch]: Buffer registry per PID adding to global registry with id: 4 (in buffer_reg_pid_add() at buffer-registry.cpp:298)
DBG3 - 11:26:57.549094959 [UST registration dispatch]: UST app buffer registry per PID created successfully (in setup_buffer_reg_pid() at ust-app.cpp:2610)
DBG2 - 11:26:57.549271939 [UST registration dispatch]: UST app session created successfully with handle 3 (in find_or_create_ust_app_session() at ust-app.cpp:2800)
DBG3 - 11:26:57.549293704 [UST registration dispatch]: Created hashtable size 4 at 0x7f222000ffe0 of type ULONG (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:57.549305808 [UST registration dispatch]: Created hashtable size 4 at 0x7f2220010570 of type STRING (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:57.549316458 [UST registration dispatch]: UST app channel chan allocated (in alloc_ust_app_channel() at ust-app.cpp:1231)
DBG2 - 11:26:57.549327089 [UST registration dispatch]: UST app shadow copy of channel chan started (in shadow_copy_channel() at ust-app.cpp:2389)
DBG3 - 11:26:57.549337795 [UST registration dispatch]: UST app shadow copy of channel chan done (in shadow_copy_channel() at ust-app.cpp:2415)
DBG1 - 11:26:57.549348674 [UST registration dispatch]: UST app creating channel chan with per PID buffers (in create_channel_per_pid() at ust-app.cpp:3578)
DBG3 - 11:26:57.549359373 [UST registration dispatch]: Buffer registry per PID find id: 4 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG3 - 11:26:57.549374994 [UST registration dispatch]: Created hashtable size 4 at 0x7f2220010b00 of type STRING (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:57.549396053 [UST registration dispatch]: Session 1 found by id. (in session_find_by_id() at session.cpp:1152)
DBG2 - 11:26:57.549414904 [UST registration dispatch]: Asking UST consumer for channel (in ask_channel_creation() at ust-consumer.cpp:58)
DBG3 - 11:26:57.549429663 [UST registration dispatch]: Consumer trace path relative to current trace chunk: "ust/pid/gen-ust-events-2152252-20231213-112657" (in setup_channel_trace_path() at consumer.cpp:75)
DBG2 - 11:26:57.575416806 [UST registration dispatch]: UST ask channel 6 successfully done with 4 stream(s) (in ask_channel_creation() at ust-consumer.cpp:178)
DBG2 - 11:26:57.579286485 [UST registration dispatch]: UST app stream 1 received successfully (in ust_consumer_get_channel() at ust-consumer.cpp:301)
DBG2 - 11:26:57.579415265 [UST registration dispatch]: UST app stream 2 received successfully (in ust_consumer_get_channel() at ust-consumer.cpp:301)
DBG2 - 11:26:57.579480647 [UST registration dispatch]: UST app stream 3 received successfully (in ust_consumer_get_channel() at ust-consumer.cpp:301)
DBG2 - 11:26:57.579540959 [UST registration dispatch]: UST app stream 4 received successfully (in ust_consumer_get_channel() at ust-consumer.cpp:301)
DBG3 - 11:26:57.579608977 [UST registration dispatch]: UST app consumer has no more stream available (in ust_consumer_get_channel() at ust-consumer.cpp:284)
DBG1 - 11:26:57.579649731 [UST registration dispatch]: UST app sending channel chan to UST app sock 62 (in send_channel_pid_to_ust() at ust-app.cpp:1980)
DBG2 - 11:26:57.579680441 [UST registration dispatch]: UST app send channel to sock 62 pid 2152252 (name: chan, key: 0) (in ust_consumer_send_channel_to_ust() at ust-consumer.cpp:416)
DBG2 - 11:26:57.579995520 [UST registration dispatch]: UST consumer send stream to app 62 (in ust_consumer_send_stream_to_ust() at ust-consumer.cpp:370)
DBG2 - 11:26:57.580378306 [UST registration dispatch]: UST consumer send stream to app 62 (in ust_consumer_send_stream_to_ust() at ust-consumer.cpp:370)
DBG2 - 11:26:57.580744927 [UST registration dispatch]: UST consumer send stream to app 62 (in ust_consumer_send_stream_to_ust() at ust-consumer.cpp:370)
DBG2 - 11:26:57.581009750 [UST registration dispatch]: UST consumer send stream to app 62 (in ust_consumer_send_stream_to_ust() at ust-consumer.cpp:370)
DBG1 - 11:26:57.581202951 [UST registration dispatch]: Beginning of waiter "wait" period (in wait() at waiter.cpp:48)
DBG1 - 11:26:57.581228873 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:26:57.581282189 [Notification]: Handling fd (23) activity (1) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:26:57.581322379 [Notification]: Received `ADD_CHANNEL` command (in handle_notification_thread_command() at notification-thread-events.cpp:3191)
DBG1 - 11:26:57.581352741 [Notification]: Adding channel: channel name = `chan`, session id = 1, channel key = 6, domain = ust (in handle_notification_thread_command_add_channel() at notification-thread-events.cpp:1704)
DBG1 - 11:26:57.581390554 [Notification]: Found 0 triggers that apply to newly added channel (in handle_notification_thread_command_add_channel() at notification-thread-events.cpp:1745)
DBG1 - 11:26:57.581427087 [UST registration dispatch]: End of waiter "wait" period (in wait() at waiter.cpp:109)
DBG1 - 11:26:57.581427292 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG3 - 11:26:57.581468568 [UST registration dispatch]: UST app event tp:tptest allocated (in alloc_ust_app_event() at ust-app.cpp:1285)
DBG2 - 11:26:57.581622022 [UST registration dispatch]: UST app event tp:tptest created successfully for pid:2152252 object = 0x7f2220013310 (in create_ust_event() at ust-app.cpp:2075)
DBG2 - 11:26:57.581844074 [UST registration dispatch]: UST app object 0x7f2220013310 enabled successfully for app: pid = 2152252 (in enable_ust_object() at ust-app.cpp:1955)
DBG2 - 11:26:57.581947581 [UST registration dispatch]: UST app create event completed: app = 'gen-ust-events' pid = 2152252 (in create_ust_app_event() at ust-app.cpp:3817)
DBG3 - 11:26:57.581982952 [UST registration dispatch]: Buffer registry per PID find id: 4 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG3 - 11:26:57.582018272 [UST registration dispatch]: Created hashtable size 4 at 0x7f22200136c0 of type ULONG (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:57.582049393 [UST registration dispatch]: Created hashtable size 4 at 0x7f2220013c50 of type STRING (in lttng_ht_new() at hashtable/hashtable.cpp:153)
DBG3 - 11:26:57.582076715 [UST registration dispatch]: UST app channel metadata allocated (in alloc_ust_app_channel() at ust-app.cpp:1231)
DBG3 - 11:26:57.582108336 [UST registration dispatch]: Session 1 found by id. (in session_find_by_id() at session.cpp:1152)
DBG2 - 11:26:57.582129213 [UST registration dispatch]: Asking UST consumer for channel (in ask_channel_creation() at ust-consumer.cpp:58)
DBG3 - 11:26:57.582159756 [UST registration dispatch]: Consumer trace path relative to current trace chunk: "ust/pid/gen-ust-events-2152252-20231213-112657" (in setup_channel_trace_path() at consumer.cpp:75)
DBG2 - 11:26:57.582663501 [UST registration dispatch]: UST ask channel 7 successfully done with 1 stream(s) (in ask_channel_creation() at ust-consumer.cpp:178)
DBG2 - 11:26:57.582713125 [UST registration dispatch]: Consumer setup metadata channel key 7 (in consumer_setup_metadata() at consumer.cpp:1420)
DBG2 - 11:26:57.583976946 [UST registration dispatch]: UST metadata with key 7 created for app pid 2152252 (in create_ust_app_metadata() at ust-app.cpp:3982)
DBG3 - 11:26:57.584046863 [UST registration dispatch]: UST app deleting channel metadata (in delete_ust_app_channel() at ust-app.cpp:575)
DBG1 - 11:26:57.584204398 [UST registration dispatch]: Could not find channel for removal: Invalid channel key provided: channel key = 7 [channel() ust-registry-session.cpp:499] (in delete_ust_app_channel() at ust-app.cpp:604)
DBG1 - 11:26:57.584262122 [UST registration dispatch]: Starting tracing for ust app pid 2152252 (in ust_app_start_trace() at ust-app.cpp:5282)
DBG3 - 11:26:57.584531194 [Application notification]: [ust-thread] Manage notify return from poll on 4 fds (in thread_application_notification() at notify-apps.cpp:81)
DBG3 - 11:26:57.584597088 [Application notification]: UST app receiving notify from sock 70 (in ust_app_recv_notify() at ust-app.cpp:6900)
DBG2 - 11:26:57.584637902 [Application notification]: UST app ustctl register channel received (in ust_app_recv_notify() at ust-app.cpp:6993)
DBG3 - 11:26:57.584683075 [Application notification]: Buffer registry per PID find id: 4 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG3 - 11:26:57.584719073 [Application notification]: UST app replying to register channel key 6 with id 0, ret = 0 (in handle_app_register_channel_notification() at ust-app.cpp:6626)
DBG3 - 11:26:57.584836108 [Application notification]: [ust-thread] Manage notify polling (in thread_application_notification() at notify-apps.cpp:75)
DBG1 - 11:26:57.591437332 [UST registration dispatch]: Woken up but nothing in the UST command queue (in thread_dispatch_ust_registration() at dispatch.cpp:274)
DBG3 - 11:26:57.591524245 [Application notification]: [ust-thread] Manage notify return from poll on 4 fds (in thread_application_notification() at notify-apps.cpp:81)
DBG3 - 11:26:57.591600213 [Application notification]: UST app receiving notify from sock 70 (in ust_app_recv_notify() at ust-app.cpp:6900)
DBG1 - 11:26:57.591450438 [UST application management]: Apps thread return from poll on 3 fds (in thread_application_management() at manage-apps.cpp:96)
DBG2 - 11:26:57.591644685 [Application notification]: UST app ustctl register enum received (in ust_app_recv_notify() at ust-app.cpp:7032)
DBG1 - 11:26:57.591704231 [UST application management]: Apps with sock 62 added to poll set (in thread_application_management() at manage-apps.cpp:149)
DBG1 - 11:26:57.591746706 [UST application management]: Apps thread polling (in thread_application_management() at manage-apps.cpp:90)
DBG3 - 11:26:57.591750407 [Application notification]: Buffer registry per PID find id: 4 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG1 - 11:26:57.591838585 [Application notification]: UST registry creating enum: tp_tptest_enum, sess_objd: 3 (in create_or_find_enum() at ust-registry-session.cpp:825)
DBG1 - 11:26:57.591870615 [Application notification]: UST registry reply with enum tp_tptest_enum with id 0 in sess_objd: 3 (in create_or_find_enum() at ust-registry-session.cpp:841)
DBG3 - 11:26:57.591918945 [Application notification]: UST registry enum tp_tptest_enum added successfully or already found (in add_enum_ust_registry() at ust-app.cpp:6886)
DBG3 - 11:26:57.591951157 [Application notification]: [ust-thread] Manage notify polling (in thread_application_notification() at notify-apps.cpp:75)
DBG3 - 11:26:57.592173677 [Application notification]: [ust-thread] Manage notify return from poll on 4 fds (in thread_application_notification() at notify-apps.cpp:81)
DBG3 - 11:26:57.592203798 [Application notification]: UST app receiving notify from sock 70 (in ust_app_recv_notify() at ust-app.cpp:6900)
DBG2 - 11:26:57.592236974 [Application notification]: UST app ustctl register event received (in ust_app_recv_notify() at ust-app.cpp:6922)
DBG3 - 11:26:57.592357481 [Application notification]: Buffer registry per PID find id: 4 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG3 - 11:26:57.592462467 [Application notification]: UST registry creating event: event = { name = `tp:tptest`, signature = `int, anint, int, netint, long *, values, char *, text, size_t, textlen, char *, etext, uint32_t *, net_values, double, doublearg, float, floatarg`, id = 0, session objd = 3, channel objd = 4 } (in add_event() at ust-registry-channel.cpp:421)
DBG3 - 11:26:57.592682057 [Application notification]: UST registry event tp:tptest with id 0 added successfully (in add_event_ust_registry() at ust-app.cpp:6789)
DBG3 - 11:26:57.592720333 [Application notification]: [ust-thread] Manage notify polling (in thread_application_notification() at notify-apps.cpp:75)
DBG1 - 11:26:57.859898508 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:26:57.859960471 [Notification]: Handling fd (11) activity (1) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:26:57.860008746 [Notification]: Handling channel sample for channel chan (key = 4) in session drHn2XSuuqUB7ASL (highest usage = 0, lowest usage = 0, consumed since last sample = 252) (in handle_notification_thread_channel_sample() at notification-thread-events.cpp:4944)
DBG1 - 11:26:57.860051623 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG1 - 11:26:58.575807888 [Consumer management]: Metadata request received for session 1, key 5 (in ust_consumer_metadata_request() at ust-consumer.cpp:476)
DBG3 - 11:26:58.575885417 [Consumer management]: Buffer registry per UID find id: 1, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:26:58.575921055 [Consumer management]: Buffer registry per PID find id: 3 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG3 - 11:26:58.575956880 [Consumer management]: No metadata to push for metadata key 5 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG1 - 11:26:58.575985517 [Consumer management]: No metadata to push (in ust_app_push_metadata() at ust-app.cpp:723)
DBG2 - 11:26:58.576004064 [Consumer management]: Consumer push metadata to consumer socket 68 (in consumer_push_metadata() at consumer.cpp:1459)
DBG1 - 11:26:58.576251031 [Consumer management]: UST Consumer metadata pushed successfully (in ust_consumer_metadata_request() at ust-consumer.cpp:518)
DBG1 - 11:26:58.576337622 [Consumer management]: Metadata request received for session 1, key 7 (in ust_consumer_metadata_request() at ust-consumer.cpp:476)
DBG3 - 11:26:58.576373331 [Consumer management]: Buffer registry per UID find id: 1, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:26:58.576403763 [Consumer management]: Buffer registry per PID find id: 4 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG2 - 11:26:58.576438169 [Consumer management]: Consumer push metadata to consumer socket 68 (in consumer_push_metadata() at consumer.cpp:1459)
DBG3 - 11:26:58.576661077 [Consumer management]: Consumer pushing metadata on sock 68 of len 5098 (in consumer_push_metadata() at consumer.cpp:1476)
DBG1 - 11:26:58.576970382 [Consumer management]: UST Consumer metadata pushed successfully (in ust_consumer_metadata_request() at ust-consumer.cpp:518)
DBG1 - 11:26:58.577383417 [Consumer management]: Metadata request received for session 1, key 7 (in ust_consumer_metadata_request() at ust-consumer.cpp:476)
DBG3 - 11:26:58.577452839 [Consumer management]: Buffer registry per UID find id: 1, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:26:58.577485099 [Consumer management]: Buffer registry per PID find id: 4 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG3 - 11:26:58.577515484 [Consumer management]: No metadata to push for metadata key 7 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG1 - 11:26:58.577543228 [Consumer management]: No metadata to push (in ust_app_push_metadata() at ust-app.cpp:723)
DBG2 - 11:26:58.577589742 [Consumer management]: Consumer push metadata to consumer socket 68 (in consumer_push_metadata() at consumer.cpp:1459)
DBG1 - 11:26:58.577709956 [Consumer management]: UST Consumer metadata pushed successfully (in ust_consumer_metadata_request() at ust-consumer.cpp:518)
DBG1 - 11:26:58.619152646 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:26:58.619215277 [Notification]: Handling fd (11) activity (1) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:26:58.619251806 [Consumer management]: Metadata request received for session 1, key 5 (in ust_consumer_metadata_request() at ust-consumer.cpp:476)
DBG3 - 11:26:58.619333790 [Consumer management]: Buffer registry per UID find id: 1, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:26:58.619373922 [Consumer management]: Buffer registry per PID find id: 3 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG1 - 11:26:58.619264194 [Notification]: Handling channel sample for channel chan (key = 6) in session drHn2XSuuqUB7ASL (highest usage = 16384, lowest usage = 0, consumed since last sample = 84) (in handle_notification_thread_channel_sample() at notification-thread-events.cpp:4944)
DBG1 - 11:26:58.619484375 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG3 - 11:26:58.619410888 [Consumer management]: No metadata to push for metadata key 5 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG1 - 11:26:58.619623466 [Consumer management]: No metadata to push (in ust_app_push_metadata() at ust-app.cpp:723)
DBG2 - 11:26:58.619648780 [Consumer management]: Consumer push metadata to consumer socket 68 (in consumer_push_metadata() at consumer.cpp:1459)
DBG1 - 11:26:58.619901254 [Consumer management]: UST Consumer metadata pushed successfully (in ust_consumer_metadata_request() at ust-consumer.cpp:518)
DBG1 - 11:26:58.619991053 [Consumer management]: Metadata request received for session 1, key 7 (in ust_consumer_metadata_request() at ust-consumer.cpp:476)
DBG3 - 11:26:58.620029106 [Consumer management]: Buffer registry per UID find id: 1, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:26:58.620069897 [Consumer management]: Buffer registry per PID find id: 4 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG3 - 11:26:58.620100244 [Consumer management]: No metadata to push for metadata key 7 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG1 - 11:26:58.620127382 [Consumer management]: No metadata to push (in ust_app_push_metadata() at ust-app.cpp:723)
DBG2 - 11:26:58.620144898 [Consumer management]: Consumer push metadata to consumer socket 68 (in consumer_push_metadata() at consumer.cpp:1459)
DBG1 - 11:26:58.620354553 [Consumer management]: UST Consumer metadata pushed successfully (in ust_consumer_metadata_request() at ust-consumer.cpp:518)
DBG1 - 11:26:58.621099848 [Consumer management]: Metadata request received for session 1, key 5 (in ust_consumer_metadata_request() at ust-consumer.cpp:476)
DBG3 - 11:26:58.621140580 [Consumer management]: Buffer registry per UID find id: 1, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:26:58.621172675 [Consumer management]: Buffer registry per PID find id: 3 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG3 - 11:26:58.621203557 [Consumer management]: No metadata to push for metadata key 5 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG1 - 11:26:58.621232070 [Consumer management]: No metadata to push (in ust_app_push_metadata() at ust-app.cpp:723)
DBG2 - 11:26:58.621250975 [Consumer management]: Consumer push metadata to consumer socket 68 (in consumer_push_metadata() at consumer.cpp:1459)
DBG1 - 11:26:58.621476527 [Consumer management]: UST Consumer metadata pushed successfully (in ust_consumer_metadata_request() at ust-consumer.cpp:518)
DBG1 - 11:26:58.621565791 [Consumer management]: Metadata request received for session 1, key 7 (in ust_consumer_metadata_request() at ust-consumer.cpp:476)
DBG3 - 11:26:58.621628604 [Consumer management]: Buffer registry per UID find id: 1, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:26:58.621660283 [Consumer management]: Buffer registry per PID find id: 4 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG3 - 11:26:58.621692475 [Consumer management]: No metadata to push for metadata key 7 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG1 - 11:26:58.621720217 [Consumer management]: No metadata to push (in ust_app_push_metadata() at ust-app.cpp:723)
DBG2 - 11:26:58.621739525 [Consumer management]: Consumer push metadata to consumer socket 68 (in consumer_push_metadata() at consumer.cpp:1459)
DBG1 - 11:26:58.621962834 [Consumer management]: UST Consumer metadata pushed successfully (in ust_consumer_metadata_request() at ust-consumer.cpp:518)
DBG1 - 11:26:58.622682647 [Consumer management]: Metadata request received for session 1, key 5 (in ust_consumer_metadata_request() at ust-consumer.cpp:476)
DBG3 - 11:26:58.622717939 [Consumer management]: Buffer registry per UID find id: 1, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:26:58.622746606 [Consumer management]: Buffer registry per PID find id: 3 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG3 - 11:26:58.622775829 [Consumer management]: No metadata to push for metadata key 5 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG1 - 11:26:58.622803837 [Consumer management]: No metadata to push (in ust_app_push_metadata() at ust-app.cpp:723)
DBG2 - 11:26:58.622822073 [Consumer management]: Consumer push metadata to consumer socket 68 (in consumer_push_metadata() at consumer.cpp:1459)
DBG1 - 11:26:58.623007091 [Consumer management]: UST Consumer metadata pushed successfully (in ust_consumer_metadata_request() at ust-consumer.cpp:518)
DBG1 - 11:26:58.623063571 [Consumer management]: Metadata request received for session 1, key 7 (in ust_consumer_metadata_request() at ust-consumer.cpp:476)
DBG3 - 11:26:58.623095538 [Consumer management]: Buffer registry per UID find id: 1, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:26:58.623126771 [Consumer management]: Buffer registry per PID find id: 4 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG3 - 11:26:58.623154688 [Consumer management]: No metadata to push for metadata key 7 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG1 - 11:26:58.623185161 [Consumer management]: No metadata to push (in ust_app_push_metadata() at ust-app.cpp:723)
DBG2 - 11:26:58.623203510 [Consumer management]: Consumer push metadata to consumer socket 68 (in consumer_push_metadata() at consumer.cpp:1459)
DBG1 - 11:26:58.623485650 [Consumer management]: UST Consumer metadata pushed successfully (in ust_consumer_metadata_request() at ust-consumer.cpp:518)
DBG1 - 11:26:58.859694876 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:26:58.859750464 [Notification]: Handling fd (11) activity (1) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:26:58.859797984 [Notification]: Handling channel sample for channel chan (key = 4) in session drHn2XSuuqUB7ASL (highest usage = 0, lowest usage = 0, consumed since last sample = 84) (in handle_notification_thread_channel_sample() at notification-thread-events.cpp:4944)
DBG1 - 11:26:58.859840489 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG1 - 11:26:59.577683934 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:26:59.577722553 [Notification]: Handling fd (11) activity (1) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:26:59.577769281 [Notification]: Handling channel sample for channel chan (key = 6) in session drHn2XSuuqUB7ASL (highest usage = 0, lowest usage = 0, consumed since last sample = 2300) (in handle_notification_thread_channel_sample() at notification-thread-events.cpp:4944)
DBG1 - 11:26:59.577834471 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG1 - 11:26:59.859688539 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:26:59.859726177 [Notification]: Handling fd (11) activity (1) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:26:59.859772461 [Notification]: Handling channel sample for channel chan (key = 4) in session drHn2XSuuqUB7ASL (highest usage = 0, lowest usage = 0, consumed since last sample = 252) (in handle_notification_thread_channel_sample() at notification-thread-events.cpp:4944)
DBG1 - 11:26:59.859815084 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG1 - 11:27:00.577663377 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:27:00.577725022 [Notification]: Handling fd (11) activity (1) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:27:00.577773128 [Notification]: Handling channel sample for channel chan (key = 6) in session drHn2XSuuqUB7ASL (highest usage = 0, lowest usage = 0, consumed since last sample = 84) (in handle_notification_thread_channel_sample() at notification-thread-events.cpp:4944)
DBG1 - 11:27:00.577815927 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG1 - 11:27:00.859636005 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:27:00.859699967 [Notification]: Handling fd (11) activity (1) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:27:00.859748968 [Notification]: Handling channel sample for channel chan (key = 4) in session drHn2XSuuqUB7ASL (highest usage = 0, lowest usage = 0, consumed since last sample = 84) (in handle_notification_thread_channel_sample() at notification-thread-events.cpp:4944)
DBG1 - 11:27:00.859792027 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG1 - 11:27:01.577764497 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:27:01.577828533 [Notification]: Handling fd (11) activity (1) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:27:01.577877767 [Notification]: Handling channel sample for channel chan (key = 6) in session drHn2XSuuqUB7ASL (highest usage = 0, lowest usage = 0, consumed since last sample = 2300) (in handle_notification_thread_channel_sample() at notification-thread-events.cpp:4944)
DBG1 - 11:27:01.577951956 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG1 - 11:27:01.860427287 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:27:01.860469211 [Notification]: Handling fd (11) activity (1) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:27:01.860524716 [Notification]: Handling channel sample for channel chan (key = 4) in session drHn2XSuuqUB7ASL (highest usage = 0, lowest usage = 0, consumed since last sample = 252) (in handle_notification_thread_channel_sample() at notification-thread-events.cpp:4944)
DBG1 - 11:27:01.860574231 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG1 - 11:27:02.577703139 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:27:02.577766858 [Notification]: Handling fd (11) activity (1) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:27:02.577814256 [Notification]: Handling channel sample for channel chan (key = 6) in session drHn2XSuuqUB7ASL (highest usage = 0, lowest usage = 0, consumed since last sample = 84) (in handle_notification_thread_channel_sample() at notification-thread-events.cpp:4944)
DBG1 - 11:27:02.577857385 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG1 - 11:27:02.859777876 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:27:02.859819006 [Notification]: Handling fd (11) activity (1) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:27:02.859866614 [Notification]: Handling channel sample for channel chan (key = 4) in session drHn2XSuuqUB7ASL (highest usage = 0, lowest usage = 0, consumed since last sample = 84) (in handle_notification_thread_channel_sample() at notification-thread-events.cpp:4944)
DBG1 - 11:27:02.859909108 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG1 - 11:27:03.257809303 [Client management]: Wait for client response (in thread_manage_clients() at client.cpp:2534)
DBG1 - 11:27:03.257921132 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.cpp:2562)
DBG1 - 11:27:03.257964738 [Client management]: Processing client command 'LIST_SESSIONS' (11) (in process_client_msg() at client.cpp:1007)
DBG1 - 11:27:03.257989659 [Client management]: Counting number of available session for UID 1000 (in lttng_sessions_count() at client.cpp:597)
DBG1 - 11:27:03.258014144 [Client management]: Getting all available session for UID 1000 GID 1000 (in cmd_list_lttng_sessions() at cmd.cpp:3971)
DBG1 - 11:27:03.258043471 [Client management]: Sending response (size: 4409, retcode: Success (10)) (in thread_manage_clients() at client.cpp:2652)
DBG1 - 11:27:03.258087537 [Client management]: Accepting client command ... (in thread_manage_clients() at client.cpp:2489)
DBG1 - 11:27:03.258382117 [Client management]: Wait for client response (in thread_manage_clients() at client.cpp:2534)
DBG1 - 11:27:03.258438131 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.cpp:2562)
DBG1 - 11:27:03.258472984 [Client management]: Processing client command 'STOP_TRACE' (15) (in process_client_msg() at client.cpp:1007)
DBG1 - 11:27:03.258496471 [Client management]: Getting session drHn2XSuuqUB7ASL by name (in process_client_msg() at client.cpp:1122)
DBG2 - 11:27:03.258515525 [Client management]: Trying to find session by name drHn2XSuuqUB7ASL (in session_find_by_name() at session.cpp:1114)
DBG1 - 11:27:03.258535627 [Client management]: Begin stop session "drHn2XSuuqUB7ASL" (id 1) (in cmd_stop_trace() at cmd.cpp:2888)
DBG1 - 11:27:03.258555134 [Client management]: Stopping all UST traces (in ust_app_stop_trace_all() at ust-app.cpp:5873)
DBG1 - 11:27:03.258568469 [Client management]: Stopping tracing for ust app pid 2152177 (in ust_app_stop_trace() at ust-app.cpp:5390)
DBG3 - 11:27:03.258851200 [Client management]: Buffer registry per PID find id: 3 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG3 - 11:27:03.258898150 [Client management]: No metadata to push for metadata key 5 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG1 - 11:27:03.258919502 [Client management]: Stopping tracing for ust app pid 2152252 (in ust_app_stop_trace() at ust-app.cpp:5390)
DBG3 - 11:27:03.259088599 [Client management]: Buffer registry per PID find id: 4 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG3 - 11:27:03.259112753 [Client management]: No metadata to push for metadata key 7 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG1 - 11:27:03.259130994 [Client management]: Flushing session buffers for all ust apps (in ust_app_flush_session() at ust-app.cpp:5562)
DBG1 - 11:27:03.259179793 [Client management]: Flushing app session buffers for ust app pid 2152177 (in ust_app_flush_app_session() at ust-app.cpp:5502)
DBG2 - 11:27:03.259209453 [Client management]: Consumer flush channel key 4 (in consumer_flush_channel() at consumer.cpp:1323)
DBG1 - 11:27:03.259375422 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:27:03.259395317 [Notification]: Handling fd (11) activity (1) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:27:03.259403771 [Client management]: Flushing app session buffers for ust app pid 2152252 (in ust_app_flush_app_session() at ust-app.cpp:5502)
DBG2 - 11:27:03.259491072 [Client management]: Consumer flush channel key 6 (in consumer_flush_channel() at consumer.cpp:1323)
DBG1 - 11:27:03.259541814 [Consumer management]: Metadata request received for session 1, key 5 (in ust_consumer_metadata_request() at ust-consumer.cpp:476)
DBG1 - 11:27:03.259427670 [Notification]: Handling channel sample for channel chan (key = 4) in session drHn2XSuuqUB7ASL (highest usage = 16384, lowest usage = 16384, consumed since last sample = 252) (in handle_notification_thread_channel_sample() at notification-thread-events.cpp:4944)
DBG1 - 11:27:03.259675531 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG3 - 11:27:03.259616565 [Consumer management]: Buffer registry per UID find id: 1, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG1 - 11:27:03.259798052 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:27:03.259824567 [Notification]: Handling fd (11) activity (1) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:27:03.259863479 [Notification]: Handling channel sample for channel chan (key = 6) in session drHn2XSuuqUB7ASL (highest usage = 16384, lowest usage = 16384, consumed since last sample = 2300) (in handle_notification_thread_channel_sample() at notification-thread-events.cpp:4944)
DBG1 - 11:27:03.259902761 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG3 - 11:27:03.259799374 [Consumer management]: Buffer registry per PID find id: 3 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG1 - 11:27:03.259936323 [Client management]: Completed stop session "drHn2XSuuqUB7ASL" (id 1) (in cmd_stop_trace() at cmd.cpp:2912)
DBG1 - 11:27:03.259987054 [Client management]: Sending response (size: 24, retcode: Success (10)) (in thread_manage_clients() at client.cpp:2652)
DBG1 - 11:27:03.260028941 [Client management]: Accepting client command ... (in thread_manage_clients() at client.cpp:2489)
DBG3 - 11:27:03.259958331 [Consumer management]: No metadata to push for metadata key 5 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG1 - 11:27:03.260084698 [Consumer management]: No metadata to push (in ust_app_push_metadata() at ust-app.cpp:723)
DBG2 - 11:27:03.260100638 [Consumer management]: Consumer push metadata to consumer socket 68 (in consumer_push_metadata() at consumer.cpp:1459)
DBG1 - 11:27:03.260188612 [Consumer management]: UST Consumer metadata pushed successfully (in ust_consumer_metadata_request() at ust-consumer.cpp:518)
DBG1 - 11:27:03.260226064 [Consumer management]: Metadata request received for session 1, key 7 (in ust_consumer_metadata_request() at ust-consumer.cpp:476)
DBG3 - 11:27:03.260247215 [Consumer management]: Buffer registry per UID find id: 1, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:27:03.260267170 [Consumer management]: Buffer registry per PID find id: 4 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG1 - 11:27:03.260270405 [Client management]: Wait for client response (in thread_manage_clients() at client.cpp:2534)
DBG3 - 11:27:03.260290940 [Consumer management]: No metadata to push for metadata key 7 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG1 - 11:27:03.260340995 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.cpp:2562)
DBG1 - 11:27:03.260342143 [Consumer management]: No metadata to push (in ust_app_push_metadata() at ust-app.cpp:723)
DBG1 - 11:27:03.260375552 [Client management]: Processing client command 'DATA_PENDING' (20) (in process_client_msg() at client.cpp:1007)
DBG1 - 11:27:03.260400044 [Client management]: Getting session drHn2XSuuqUB7ASL by name (in process_client_msg() at client.cpp:1122)
DBG2 - 11:27:03.260421930 [Client management]: Trying to find session by name drHn2XSuuqUB7ASL (in session_find_by_name() at session.cpp:1114)
DBG1 - 11:27:03.260444510 [Client management]: Data pending for session drHn2XSuuqUB7ASL (in cmd_data_pending() at cmd.cpp:4032)
DBG3 - 11:27:03.260481928 [Client management]: Consumer data pending for id 1 (in consumer_is_data_pending() at consumer.cpp:1266)
DBG2 - 11:27:03.260377176 [Consumer management]: Consumer push metadata to consumer socket 68 (in consumer_push_metadata() at consumer.cpp:1459)
DBG1 - 11:27:03.260597475 [Client management]: Consumer data is pending for session id 1 (in consumer_is_data_pending() at consumer.cpp:1302)
DBG1 - 11:27:03.260626556 [Client management]: Sending response (size: 25, retcode: Success (10)) (in thread_manage_clients() at client.cpp:2652)
DBG1 - 11:27:03.260667275 [Client management]: Accepting client command ... (in thread_manage_clients() at client.cpp:2489)
DBG1 - 11:27:03.260707637 [Consumer management]: UST Consumer metadata pushed successfully (in ust_consumer_metadata_request() at ust-consumer.cpp:518)
DBG1 - 11:27:03.261057734 [Consumer management]: Metadata request received for session 1, key 5 (in ust_consumer_metadata_request() at ust-consumer.cpp:476)
DBG3 - 11:27:03.261082634 [Consumer management]: Buffer registry per UID find id: 1, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:27:03.261102473 [Consumer management]: Buffer registry per PID find id: 3 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG3 - 11:27:03.261121099 [Consumer management]: No metadata to push for metadata key 5 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG1 - 11:27:03.261140470 [Consumer management]: No metadata to push (in ust_app_push_metadata() at ust-app.cpp:723)
DBG2 - 11:27:03.261152065 [Consumer management]: Consumer push metadata to consumer socket 68 (in consumer_push_metadata() at consumer.cpp:1459)
DBG1 - 11:27:03.261231249 [Consumer management]: UST Consumer metadata pushed successfully (in ust_consumer_metadata_request() at ust-consumer.cpp:518)
DBG1 - 11:27:03.261282601 [Consumer management]: Metadata request received for session 1, key 7 (in ust_consumer_metadata_request() at ust-consumer.cpp:476)
DBG3 - 11:27:03.261311136 [Consumer management]: Buffer registry per UID find id: 1, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:27:03.261333969 [Consumer management]: Buffer registry per PID find id: 4 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG3 - 11:27:03.261352590 [Consumer management]: No metadata to push for metadata key 7 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG1 - 11:27:03.261382608 [Consumer management]: No metadata to push (in ust_app_push_metadata() at ust-app.cpp:723)
DBG2 - 11:27:03.261394861 [Consumer management]: Consumer push metadata to consumer socket 68 (in consumer_push_metadata() at consumer.cpp:1459)
DBG1 - 11:27:03.261465615 [Consumer management]: UST Consumer metadata pushed successfully (in ust_consumer_metadata_request() at ust-consumer.cpp:518)
DBG1 - 11:27:03.261850935 [Consumer management]: Metadata request received for session 1, key 5 (in ust_consumer_metadata_request() at ust-consumer.cpp:476)
DBG3 - 11:27:03.261875705 [Consumer management]: Buffer registry per UID find id: 1, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:27:03.261911251 [Consumer management]: Buffer registry per PID find id: 3 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG3 - 11:27:03.261933317 [Consumer management]: No metadata to push for metadata key 5 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG1 - 11:27:03.261953526 [Consumer management]: No metadata to push (in ust_app_push_metadata() at ust-app.cpp:723)
DBG2 - 11:27:03.261964851 [Consumer management]: Consumer push metadata to consumer socket 68 (in consumer_push_metadata() at consumer.cpp:1459)
DBG1 - 11:27:03.262049410 [Consumer management]: UST Consumer metadata pushed successfully (in ust_consumer_metadata_request() at ust-consumer.cpp:518)
DBG1 - 11:27:03.262103204 [Consumer management]: Metadata request received for session 1, key 7 (in ust_consumer_metadata_request() at ust-consumer.cpp:476)
DBG3 - 11:27:03.262124992 [Consumer management]: Buffer registry per UID find id: 1, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:27:03.262169501 [Consumer management]: Buffer registry per PID find id: 4 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG3 - 11:27:03.262188875 [Consumer management]: No metadata to push for metadata key 7 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG1 - 11:27:03.262207138 [Consumer management]: No metadata to push (in ust_app_push_metadata() at ust-app.cpp:723)
DBG2 - 11:27:03.262218577 [Consumer management]: Consumer push metadata to consumer socket 68 (in consumer_push_metadata() at consumer.cpp:1459)
DBG1 - 11:27:03.262339159 [Consumer management]: UST Consumer metadata pushed successfully (in ust_consumer_metadata_request() at ust-consumer.cpp:518)
DBG1 - 11:27:03.262853589 [Consumer management]: Metadata request received for session 1, key 5 (in ust_consumer_metadata_request() at ust-consumer.cpp:476)
DBG3 - 11:27:03.262875565 [Consumer management]: Buffer registry per UID find id: 1, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:27:03.262895050 [Consumer management]: Buffer registry per PID find id: 3 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG3 - 11:27:03.262913328 [Consumer management]: No metadata to push for metadata key 5 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG1 - 11:27:03.262930950 [Consumer management]: No metadata to push (in ust_app_push_metadata() at ust-app.cpp:723)
DBG2 - 11:27:03.262942680 [Consumer management]: Consumer push metadata to consumer socket 68 (in consumer_push_metadata() at consumer.cpp:1459)
DBG1 - 11:27:03.263022112 [Consumer management]: UST Consumer metadata pushed successfully (in ust_consumer_metadata_request() at ust-consumer.cpp:518)
DBG1 - 11:27:03.263079608 [Consumer management]: Metadata request received for session 1, key 7 (in ust_consumer_metadata_request() at ust-consumer.cpp:476)
DBG3 - 11:27:03.263103694 [Consumer management]: Buffer registry per UID find id: 1, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:27:03.263126197 [Consumer management]: Buffer registry per PID find id: 4 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG3 - 11:27:03.263147291 [Consumer management]: No metadata to push for metadata key 7 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG1 - 11:27:03.263166462 [Consumer management]: No metadata to push (in ust_app_push_metadata() at ust-app.cpp:723)
DBG2 - 11:27:03.263179037 [Consumer management]: Consumer push metadata to consumer socket 68 (in consumer_push_metadata() at consumer.cpp:1459)
DBG1 - 11:27:03.263253336 [Consumer management]: UST Consumer metadata pushed successfully (in ust_consumer_metadata_request() at ust-consumer.cpp:518)
DBG1 - 11:27:03.263744909 [Consumer management]: Metadata request received for session 1, key 5 (in ust_consumer_metadata_request() at ust-consumer.cpp:476)
DBG3 - 11:27:03.263790620 [Consumer management]: Buffer registry per UID find id: 1, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:27:03.263814725 [Consumer management]: Buffer registry per PID find id: 3 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG3 - 11:27:03.263835355 [Consumer management]: No metadata to push for metadata key 5 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG1 - 11:27:03.263853785 [Consumer management]: No metadata to push (in ust_app_push_metadata() at ust-app.cpp:723)
DBG2 - 11:27:03.263867471 [Consumer management]: Consumer push metadata to consumer socket 68 (in consumer_push_metadata() at consumer.cpp:1459)
DBG1 - 11:27:03.264006569 [Consumer management]: UST Consumer metadata pushed successfully (in ust_consumer_metadata_request() at ust-consumer.cpp:518)
DBG1 - 11:27:03.264061677 [Consumer management]: Metadata request received for session 1, key 7 (in ust_consumer_metadata_request() at ust-consumer.cpp:476)
DBG3 - 11:27:03.264083431 [Consumer management]: Buffer registry per UID find id: 1, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:27:03.264121153 [Consumer management]: Buffer registry per PID find id: 4 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG3 - 11:27:03.264140395 [Consumer management]: No metadata to push for metadata key 7 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG1 - 11:27:03.264158331 [Consumer management]: No metadata to push (in ust_app_push_metadata() at ust-app.cpp:723)
DBG2 - 11:27:03.264169833 [Consumer management]: Consumer push metadata to consumer socket 68 (in consumer_push_metadata() at consumer.cpp:1459)
DBG1 - 11:27:03.264246102 [Consumer management]: UST Consumer metadata pushed successfully (in ust_consumer_metadata_request() at ust-consumer.cpp:518)
DBG1 - 11:27:03.264817037 [Consumer management]: Metadata request received for session 1, key 5 (in ust_consumer_metadata_request() at ust-consumer.cpp:476)
DBG3 - 11:27:03.264860218 [Consumer management]: Buffer registry per UID find id: 1, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:27:03.264883990 [Consumer management]: Buffer registry per PID find id: 3 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG3 - 11:27:03.264904620 [Consumer management]: No metadata to push for metadata key 5 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG1 - 11:27:03.264923959 [Consumer management]: No metadata to push (in ust_app_push_metadata() at ust-app.cpp:723)
DBG2 - 11:27:03.264940058 [Consumer management]: Consumer push metadata to consumer socket 68 (in consumer_push_metadata() at consumer.cpp:1459)
DBG1 - 11:27:03.265030818 [Consumer management]: UST Consumer metadata pushed successfully (in ust_consumer_metadata_request() at ust-consumer.cpp:518)
DBG1 - 11:27:03.265068371 [Consumer management]: Metadata request received for session 1, key 7 (in ust_consumer_metadata_request() at ust-consumer.cpp:476)
DBG3 - 11:27:03.265088120 [Consumer management]: Buffer registry per UID find id: 1, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:27:03.265106819 [Consumer management]: Buffer registry per PID find id: 4 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG3 - 11:27:03.265125497 [Consumer management]: No metadata to push for metadata key 7 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG1 - 11:27:03.265142942 [Consumer management]: No metadata to push (in ust_app_push_metadata() at ust-app.cpp:723)
DBG2 - 11:27:03.265154251 [Consumer management]: Consumer push metadata to consumer socket 68 (in consumer_push_metadata() at consumer.cpp:1459)
DBG1 - 11:27:03.265320764 [Consumer management]: UST Consumer metadata pushed successfully (in ust_consumer_metadata_request() at ust-consumer.cpp:518)
DBG1 - 11:27:03.265644304 [Consumer management]: Metadata request received for session 1, key 5 (in ust_consumer_metadata_request() at ust-consumer.cpp:476)
DBG3 - 11:27:03.265670506 [Consumer management]: Buffer registry per UID find id: 1, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:27:03.265694229 [Consumer management]: Buffer registry per PID find id: 3 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG3 - 11:27:03.265713909 [Consumer management]: No metadata to push for metadata key 5 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG1 - 11:27:03.265732980 [Consumer management]: No metadata to push (in ust_app_push_metadata() at ust-app.cpp:723)
DBG2 - 11:27:03.265745010 [Consumer management]: Consumer push metadata to consumer socket 68 (in consumer_push_metadata() at consumer.cpp:1459)
DBG1 - 11:27:03.265818192 [Consumer management]: UST Consumer metadata pushed successfully (in ust_consumer_metadata_request() at ust-consumer.cpp:518)
DBG1 - 11:27:03.265851948 [Consumer management]: Metadata request received for session 1, key 7 (in ust_consumer_metadata_request() at ust-consumer.cpp:476)
DBG3 - 11:27:03.265875816 [Consumer management]: Buffer registry per UID find id: 1, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:27:03.265912324 [Consumer management]: Buffer registry per PID find id: 4 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG3 - 11:27:03.265956235 [Consumer management]: No metadata to push for metadata key 7 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG1 - 11:27:03.265974360 [Consumer management]: No metadata to push (in ust_app_push_metadata() at ust-app.cpp:723)
DBG2 - 11:27:03.265985673 [Consumer management]: Consumer push metadata to consumer socket 68 (in consumer_push_metadata() at consumer.cpp:1459)
DBG1 - 11:27:03.266076395 [Consumer management]: UST Consumer metadata pushed successfully (in ust_consumer_metadata_request() at ust-consumer.cpp:518)
DBG1 - 11:27:03.266447313 [Consumer management]: Metadata request received for session 1, key 5 (in ust_consumer_metadata_request() at ust-consumer.cpp:476)
DBG3 - 11:27:03.266469309 [Consumer management]: Buffer registry per UID find id: 1, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:27:03.266488967 [Consumer management]: Buffer registry per PID find id: 3 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG3 - 11:27:03.266509365 [Consumer management]: No metadata to push for metadata key 5 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG1 - 11:27:03.266527718 [Consumer management]: No metadata to push (in ust_app_push_metadata() at ust-app.cpp:723)
DBG2 - 11:27:03.266539735 [Consumer management]: Consumer push metadata to consumer socket 68 (in consumer_push_metadata() at consumer.cpp:1459)
DBG1 - 11:27:03.266635592 [Consumer management]: UST Consumer metadata pushed successfully (in ust_consumer_metadata_request() at ust-consumer.cpp:518)
DBG1 - 11:27:03.266668220 [Consumer management]: Metadata request received for session 1, key 7 (in ust_consumer_metadata_request() at ust-consumer.cpp:476)
DBG3 - 11:27:03.266691706 [Consumer management]: Buffer registry per UID find id: 1, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.cpp:201)
DBG3 - 11:27:03.266711584 [Consumer management]: Buffer registry per PID find id: 4 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG3 - 11:27:03.266732029 [Consumer management]: No metadata to push for metadata key 7 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG1 - 11:27:03.266750801 [Consumer management]: No metadata to push (in ust_app_push_metadata() at ust-app.cpp:723)
DBG2 - 11:27:03.266763494 [Consumer management]: Consumer push metadata to consumer socket 68 (in consumer_push_metadata() at consumer.cpp:1459)
DBG1 - 11:27:03.266841146 [Consumer management]: UST Consumer metadata pushed successfully (in ust_consumer_metadata_request() at ust-consumer.cpp:518)
DBG1 - 11:27:03.461343726 [Client management]: Wait for client response (in thread_manage_clients() at client.cpp:2534)
DBG1 - 11:27:03.461464419 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.cpp:2562)
DBG1 - 11:27:03.461523181 [Client management]: Processing client command 'DATA_PENDING' (20) (in process_client_msg() at client.cpp:1007)
DBG1 - 11:27:03.461558901 [Client management]: Getting session drHn2XSuuqUB7ASL by name (in process_client_msg() at client.cpp:1122)
DBG2 - 11:27:03.461589061 [Client management]: Trying to find session by name drHn2XSuuqUB7ASL (in session_find_by_name() at session.cpp:1114)
DBG1 - 11:27:03.461619741 [Client management]: Data pending for session drHn2XSuuqUB7ASL (in cmd_data_pending() at cmd.cpp:4032)
DBG3 - 11:27:03.461648129 [Client management]: Consumer data pending for id 1 (in consumer_is_data_pending() at consumer.cpp:1266)
DBG1 - 11:27:03.467047629 [Client management]: Consumer data is NOT pending for session id 1 (in consumer_is_data_pending() at consumer.cpp:1302)
DBG1 - 11:27:03.467104992 [Client management]: Sending response (size: 25, retcode: Success (10)) (in thread_manage_clients() at client.cpp:2652)
DBG1 - 11:27:03.467173060 [Client management]: Accepting client command ... (in thread_manage_clients() at client.cpp:2489)
DBG1 - 11:27:03.467555480 [Client management]: Wait for client response (in thread_manage_clients() at client.cpp:2534)
DBG1 - 11:27:03.467631410 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.cpp:2562)
DBG1 - 11:27:03.467676994 [Client management]: Processing client command 'LIST_SESSIONS' (11) (in process_client_msg() at client.cpp:1007)
DBG1 - 11:27:03.467709710 [Client management]: Counting number of available session for UID 1000 (in lttng_sessions_count() at client.cpp:597)
DBG1 - 11:27:03.467741434 [Client management]: Getting all available session for UID 1000 GID 1000 (in cmd_list_lttng_sessions() at cmd.cpp:3971)
DBG1 - 11:27:03.467780294 [Client management]: Sending response (size: 4409, retcode: Success (10)) (in thread_manage_clients() at client.cpp:2652)
DBG1 - 11:27:03.467838533 [Client management]: Accepting client command ... (in thread_manage_clients() at client.cpp:2489)
DBG1 - 11:27:03.468216969 [Client management]: Wait for client response (in thread_manage_clients() at client.cpp:2534)
DBG1 - 11:27:03.468261517 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.cpp:2562)
DBG1 - 11:27:03.468299492 [Client management]: Processing client command 'LIST_DOMAINS' (9) (in process_client_msg() at client.cpp:1007)
DBG1 - 11:27:03.468330253 [Client management]: Getting session drHn2XSuuqUB7ASL by name (in process_client_msg() at client.cpp:1122)
DBG2 - 11:27:03.468357804 [Client management]: Trying to find session by name drHn2XSuuqUB7ASL (in session_find_by_name() at session.cpp:1114)
DBG3 - 11:27:03.468386222 [Client management]: Listing domains found UST global domain (in cmd_list_domains() at cmd.cpp:3669)
DBG1 - 11:27:03.468409809 [Client management]: Sending response (size: 332, retcode: Success (10)) (in thread_manage_clients() at client.cpp:2652)
DBG1 - 11:27:03.468459089 [Client management]: Accepting client command ... (in thread_manage_clients() at client.cpp:2489)
DBG1 - 11:27:03.468788975 [Client management]: Wait for client response (in thread_manage_clients() at client.cpp:2534)
DBG1 - 11:27:03.468832945 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.cpp:2562)
DBG1 - 11:27:03.468870076 [Client management]: Processing client command 'LIST_CHANNELS' (8) (in process_client_msg() at client.cpp:1007)
DBG1 - 11:27:03.468899905 [Client management]: Getting session drHn2XSuuqUB7ASL by name (in process_client_msg() at client.cpp:1122)
DBG2 - 11:27:03.468926784 [Client management]: Trying to find session by name drHn2XSuuqUB7ASL (in session_find_by_name() at session.cpp:1114)
DBG3 - 11:27:03.468957924 [Client management]: Consumer socket created (fd: 67) and added to output (in consumer_create_socket() at consumer.cpp:347)
DBG1 - 11:27:03.468986152 [Client management]: Setting relayd for session drHn2XSuuqUB7ASL (in cmd_setup_relayd() at cmd.cpp:1029)
DBG1 - 11:27:03.469015435 [Client management]: Listing channels for session drHn2XSuuqUB7ASL (in cmd_list_channels() at cmd.cpp:3744)
DBG3 - 11:27:03.469051680 [Client management]: Consumer discarded events id 1 (in consumer_get_discarded_events() at consumer.cpp:1576)
DBG1 - 11:27:03.469257258 [Client management]: Consumer discarded 0 events in session id 1 (in consumer_get_discarded_events() at consumer.cpp:1617)
DBG3 - 11:27:03.469325636 [Client management]: Consumer discarded events id 1 (in consumer_get_discarded_events() at consumer.cpp:1576)
DBG1 - 11:27:03.469496670 [Client management]: Consumer discarded 0 events in session id 1 (in consumer_get_discarded_events() at consumer.cpp:1617)
DBG1 - 11:27:03.469550136 [Client management]: Sending response (size: 116, retcode: Success (10)) (in thread_manage_clients() at client.cpp:2652)
DBG1 - 11:27:03.469610137 [Client management]: Accepting client command ... (in thread_manage_clients() at client.cpp:2489)
DBG1 - 11:27:03.516916200 [Client management]: Wait for client response (in thread_manage_clients() at client.cpp:2534)
DBG1 - 11:27:03.516987170 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.cpp:2562)
DBG1 - 11:27:03.517021134 [Client management]: Processing client command 'LIST_SESSIONS' (11) (in process_client_msg() at client.cpp:1007)
DBG1 - 11:27:03.517061606 [Client management]: Counting number of available session for UID 1000 (in lttng_sessions_count() at client.cpp:597)
DBG1 - 11:27:03.517084677 [Client management]: Getting all available session for UID 1000 GID 1000 (in cmd_list_lttng_sessions() at cmd.cpp:3971)
DBG1 - 11:27:03.517113412 [Client management]: Sending response (size: 4409, retcode: Success (10)) (in thread_manage_clients() at client.cpp:2652)
DBG1 - 11:27:03.517155762 [Client management]: Accepting client command ... (in thread_manage_clients() at client.cpp:2489)
DBG1 - 11:27:03.517452722 [Client management]: Wait for client response (in thread_manage_clients() at client.cpp:2534)
DBG1 - 11:27:03.517506839 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.cpp:2562)
DBG1 - 11:27:03.517540272 [Client management]: Processing client command 'STOP_TRACE' (15) (in process_client_msg() at client.cpp:1007)
DBG1 - 11:27:03.517562771 [Client management]: Getting session drHn2XSuuqUB7ASL by name (in process_client_msg() at client.cpp:1122)
DBG2 - 11:27:03.517581654 [Client management]: Trying to find session by name drHn2XSuuqUB7ASL (in session_find_by_name() at session.cpp:1114)
DBG1 - 11:27:03.517601086 [Client management]: Begin stop session "drHn2XSuuqUB7ASL" (id 1) (in cmd_stop_trace() at cmd.cpp:2888)
DBG1 - 11:27:03.517621809 [Client management]: Sending response (size: 24, retcode: Tracing has already been stopped (81)) (in thread_manage_clients() at client.cpp:2652)
DBG1 - 11:27:03.517661766 [Client management]: Accepting client command ... (in thread_manage_clients() at client.cpp:2489)
DBG1 - 11:27:03.517854748 [Client management]: Wait for client response (in thread_manage_clients() at client.cpp:2534)
DBG1 - 11:27:03.517994783 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.cpp:2562)
DBG1 - 11:27:03.518030682 [Client management]: Processing client command 'DATA_PENDING' (20) (in process_client_msg() at client.cpp:1007)
DBG1 - 11:27:03.518051603 [Client management]: Getting session drHn2XSuuqUB7ASL by name (in process_client_msg() at client.cpp:1122)
DBG2 - 11:27:03.518069862 [Client management]: Trying to find session by name drHn2XSuuqUB7ASL (in session_find_by_name() at session.cpp:1114)
DBG1 - 11:27:03.518088575 [Client management]: Data pending for session drHn2XSuuqUB7ASL (in cmd_data_pending() at cmd.cpp:4032)
DBG3 - 11:27:03.518106876 [Client management]: Consumer data pending for id 1 (in consumer_is_data_pending() at consumer.cpp:1266)
DBG1 - 11:27:03.520908078 [Client management]: Consumer data is NOT pending for session id 1 (in consumer_is_data_pending() at consumer.cpp:1302)
DBG1 - 11:27:03.520955025 [Client management]: Sending response (size: 25, retcode: Success (10)) (in thread_manage_clients() at client.cpp:2652)
DBG1 - 11:27:03.520998237 [Client management]: Accepting client command ... (in thread_manage_clients() at client.cpp:2489)
DBG1 - 11:27:03.521202703 [Client management]: Wait for client response (in thread_manage_clients() at client.cpp:2534)
DBG1 - 11:27:03.521302616 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.cpp:2562)
DBG1 - 11:27:03.521330804 [Client management]: Processing client command 'DESTROY_SESSION' (7) (in process_client_msg() at client.cpp:1007)
DBG1 - 11:27:03.521348317 [Client management]: Getting session drHn2XSuuqUB7ASL by name (in process_client_msg() at client.cpp:1122)
DBG2 - 11:27:03.521362624 [Client management]: Trying to find session by name drHn2XSuuqUB7ASL (in session_find_by_name() at session.cpp:1114)
DBG1 - 11:27:03.521379055 [Client management]: Begin destroy session drHn2XSuuqUB7ASL (id 1) (in cmd_destroy_session() at cmd.cpp:3419)
DBG3 - 11:27:03.521400287 [Client management]: Buffer registry per PID find id: 3 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG1 - 11:27:03.521415539 [Client management]: Consumer rotate channel key 4 (in consumer_rotate_channel() at consumer.cpp:1699)
DBG3 - 11:27:03.522231901 [Client management]: No metadata to push for metadata key 5 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG1 - 11:27:03.522266132 [Client management]: Consumer rotate channel key 5 (in consumer_rotate_channel() at consumer.cpp:1699)
DBG3 - 11:27:03.522722048 [Client management]: Buffer registry per PID find id: 4 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG1 - 11:27:03.522755988 [Client management]: Consumer rotate channel key 6 (in consumer_rotate_channel() at consumer.cpp:1699)
DBG3 - 11:27:03.523478142 [Client management]: No metadata to push for metadata key 7 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG1 - 11:27:03.523498448 [Client management]: Consumer rotate channel key 7 (in consumer_rotate_channel() at consumer.cpp:1699)
DBG1 - 11:27:03.523869746 [Client management]: Setting trace chunk close command to "no operation" (in lttng_trace_chunk_set_close_command() at trace-chunk.cpp:1719)
DBG1 - 11:27:03.523889779 [Client management]: lttng_trace_chunk_rename_path from to (in lttng_trace_chunk_rename_path_no_lock() at trace-chunk.cpp:732)
DBG1 - 11:27:03.523912099 [Client management]: Sending consumer close trace chunk command: relayd_id = 3, session_id = 1, chunk_id = 0, close command = "none" (in consumer_close_trace_chunk() at consumer.cpp:2038)
DBG1 - 11:27:03.524247123 [Client management]: Enabling session rotation pending check timer on session 1 (in timer_session_rotation_pending_check_start() at timer.cpp:211)
DBG1 - 11:27:03.524272311 [Client management]: Cmd rotate session drHn2XSuuqUB7ASL, archive_id 0 sent (in cmd_rotate_session() at cmd.cpp:5627)
DBG1 - 11:27:03.524288439 [Client management]: Accepting client command ... (in thread_manage_clients() at client.cpp:2489)
DBG1 - 11:27:03.578100430 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:27:03.578162204 [Notification]: Handling fd (11) activity (1) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:27:03.578210829 [Notification]: Handling channel sample for channel chan (key = 6) in session drHn2XSuuqUB7ASL (highest usage = 0, lowest usage = 0, consumed since last sample = 420) (in handle_notification_thread_channel_sample() at notification-thread-events.cpp:4944)
DBG1 - 11:27:03.578253889 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG1 - 11:27:03.860061197 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:27:03.860135808 [Notification]: Handling fd (11) activity (1) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:27:03.860188344 [Notification]: Handling channel sample for channel chan (key = 4) in session drHn2XSuuqUB7ASL (highest usage = 0, lowest usage = 0, consumed since last sample = 420) (in handle_notification_thread_channel_sample() at notification-thread-events.cpp:4944)
DBG1 - 11:27:03.860231066 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG1 - 11:27:04.024515184 [Rotation]: Poll wait returned: ret=1 (in _run() at rotation-thread.cpp:734)
DBG1 - 11:27:04.024619273 [Rotation]: Handling descriptor activity: fd=9, events=1 (in _run() at rotation-thread.cpp:752)
DBG1 - 11:27:04.024649739 [Rotation]: Checking for pending rotation on session "drHn2XSuuqUB7ASL", trace archive 0 (in check_session_rotation_pending() at rotation-thread.cpp:234)
DBG1 - 11:27:04.024685841 [Rotation]: Disabling session rotation pending check timer on session 1 (in timer_session_rotation_pending_check_stop() at timer.cpp:242)
DBG1 - 11:27:04.024913997 [Rotation]: Sending consumer trace chunk exists command: relayd_id = 3, session_id = 1, chunk_id = 0 (in consumer_trace_chunk_exists() at consumer.cpp:2137)
DBG1 - 11:27:04.025795727 [Rotation]: Consumer ret code -128 (in consumer_recv_status_reply() at consumer.cpp:202)
DBG1 - 11:27:04.025869014 [Rotation]: Consumer reply to TRACE_CHUNK_EXISTS command: unknown trace chunk (in consumer_trace_chunk_exists() at consumer.cpp:2163)
DBG1 - 11:27:04.025987609 [Rotation]: Rotation of trace archive 0 of session "drHn2XSuuqUB7ASL" is complete on all consumers (in check_session_rotation_pending_on_consumers() at rotation-thread.cpp:195)
DBG3 - 11:27:04.026032366 [Rotation]: No kernel session when tearing down session (in kernel_destroy_session() at kernel.cpp:1600)
DBG2 - 11:27:04.026066233 [Rotation]: Sending destroy relayd command to consumer sock 67 (in consumer_send_destroy_relayd() at consumer.cpp:260)
DBG2 - 11:27:04.026241099 [Rotation]: Consumer send destroy relayd command done (in consumer_send_destroy_relayd() at consumer.cpp:275)
DBG1 - 11:27:04.026295646 [Rotation]: Destroy all UST traces (in ust_app_destroy_trace_all() at ust-app.cpp:5907)
DBG1 - 11:27:04.026318685 [Rotation]: Destroy tracing for ust app pid 2152177 (in destroy_trace() at ust-app.cpp:5782)
DBG3 - 11:27:04.026347096 [Rotation]: Buffer registry per PID find id: 3 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG3 - 11:27:04.026371022 [Rotation]: No metadata to push for metadata key 5 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG3 - 11:27:04.026394411 [Rotation]: UST app deleting channel chan (in delete_ust_app_channel() at ust-app.cpp:575)
DBG1 - 11:27:04.026633042 [Rotation]: Beginning of waiter "wait" period (in wait() at waiter.cpp:48)
DBG1 - 11:27:04.026677105 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:27:04.026755728 [Notification]: Handling fd (23) activity (1) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:27:04.026802731 [Notification]: Received `REMOVE_CHANNEL` command (in handle_notification_thread_command() at notification-thread-events.cpp:3191)
DBG1 - 11:27:04.026837157 [Notification]: Removing channel key = 4 in ust domain (in handle_notification_thread_command_remove_channel() at notification-thread-events.cpp:1866)
DBG1 - 11:27:04.026903910 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG1 - 11:27:04.026904849 [Rotation]: End of waiter "wait" period (in wait() at waiter.cpp:109)
DBG3 - 11:27:04.026985242 [Rotation]: Session 1 found by id. (in session_find_by_id() at session.cpp:1152)
DBG2 - 11:27:04.027261980 [Rotation]: Consumer close metadata channel key 5 (in consumer_close_metadata() at consumer.cpp:1388)
DBG3 - 11:27:04.027543742 [Rotation]: Buffer registry per PID find id: 3 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG3 - 11:27:04.027611364 [Rotation]: Buffer registry per PID destroy with id: 3 (in buffer_reg_pid_destroy() at buffer-registry.cpp:726)
DBG1 - 11:27:04.028561820 [Rotation]: Destroy tracing for ust app pid 2152252 (in destroy_trace() at ust-app.cpp:5782)
DBG3 - 11:27:04.028634977 [Rotation]: Buffer registry per PID find id: 4 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG3 - 11:27:04.028666195 [Rotation]: No metadata to push for metadata key 7 (in ust_app_push_metadata() at ust-app.cpp:719)
DBG3 - 11:27:04.028692165 [Rotation]: UST app deleting channel chan (in delete_ust_app_channel() at ust-app.cpp:575)
DBG1 - 11:27:04.028932923 [Rotation]: Beginning of waiter "wait" period (in wait() at waiter.cpp:48)
DBG1 - 11:27:04.028976619 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:27:04.029133158 [Notification]: Handling fd (23) activity (1) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:27:04.029183384 [Notification]: Received `REMOVE_CHANNEL` command (in handle_notification_thread_command() at notification-thread-events.cpp:3191)
DBG1 - 11:27:04.029218280 [Notification]: Removing channel key = 6 in ust domain (in handle_notification_thread_command_remove_channel() at notification-thread-events.cpp:1866)
DBG1 - 11:27:04.029277237 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG1 - 11:27:04.029321588 [Rotation]: End of waiter "wait" period (in wait() at waiter.cpp:109)
DBG3 - 11:27:04.029366678 [Rotation]: Session 1 found by id. (in session_find_by_id() at session.cpp:1152)
DBG2 - 11:27:04.029645279 [Rotation]: Consumer close metadata channel key 7 (in consumer_close_metadata() at consumer.cpp:1388)
DBG3 - 11:27:04.030890012 [Rotation]: Buffer registry per PID find id: 4 (in buffer_reg_pid_find() at buffer-registry.cpp:318)
DBG3 - 11:27:04.030941982 [Rotation]: Buffer registry per PID destroy with id: 4 (in buffer_reg_pid_destroy() at buffer-registry.cpp:726)
DBG2 - 11:27:04.031636094 [Rotation]: Trace UST destroy session 1 (in trace_ust_destroy_session() at trace-ust.cpp:1415)
DBG1 - 11:27:04.031727603 [Rotation]: Destroying session drHn2XSuuqUB7ASL (id 1) (in session_release() at session.cpp:986)
DBG1 - 11:27:04.031805800 [Rotation]: Empty ltt_sessions_ht_by_id/name, destroying hast tables (in del_session_ht() at session.cpp:441)
DBG1 - 11:27:04.031865124 [Rotation]: Beginning of waiter "wait" period (in wait() at waiter.cpp:48)
DBG1 - 11:27:04.031884807 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:27:04.031955279 [Notification]: Handling fd (23) activity (1) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:27:04.031995113 [Notification]: Received `REMOVE_SESSION` command (in handle_notification_thread_command() at notification-thread-events.cpp:3191)
DBG1 - 11:27:04.032023905 [Notification]: Removing session: session id = 1 (in handle_notification_thread_command_remove_session() at notification-thread-events.cpp:1824)
DBG1 - 11:27:04.032073350 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG1 - 11:27:04.032073486 [Rotation]: End of waiter "wait" period (in wait() at waiter.cpp:109)
DBG1 - 11:27:04.032140198 [Rotation]: No implicit rotation performed during the destruction of session "drHn2XSuuqUB7ASL", sending reply (in cmd_destroy_session_reply() at cmd.cpp:3352)
DBG1 - 11:27:04.032284191 [Rotation]: Entering poll wait (in _run() at rotation-thread.cpp:732)
DBG3 - 11:27:04.037214246 [2152012/2152074]: Buffer registry session destroy (in buffer_reg_session_destroy() at buffer-registry.cpp:590)
DBG3 - 11:27:04.037345330 [2152012/2152074]: Buffer registry session destroy (in buffer_reg_session_destroy() at buffer-registry.cpp:590)
DBG2 - 11:27:04.037394108 [2152012/2152074]: Trace destroy UST event tp:tptest (in trace_ust_destroy_event() at trace-ust.cpp:1235)
DBG2 - 11:27:04.037424503 [2152012/2152074]: Trace destroy UST channel chan (in _trace_ust_destroy_channel() at trace-ust.cpp:1300)
DBG1 - 11:27:04.042838493 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:27:04.042902575 [Notification]: Handling fd (71) activity (16) (in thread_notification() at notification-thread.cpp:668)
DBG3 - 11:27:04.042936693 [Notification]: Removing tracer event source from poll set: tracer_event_source_fd = 71, domain = 'ust' (in remove_tracer_event_source_from_pollset() at notification-thread-events.cpp:2170)
DBG1 - 11:27:04.043016502 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG3 - 11:27:04.043651604 [Application notification]: [ust-thread] Manage notify return from poll on 4 fds (in thread_application_notification() at notify-apps.cpp:81)
DBG3 - 11:27:04.043726304 [Application notification]: UST app receiving notify from sock 70 (in ust_app_recv_notify() at ust-app.cpp:6900)
DBG1 - 11:27:04.043659182 [UST application management]: Apps thread return from poll on 4 fds (in thread_application_management() at manage-apps.cpp:96)
DBG1 - 11:27:04.043842180 [UST application management]: Application unregistering after socket activity: pid=2152252, socket_fd=62 (in ust_app_unregister_by_socket() at ust-app.cpp:4452)
DBG3 - 11:27:04.043765835 [Application notification]: UST app recv notify failed. Application died: sock = 70 (in ust_app_recv_notify() at ust-app.cpp:6905)
DBG1 - 11:27:04.043886438 [UST application management]: Apps thread polling (in thread_application_management() at manage-apps.cpp:90)
DBG1 - 11:27:04.043963238 [Application notification]: UST app notify socket unregister 70 (in ust_app_notify_sock_unregister() at ust-app.cpp:7103)
DBG2 - 11:27:04.044066130 [Application notification]: UST app find by notify sock 70 not found (in find_app_by_notify_sock() at ust-app.cpp:1483)
DBG3 - 11:27:04.044099290 [Application notification]: [ust-thread] Manage notify polling (in thread_application_notification() at notify-apps.cpp:75)
DBG3 - 11:27:04.047626157 [2152012/2152074]: Call RCU deleting app PID 2152252 (in delete_ust_app_rcu() at ust-app.cpp:1129)
DBG1 - 11:27:04.047715395 [2152012/2152074]: Beginning of waiter "wait" period (in wait() at waiter.cpp:48)
DBG1 - 11:27:04.047794379 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:27:04.047849068 [Notification]: Handling fd (23) activity (1) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:27:04.047888747 [Notification]: Received `REMOVE_TRACER_EVENT_SOURCE` command (in handle_notification_thread_command() at notification-thread-events.cpp:3191)
DBG1 - 11:27:04.047923923 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG1 - 11:27:04.047924214 [2152012/2152074]: End of waiter "wait" period (in wait() at waiter.cpp:109)
DBG2 - 11:27:04.048063903 [2152012/2152074]: UST app pid 2152252 deleted (in delete_ust_app() at ust-app.cpp:1115)
DBG1 - 11:27:04.063107699 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:27:04.063203017 [Notification]: Handling fd (53) activity (16) (in thread_notification() at notification-thread.cpp:668)
DBG3 - 11:27:04.063240067 [Notification]: Removing tracer event source from poll set: tracer_event_source_fd = 53, domain = 'ust' (in remove_tracer_event_source_from_pollset() at notification-thread-events.cpp:2170)
DBG1 - 11:27:04.063320103 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG3 - 11:27:04.063918498 [Application notification]: [ust-thread] Manage notify return from poll on 3 fds (in thread_application_notification() at notify-apps.cpp:81)
DBG3 - 11:27:04.063998753 [Application notification]: UST app receiving notify from sock 52 (in ust_app_recv_notify() at ust-app.cpp:6900)
DBG3 - 11:27:04.064038254 [Application notification]: UST app recv notify failed. Application died: sock = 52 (in ust_app_recv_notify() at ust-app.cpp:6905)
DBG1 - 11:27:04.064077393 [Application notification]: UST app notify socket unregister 52 (in ust_app_notify_sock_unregister() at ust-app.cpp:7103)
DBG1 - 11:27:04.063955006 [UST application management]: Apps thread return from poll on 3 fds (in thread_application_management() at manage-apps.cpp:96)
DBG3 - 11:27:04.064139758 [Application notification]: [ust-thread] Manage notify polling (in thread_application_notification() at notify-apps.cpp:75)
DBG1 - 11:27:04.064218362 [UST application management]: Application unregistering after socket activity: pid=2152177, socket_fd=51 (in ust_app_unregister_by_socket() at ust-app.cpp:4452)
DBG1 - 11:27:04.064265148 [UST application management]: Apps thread polling (in thread_application_management() at manage-apps.cpp:90)
DBG3 - 11:27:04.074355097 [2152012/2152074]: Call RCU deleting app PID 2152177 (in delete_ust_app_rcu() at ust-app.cpp:1129)
DBG1 - 11:27:04.074486332 [2152012/2152074]: Beginning of waiter "wait" period (in wait() at waiter.cpp:48)
DBG1 - 11:27:04.074546776 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:27:04.074608210 [Notification]: Handling fd (23) activity (1) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:27:04.074650996 [Notification]: Received `REMOVE_TRACER_EVENT_SOURCE` command (in handle_notification_thread_command() at notification-thread-events.cpp:3191)
DBG1 - 11:27:04.074689209 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG1 - 11:27:04.074689725 [2152012/2152074]: End of waiter "wait" period (in wait() at waiter.cpp:109)
DBG2 - 11:27:04.074879577 [2152012/2152074]: UST app pid 2152177 deleted (in delete_ust_app() at ust-app.cpp:1115)
DBG1 - 11:27:04.151200682 [Run-as worker]: run_as worker received signal SIGTERM (in worker_sighandler() at runas.cpp:1353)
DBG1 - 11:27:04.151227097 [Main]: SIGTERM caught (in sighandler() at main.cpp:1150)
DBG1 - 11:27:04.151243486 [Main]: Notify the main thread to terminate all worker threads (in notify_main_quit_pipe() at main.cpp:178)
DBG1 - 11:27:04.151267420 [Main]: Terminating all threads (in _main() at main.cpp:1874)
DBG1 - 11:27:04.151273665 [Main]: Shutting down "Client management" thread (in _lttng_thread_shutdown() at thread.cpp:152)
DBG1 - 11:27:04.151325298 [Client management]: Activity on thread quit pipe (in thread_manage_clients() at client.cpp:2517)
DBG1 - 11:27:04.151384535 [Client management]: Client thread dying (in thread_manage_clients() at client.cpp:2698)
DBG1 - 11:27:04.151396004 [Client management]: Thread entry point has returned (in launch_thread() at thread.cpp:68)
DBG1 - 11:27:04.151463767 [Main]: Joined thread "Client management" (in _lttng_thread_shutdown() at thread.cpp:167)
DBG1 - 11:27:04.151486573 [Main]: Initiating destruction of all sessions (in destroy_all_sessions_and_wait() at main.cpp:1288)
DBG1 - 11:27:04.151493235 [Main]: Waiting for the destruction of all sessions to complete (in destroy_all_sessions_and_wait() at main.cpp:1314)
DBG1 - 11:27:04.151500779 [Main]: Destruction of all sessions completed (in destroy_all_sessions_and_wait() at main.cpp:1316)
DBG1 - 11:27:04.151505355 [Main]: Unregistering all triggers (in unregister_all_triggers() at main.cpp:1330)
DBG1 - 11:27:04.151514318 [Main]: Beginning of waiter "wait" period (in wait() at waiter.cpp:48)
DBG1 - 11:27:04.151558345 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:27:04.151571272 [Notification]: Handling fd (23) activity (1) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:27:04.151581889 [Notification]: Received `LIST_TRIGGERS` command (in handle_notification_thread_command() at notification-thread-events.cpp:3191)
DBG1 - 11:27:04.151594137 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG1 - 11:27:04.151629032 [Main]: End of waiter "wait" period (in wait() at waiter.cpp:109)
DBG1 - 11:27:04.151641285 [Main]: Shutting down "UST application registration" thread (in _lttng_thread_shutdown() at thread.cpp:152)
DBG1 - 11:27:04.151704600 [UST application registration]: Notifying applications of session daemon state: 0 (in notify_ust_apps() at register.cpp:92)
DBG1 - 11:27:04.151738281 [UST application registration]: Wait shared memory file descriptor created successfully: path = '/lttng-ust-wait-8-1000', mmap_size = 4096, global = false, fd = 32 (in get_wait_shm() at shm.cpp:139)
DBG1 - 11:27:04.151762684 [UST application registration]: Futex wait update active 0 (in futex_wait_update() at futex.cpp:53)
DBG1 - 11:27:04.151795153 [UST application registration]: UST Registration thread cleanup complete (in thread_application_registration() at register.cpp:368)
DBG1 - 11:27:04.151805268 [UST application registration]: Thread entry point has returned (in launch_thread() at thread.cpp:68)
DBG1 - 11:27:04.151862928 [Main]: Joined thread "UST application registration" (in _lttng_thread_shutdown() at thread.cpp:167)
DBG1 - 11:27:04.151884322 [Main]: Shutting down "Consumer management" thread (in _lttng_thread_shutdown() at thread.cpp:152)
DBG1 - 11:27:04.151995212 [Consumer management]: consumer thread cleanup completed (in thread_consumer_management() at manage-consumer.cpp:404)
DBG1 - 11:27:04.152010412 [Consumer management]: Thread entry point has returned (in launch_thread() at thread.cpp:68)
DBG1 - 11:27:04.152095081 [Main]: Joined thread "Consumer management" (in _lttng_thread_shutdown() at thread.cpp:167)
DBG1 - 11:27:04.152107783 [Main]: Shutting down "Agent management" thread (in _lttng_thread_shutdown() at thread.cpp:152)
DBG3 - 11:27:04.152170034 [Agent management]: Manage agent return from poll on 2 fds (in thread_agent_management() at agent-thread.cpp:420)
DBG3 - 11:27:04.152193270 [Agent management]: 1 fd ready (in thread_agent_management() at agent-thread.cpp:431)
DBG1 - 11:27:04.152198538 [Agent management]: Activity on thread quit pipe (in thread_agent_management() at agent-thread.cpp:440)
DBG3 - 11:27:04.152208134 [Agent management]: Destroy TCP socket on port 5345 (in destroy_tcp_socket() at agent-thread.cpp:204)
DBG1 - 11:27:04.152220341 [Agent management]: Cleaning up and stopping. (in thread_agent_management() at agent-thread.cpp:536)
DBG1 - 11:27:04.152226137 [Agent management]: Thread entry point has returned (in launch_thread() at thread.cpp:68)
DBG1 - 11:27:04.152281393 [Main]: Joined thread "Agent management" (in _lttng_thread_shutdown() at thread.cpp:167)
DBG1 - 11:27:04.152293958 [Main]: Shutting down "Application notification" thread (in _lttng_thread_shutdown() at thread.cpp:152)
DBG3 - 11:27:04.152313282 [Application notification]: [ust-thread] Manage notify return from poll on 2 fds (in thread_application_notification() at notify-apps.cpp:81)
DBG1 - 11:27:04.152323257 [Application notification]: Activity on thread quit pipe (in thread_application_notification() at notify-apps.cpp:105)
DBG1 - 11:27:04.152334474 [Application notification]: Application notify communication apps thread cleanup complete (in thread_application_notification() at notify-apps.cpp:194)
DBG1 - 11:27:04.152343096 [Application notification]: Thread entry point has returned (in launch_thread() at thread.cpp:68)
DBG1 - 11:27:04.152412915 [Main]: Joined thread "Application notification" (in _lttng_thread_shutdown() at thread.cpp:167)
DBG1 - 11:27:04.152421442 [Main]: Shutting down "UST application management" thread (in _lttng_thread_shutdown() at thread.cpp:152)
DBG1 - 11:27:04.152494735 [UST application management]: Apps thread return from poll on 2 fds (in thread_application_management() at manage-apps.cpp:96)
DBG1 - 11:27:04.152511477 [UST application management]: Activity on thread quit pipe (in thread_application_management() at manage-apps.cpp:119)
DBG1 - 11:27:04.152525732 [UST application management]: Application communication apps thread cleanup complete (in thread_application_management() at manage-apps.cpp:200)
DBG1 - 11:27:04.152534569 [UST application management]: Thread entry point has returned (in launch_thread() at thread.cpp:68)
DBG1 - 11:27:04.152634392 [Main]: Joined thread "UST application management" (in _lttng_thread_shutdown() at thread.cpp:167)
DBG1 - 11:27:04.152641162 [Main]: Shutting down "UST registration dispatch" thread (in _lttng_thread_shutdown() at thread.cpp:152)
DBG1 - 11:27:04.152651200 [Main]: Futex n to 1 wake done (in futex_nto1_wake() at futex.cpp:116)
DBG1 - 11:27:04.152656933 [UST registration dispatch]: Futex n to 1 wait done (in futex_nto1_wait() at futex.cpp:100)
DBG1 - 11:27:04.152664211 [UST registration dispatch]: Futex n to 1 prepare done (in futex_nto1_prepare() at futex.cpp:64)
DBG1 - 11:27:04.152669878 [UST registration dispatch]: Dispatch thread dying (in thread_dispatch_ust_registration() at dispatch.cpp:478)
DBG1 - 11:27:04.152677442 [UST registration dispatch]: Thread entry point has returned (in launch_thread() at thread.cpp:68)
DBG1 - 11:27:04.152708087 [Main]: Joined thread "UST registration dispatch" (in _lttng_thread_shutdown() at thread.cpp:167)
DBG1 - 11:27:04.152714521 [Main]: Shutting down "Rotation" thread (in _lttng_thread_shutdown() at thread.cpp:152)
DBG1 - 11:27:04.152731927 [Rotation]: Poll wait returned: ret=1 (in _run() at rotation-thread.cpp:734)
DBG1 - 11:27:04.152740071 [Rotation]: Handling descriptor activity: fd=27, events=1 (in _run() at rotation-thread.cpp:752)
DBG1 - 11:27:04.152745450 [Rotation]: Quit pipe activity (in _run() at rotation-thread.cpp:798)
DBG1 - 11:27:04.152750454 [Rotation]: Thread exit (in _thread_function() at rotation-thread.cpp:710)
DBG1 - 11:27:04.152755029 [Rotation]: Thread entry point has returned (in launch_thread() at thread.cpp:68)
DBG1 - 11:27:04.152783520 [Main]: Joined thread "Rotation" (in _lttng_thread_shutdown() at thread.cpp:167)
DBG1 - 11:27:04.152796190 [Main]: Shutting down "Timer" thread (in _lttng_thread_shutdown() at thread.cpp:152)
DBG1 - 11:27:04.152843564 [Timer]: Thread exit (in thread_timer() at timer.cpp:403)
DBG1 - 11:27:04.152856469 [Timer]: Thread entry point has returned (in launch_thread() at thread.cpp:68)
DBG1 - 11:27:04.152883683 [Main]: Joined thread "Timer" (in _lttng_thread_shutdown() at thread.cpp:167)
DBG1 - 11:27:04.152891021 [Main]: Shutting down "Health management" thread (in _lttng_thread_shutdown() at thread.cpp:152)
DBG1 - 11:27:04.152930646 [Health management]: Activity on thread quit pipe (in thread_manage_health() at health.cpp:163)
DBG1 - 11:27:04.152938580 [Health management]: Health check thread dying (in thread_manage_health() at health.cpp:234)
DBG1 - 11:27:04.152975837 [Health management]: Thread entry point has returned (in launch_thread() at thread.cpp:68)
DBG1 - 11:27:04.153012949 [Main]: Joined thread "Health management" (in _lttng_thread_shutdown() at thread.cpp:167)
DBG1 - 11:27:04.163190484 [Main]: Cleanup sessiond (in sessiond_cleanup() at main.cpp:281)
DBG1 - 11:27:04.163267790 [Main]: Removing sessiond and consumerd content of directory /home/kstewart/src/efficios/lttng/master/home/.lttng (in sessiond_cleanup() at main.cpp:299)
DBG1 - 11:27:04.163279022 [Main]: Removing /home/kstewart/src/efficios/lttng/master/home/.lttng/lttng-sessiond.pid (in sessiond_cleanup() at main.cpp:302)
DBG1 - 11:27:04.163289463 [Main]: Removing /home/kstewart/src/efficios/lttng/master/home/.lttng/agent.port (in sessiond_cleanup() at main.cpp:305)
DBG1 - 11:27:04.163311288 [Main]: Removing /home/kstewart/src/efficios/lttng/master/home/.lttng/kconsumerd/error (in sessiond_cleanup() at main.cpp:309)
DBG1 - 11:27:04.163322382 [Main]: Removing directory /home/kstewart/src/efficios/lttng/master/home/.lttng/kconsumerd (in sessiond_cleanup() at main.cpp:312)
DBG1 - 11:27:04.163333475 [Main]: Removing /home/kstewart/src/efficios/lttng/master/home/.lttng/ustconsumerd32/error (in sessiond_cleanup() at main.cpp:316)
DBG1 - 11:27:04.163350746 [Main]: Removing directory /home/kstewart/src/efficios/lttng/master/home/.lttng/ustconsumerd32 (in sessiond_cleanup() at main.cpp:319)
DBG1 - 11:27:04.163366528 [Main]: Removing /home/kstewart/src/efficios/lttng/master/home/.lttng/ustconsumerd64/error (in sessiond_cleanup() at main.cpp:323)
DBG1 - 11:27:04.163376368 [Main]: Removing directory /home/kstewart/src/efficios/lttng/master/home/.lttng/ustconsumerd64 (in sessiond_cleanup() at main.cpp:326)
DBG1 - 11:27:04.163391748 [Main]: Cleaning up all per-event notifier domain agents (in sessiond_cleanup() at main.cpp:331)
DBG1 - 11:27:04.163401561 [Main]: Cleaning up all agent apps (in sessiond_cleanup() at main.cpp:334)
DBG1 - 11:27:04.163406878 [Main]: Closing all UST sockets (in sessiond_cleanup() at main.cpp:336)
DBG2 - 11:27:04.163411613 [Main]: UST app cleaning registered apps hash table (in ust_app_clean_list() at ust-app.cpp:4790)
DBG3 - 11:27:04.163418063 [Main]: Buffer registry destroy all registry (in buffer_reg_destroy_registries() at buffer-registry.cpp:737)
DBG1 - 11:27:04.163456884 [Main]: Waiting for complete teardown of consumerd (PID: 2152064) (in wait_consumer() at main.cpp:263)
DBG1 - 11:27:04.194209222 [Notification]: Poll wait returned (2) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:27:04.194233961 [Notification]: Handling fd (11) activity (16) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:27:04.194247928 [Notification]: Handling fd (7) activity (16) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:27:04.194257181 [Notification]: Entering poll wait (in thread_notification() at notification-thread.cpp:642)
DBG1 - 11:27:04.204398189 [Main]: Shutting down "Notification" thread (in _lttng_thread_shutdown() at thread.cpp:152)
DBG1 - 11:27:04.204428808 [Main]: Beginning of waiter "wait" period (in wait() at waiter.cpp:48)
DBG1 - 11:27:04.204475039 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.cpp:644)
DBG1 - 11:27:04.204499985 [Notification]: Handling fd (23) activity (1) (in thread_notification() at notification-thread.cpp:668)
DBG1 - 11:27:04.204510963 [Notification]: Received `QUIT` command (in handle_notification_thread_command() at notification-thread-events.cpp:3191)
DBG1 - 11:27:04.204521753 [Notification]: Closing all client connections (in handle_notification_thread_client_disconnect_all() at notification-thread-events.cpp:3522)
DBG1 - 11:27:04.204569303 [Main]: End of waiter "wait" period (in wait() at waiter.cpp:109)
DBG1 - 11:27:04.204575406 [Notification]: Destroying notification channel socket (in notification_channel_socket_destroy() at notification-thread.cpp:201)
DBG1 - 11:27:04.204637001 [Notification]: Shutting down "Action Executor" thread (in _lttng_thread_shutdown() at thread.cpp:152)
DBG1 - 11:27:04.204703128 [Action Executor]: Woke-up from wait (in action_executor_thread() at action-executor.cpp:753)
DBG1 - 11:27:04.204718706 [Action Executor]: Left work execution loop (in action_executor_thread() at action-executor.cpp:809)
DBG1 - 11:27:04.204725345 [Action Executor]: Thread entry point has returned (in launch_thread() at thread.cpp:68)
DBG1 - 11:27:04.204804808 [Notification]: Joined thread "Action Executor" (in _lttng_thread_shutdown() at thread.cpp:167)
DBG1 - 11:27:04.204825214 [Notification]: Thread entry point has returned (in launch_thread() at thread.cpp:68)
DBG1 - 11:27:04.204971577 [Main]: Joined thread "Notification" (in _lttng_thread_shutdown() at thread.cpp:167)
DBG1 - 11:27:04.205035659 [Main]: Cleaning up options (in sessiond_cleanup_options() at main.cpp:362)
DBG1 - 11:27:04.205045842 [Main]: Destroying run_as worker (in run_as_destroy_worker_no_lock() at runas.cpp:1518)
DBG1 - 11:27:04.205051358 [Main]: Closing run_as worker socket (in run_as_destroy_worker_no_lock() at runas.cpp:1523)
DBG1 - 11:27:04.205122343 [Run-as worker]: run_as worker exiting (ret = 0) (in run_as_create_worker_no_lock() at runas.cpp:1470)
DBG1 - 11:27:04.205697287 [Main]: lttng-runas terminated with status code 0 (in run_as_destroy_worker_no_lock() at runas.cpp:1543)
(3-3/5)