LTTng » LTTng-tools

Mar 26 10:24:53 dorsal-vm2 systemd[1]: Started LTTng session daemon.

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: libringbuffer-clients[54505/54505]: LTT : ltt ring buffer client "relay-metadata-mmap" init

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: (in lttng_ring_buffer_metadata_client_init() at ../../src/common/ringbuffer-clients/metadata-template.h:364)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: libringbuffer-clients[54505/54505]: LTT : ltt ring buffer client "relay-overwrite-mmap" init

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: (in lttng_ring_buffer_client_overwrite_init() at ../../src/common/ringbuffer-clients/template.h:826)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: libringbuffer-clients[54505/54505]: LTT : ltt ring buffer client "relay-overwrite-rt-mmap" init

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: (in lttng_ring_buffer_client_overwrite_rt_init() at ../../src/common/ringbuffer-clients/template.h:826)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: libringbuffer-clients[54505/54505]: LTT : ltt ring buffer client "relay-discard-mmap" init

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: (in lttng_ring_buffer_client_discard_init() at ../../src/common/ringbuffer-clients/template.h:826)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: libringbuffer-clients[54505/54505]: LTT : ltt ring buffer client "relay-discard-rt-mmap" init

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: (in lttng_ring_buffer_client_discard_rt_init() at ../../src/common/ringbuffer-clients/template.h:826)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.757301188 [Main]: [sessiond configuration]

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.757380486 [Main]: version 2.13.11

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.757389554 [Main]: verbose: 3

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.757397088 [Main]: verbose consumer: 1

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.757404405 [Main]: quiet mode: False

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.757421914 [Main]: agent_tcp_port: [5345, 5354]

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.757430477 [Main]: application socket timeout: 5

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.757439091 [Main]: no-kernel: False

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.757446900 [Main]: background: False

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.757454233 [Main]: daemonize: False

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.757461444 [Main]: signal parent on start: False

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.757468412 [Main]: tracing group name: tracing

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.757475903 [Main]: kmod_probe_list: None

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.757483462 [Main]: kmod_extra_probe_list: None

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.757490662 [Main]: rundir: /var/run/lttng

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.757497700 [Main]: application socket path: /var/run/lttng/lttng-ust-sock-8

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.757504982 [Main]: client socket path: /var/run/lttng/client-lttng-sessiond

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.757512255 [Main]: wait shm path: /lttng-ust-wait-8

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.757519587 [Main]: health socket path: /var/run/lttng/sessiond-health

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.757526904 [Main]: LTTNG_UST_CLOCK_PLUGIN: None

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.757544660 [Main]: pid file path: /var/run/lttng/lttng-sessiond.pid

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.757552319 [Main]: lock file path: /var/run/lttng/lttng-sessiond.lck

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.757559572 [Main]: session load path: None

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.757566975 [Main]: agent port file path: /var/run/lttng/agent.port

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.757574433 [Main]: consumerd32 path: /var/run/lttng/ustconsumerd32

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.757581388 [Main]: consumerd32 bin path: Unknown

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.757588950 [Main]: consumerd32 lib dir: Unknown

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.757596139 [Main]: consumerd32 err unix sock path:/var/run/lttng/ustconsumerd32/error

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.757603186 [Main]: consumerd32 cmd unix sock path:/var/run/lttng/ustconsumerd32/command

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.757610979 [Main]: consumerd64 path: /var/run/lttng/ustconsumerd64

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.757618581 [Main]: consumerd64 bin path: /usr/lib/x86_64-linux-gnu/lttng/libexec/lttng-consumerd

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.757626867 [Main]: consumerd64 lib dir: /usr/lib/x86_64-linux-gnu

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.757633972 [Main]: consumerd64 err unix sock path:/var/run/lttng/ustconsumerd64/error

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.757660058 [Main]: consumerd64 cmd unix sock path:/var/run/lttng/ustconsumerd64/command

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.757667711 [Main]: kconsumerd path: /var/run/lttng/kconsumerd

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.757689603 [Main]: kconsumerd err unix sock path: /var/run/lttng/kconsumerd/error

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.757697118 [Main]: kconsumerd cmd unix sock path: /var/run/lttng/kconsumerd/command

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.757716879 [Main]: Starting lttng-sessiond {e196cba6-8a9c-45e5-82fc-8edd9fe7c9d1} (in sessiond_uuid_log() at main.c:1437)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:24:53.757725791 [Main]: Creating LTTng run directory: /var/run/lttng (in create_lttng_rundir() at main.c:1069)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54506]: DBG1 - 10:24:53.758736470 [Main]: Resetting run_as worker signal handlers to default (in reset_sighandler() at runas.c:1377)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54506]: DBG1 - 10:24:53.758966045 [Main]: run_as signal handler set for SIGTERM and SIGINT (in set_worker_sighandlers() at runas.c:1438)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.761006978 [Main]: Health check time delta in seconds set to 20 (in health_init() at health.c:62)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.761456157 [HT cleanup]: Entering thread entry point (in launch_thread() at thread.c:65)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.761538631 [HT cleanup]: startup. (in thread_ht_cleanup() at ht-cleanup.c:98)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.761692056 [HT cleanup]: epoll set max size is 1783184 (in compat_epoll_set_max_size() at poll.c:350)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:24:53.761744137 [Main]: Created hashtable size 4 at 0x55ee6abb91d0 of type ULONG (in lttng_ht_new() at hashtable.c:152)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:24:53.761834238 [Main]: Created hashtable size 4 at 0x55ee6abb98d0 of type ULONG (in lttng_ht_new() at hashtable.c:152)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:24:53.761859850 [Main]: Created hashtable size 4 at 0x55ee6abba040 of type ULONG (in lttng_ht_new() at hashtable.c:152)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:24:53.761833972 [HT cleanup]: Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:24:53.761921645 [Main]: Created hashtable size 16 at 0x55ee6abba800 of type U64 (in lttng_ht_new() at hashtable.c:152)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:24:53.761933918 [Main]: Created hashtable size 16 at 0x55ee6abbb0a0 of type U64 (in lttng_ht_new() at hashtable.c:152)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:24:53.761948801 [Main]: Created hashtable size 16 at 0x55ee6abbb910 of type U64 (in lttng_ht_new() at hashtable.c:152)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:24:53.761969122 [Main]: Created hashtable size 4 at 0x55ee6abbc180 of type ULONG (in lttng_ht_new() at hashtable.c:152)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:24:53.761983502 [Main]: Created hashtable size 4 at 0x55ee6abbc910 of type U64 (in lttng_ht_new() at hashtable.c:152)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:24:53.762001365 [Main]: Creating consumer directory: /var/run/lttng/kconsumerd (in set_consumer_sockets() at main.c:1111)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.763225257 [Main]: libkmod: could not find module by name='lttng_ring_buffer_client_discard'

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: (in log_kmod() at modprobe.c:261)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: Error: Unable to load required module lttng-ring-buffer-client-discard

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: Warning: No kernel tracer available

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:24:53.763273100 [Main]: Creating consumer directory: /var/run/lttng/ustconsumerd64 (in set_consumer_sockets() at main.c:1111)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:24:53.763364054 [Main]: Creating consumer directory: /var/run/lttng/ustconsumerd32 (in set_consumer_sockets() at main.c:1111)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:24:53.763483167 [Main]: Created hashtable size 4 at 0x55ee6abbde30 of type U64 (in lttng_ht_new() at hashtable.c:152)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:24:53.763493681 [Main]: Global buffer per UID registry initialized (in buffer_reg_init_uid_registry() at buffer-registry.c:90)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:24:53.763514289 [Main]: Created hashtable size 4 at 0x55ee6abbe5c0 of type U64 (in lttng_ht_new() at hashtable.c:152)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:24:53.763522871 [Main]: Global buffer per PID registry initialized (in buffer_reg_init_pid_registry() at buffer-registry.c:219)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.763531179 [Main]: Command subsystem initialized (in cmd_init() at cmd.c:6090)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.763557950 [Main]: '54505' written in file /var/run/lttng/lttng-sessiond.pid (in utils_create_pid_file() at utils.c:257)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.763643858 [Main]: TCP inet operation timeout set to 216 sec (in lttcomm_inet_init() at inet.c:545)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.763748030 [Main]: Waiting for health management thread to be ready (in wait_until_thread_is_ready() at health.c:35)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.763834347 [Health management]: Entering thread entry point (in launch_thread() at thread.c:65)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.763906036 [Health management]: [thread] Manage health check started (in thread_manage_health() at health.c:65)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.764162528 [Health management]: Marking health management thread as ready (in mark_thread_as_ready() at health.c:28)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.764207077 [Health management]: Health check ready (in thread_manage_health() at health.c:136)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.764235576 [Main]: Health management thread is ready (in wait_until_thread_is_ready() at health.c:37)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.764334107 [Main]: Waiting for notification thread to be ready (in wait_until_thread_is_ready() at notification-thread.c:414)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.764393471 [Notification]: Entering thread entry point (in launch_thread() at thread.c:65)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.764447948 [Notification]: Started notification thread (in thread_notification() at notification-thread.c:642)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.764507304 [Notification]: Creating notification channel UNIX socket at /var/run/lttng/sessiond-notification (in notification_channel_socket_create() at notification-thread.c:223)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.764637070 [Notification]: Notification channel UNIX socket created (fd = 34) (in notification_channel_socket_create() at notification-thread.c:258)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.764672058 [Notification]: Listening on notification channel socket (in init_thread_state() at notification-thread.c:442)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.764873530 [Notification]: Marking notification thread as ready (in mark_thread_as_ready() at notification-thread.c:407)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.764904101 [Notification]: Entering poll wait (in thread_notification() at notification-thread.c:668)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.764957669 [Main]: Notification thread is ready (in wait_until_thread_is_ready() at notification-thread.c:416)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.764973775 [Action Executor]: Entering thread entry point (in launch_thread() at thread.c:65)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.765155116 [Action Executor]: Entering work execution loop (in action_executor_thread() at action-executor.c:761)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.765180538 [Action Executor]: No work items enqueued, entering wait (in action_executor_thread() at action-executor.c:770)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.765237883 [Timer]: Entering thread entry point (in launch_thread() at thread.c:65)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.765371609 [Main]: Created client socket (fd = 40) (in create_client_sock() at client.c:2435)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.765407601 [Rotation]: Entering thread entry point (in launch_thread() at thread.c:65)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.765467779 [Rotation]: Started rotation thread (in thread_rotation() at rotation-thread.c:840)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.765537310 [Main]: Waiting for client thread to be ready (in wait_thread_status() at client.c:65)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.765624687 [Client management]: Entering thread entry point (in launch_thread() at thread.c:65)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.765669290 [Client management]: [thread] Manage client started (in thread_manage_clients() at client.c:2468)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.765787553 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.c:670)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.765805553 [Notification]: Handling fd (34) activity (1) (in thread_notification() at notification-thread.c:694)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.765806360 [Client management]: Marking client thread's state as running (in set_thread_status() at client.c:58)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.765882092 [Client management]: Accepting client command ... (in thread_manage_clients() at client.c:2534)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.765890399 [Notification]: Handling new notification channel client connection (in handle_notification_thread_client_connect() at notification-thread-events.c:3351)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.765915851 [Main]: Client thread is ready (in wait_thread_status() at client.c:68)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.765939086 [Notification]: Client socket (fd = 44) set as non-blocking (in socket_set_non_blocking() at notification-thread-events.c:3319)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.765959082 [Notification]: Added new notification channel client socket (44) to poll set (in handle_notification_thread_client_connect() at notification-thread-events.c:3404)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.765972007 [Notification]: Entering poll wait (in thread_notification() at notification-thread.c:668)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.765983568 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.c:670)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.765992854 [Notification]: Handling fd (44) activity (1) (in thread_notification() at notification-thread.c:694)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.766012756 [Main]: All permissions are set (in set_permissions() at main.c:1057)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.766033503 [Notification]: Entering poll wait (in thread_notification() at notification-thread.c:668)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.766045812 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.c:670)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.766054787 [Notification]: Handling fd (44) activity (1) (in thread_notification() at notification-thread.c:694)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.766088847 [Notification]: Received handshake from client: uid = 0, gid = 0, protocol version = 1.1, client is sessiond = true (in client_handle_message_handshake() at notification-thread-events.c:3879)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.766116031 [Notification]: Send command reply (0) (in client_send_command_reply() at notification-thread-events.c:3755)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.766176958 [Notification]: Flushing client (socket fd = 44) outgoing queue (in client_flush_outgoing_queue() at notification-thread-events.c:3644)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:24:53.766169116 [Main]: Session daemon application socket created (fd = 47) (in create_application_socket() at register.c:71)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.766227862 [Notification]: Entering poll wait (in thread_notification() at notification-thread.c:668)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.766230099 [UST registration dispatch]: Entering thread entry point (in launch_thread() at thread.c:65)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.766331002 [Rotation]: Entering poll wait (in thread_rotation() at rotation-thread.c:864)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.766364074 [Main]: Waiting for application registration thread to be ready (in wait_thread_status() at register.c:131)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.766334067 [UST registration dispatch]: [thread] Dispatch UST command started (in thread_dispatch_ust_registration() at dispatch.c:250)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.766397044 [UST registration dispatch]: Futex n to 1 prepare done (in futex_nto1_prepare() at futex.c:67)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.766411508 [UST registration dispatch]: Woken up but nothing in the UST command queue (in thread_dispatch_ust_registration() at dispatch.c:279)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.766417302 [UST application registration]: Entering thread entry point (in launch_thread() at thread.c:65)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.766444021 [UST application registration]: [thread] Manage application registration started (in thread_application_registration() at register.c:168)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.766499268 [UST application registration]: Marking application registration thread's state as running (in set_thread_status() at register.c:124)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.766545096 [UST application registration]: Accepting application registration (in thread_application_registration() at register.c:207)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.766575023 [Main]: Application registration thread is ready (in wait_thread_status() at register.c:134)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.766620106 [Main]: Notifying applications of session daemon state: 1 (in notify_ust_apps() at register.c:91)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.766664110 [Main]: Wait shared memory file descriptor created successfully: path = '/lttng-ust-wait-8', mmap_size = 4096, global = true, fd = 50 (in get_wait_shm() at shm.c:133)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.766705997 [Main]: Futex wait update active 1 (in futex_wait_update() at futex.c:55)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.767026689 [Application notification]: Entering thread entry point (in launch_thread() at thread.c:65)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.767019497 [UST application management]: Entering thread entry point (in launch_thread() at thread.c:65)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.767057383 [Application notification]: [ust-thread] Manage application notify command (in thread_application_notification() at notify-apps.c:39)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.767140614 [Main]: Waiting for agent management thread to be ready (in wait_until_thread_is_ready() at agent-thread.c:348)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:24:53.767152313 [Application notification]: [ust-thread] Manage notify polling (in thread_application_notification() at notify-apps.c:74)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.767158226 [UST application management]: [thread] Manage application started (in thread_application_management() at manage-apps.c:52)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.767260931 [Agent management]: Entering thread entry point (in launch_thread() at thread.c:65)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.767291985 [UST application management]: Apps thread polling (in thread_application_management() at manage-apps.c:88)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.767316519 [Agent management]: Manage agent application registration. (in thread_agent_management() at agent-thread.c:366)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:24:53.767467151 [Agent management]: URI string: tcp://localhost (in uri_parse() at uri.c:298)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:24:53.767847758 [Agent management]: IP address resolved to 127.0.0.1 (in set_ip_address() at uri.c:155)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:24:53.767869664 [Agent management]: URI dtype: 1, proto: 1, host: localhost, subdir: , ctrl: 0, data: 0 (in uri_parse() at uri.c:510)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:24:53.767945204 [Agent management]: Trying to bind on port 5345 (in init_tcp_socket() at agent-thread.c:140)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.767995551 [Agent management]: Listening on TCP port 5345 and socket 59 (in init_tcp_socket() at agent-thread.c:177)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.768052984 [Agent management]: '5345' written in file /var/run/lttng/agent.port (in utils_create_pid_file() at utils.c:257)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.768096332 [Agent management]: Marking agent management thread as ready (in mark_thread_as_ready() at agent-thread.c:341)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:24:53.768146665 [Agent management]: Manage agent polling (in thread_agent_management() at agent-thread.c:421)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.768182388 [Main]: Agent management thread is ready (in wait_until_thread_is_ready() at agent-thread.c:350)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.768463025 [Kernel management]: Entering thread entry point (in launch_thread() at thread.c:65)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.768528983 [Kernel management]: [thread] Thread manage kernel started (in thread_kernel_management() at manage-kernel.c:173)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.768675778 [Kernel management]: Updating kernel poll set (in update_kernel_poll() at manage-kernel.c:37)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:24:53.768750578 [Kernel management]: Thread kernel polling (in thread_kernel_management() at manage-kernel.c:227)

Mar 26 10:24:53 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:24:53.772413092 [Main]: Home directory is '/root' (in utils_get_home_dir() at utils.c:796)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.244159208 [Client management]: Wait for client response (in thread_manage_clients() at client.c:2576)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.244261646 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.c:2604)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.244284302 [Client management]: Incomplete recv() from client... continuing (in thread_manage_clients() at client.c:2608)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.244325449 [Client management]: Accepting client command ... (in thread_manage_clients() at client.c:2534)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.244341437 [Client management]: Wait for client response (in thread_manage_clients() at client.c:2576)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.244366458 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.c:2604)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.244382956 [Client management]: Incomplete recv() from client... continuing (in thread_manage_clients() at client.c:2608)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.244409611 [Client management]: Accepting client command ... (in thread_manage_clients() at client.c:2534)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.244423567 [Client management]: Wait for client response (in thread_manage_clients() at client.c:2576)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.244447655 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.c:2604)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.244461558 [Client management]: Incomplete recv() from client... continuing (in thread_manage_clients() at client.c:2608)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.244487369 [Client management]: Accepting client command ... (in thread_manage_clients() at client.c:2534)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.244501912 [Client management]: Wait for client response (in thread_manage_clients() at client.c:2576)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.244528516 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.c:2604)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.244598235 [Client management]: Processing client command 'LTTNG_CREATE_SESSION_EXT' (49) (in process_client_msg() at client.c:1016)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.244882093 [Client management]: Created hashtable size 4 at 0x7f5fac0090b0 of type ULONG (in lttng_ht_new() at hashtable.c:152)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:25:02.244944153 [Client management]: Trying to find session by name auto-20240326-102502 (in session_find_by_name() at session.c:1143)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.244959185 [Client management]: Generated session name "auto-20240326-102502" (in session_create() at session.c:1300)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.245006899 [Client management]: Created hashtable size 4 at 0x7f5fac009840 of type ULONG (in lttng_ht_new() at hashtable.c:152)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.245074752 [Client management]: Allocating ltt_sessions_ht_by_id (in ltt_sessions_ht_alloc() at session.c:306)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.245099542 [Client management]: Created hashtable size 4 at 0x7f5fac009fd0 of type U64 (in lttng_ht_new() at hashtable.c:152)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.245113544 [Client management]: Allocating ltt_sessions_ht_by_name (in ltt_sessions_ht_alloc() at session.c:314)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.245128171 [Client management]: Created hashtable size 4 at 0x7f5fac00a760 of type STRING (in lttng_ht_new() at hashtable.c:152)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.245174012 [Client management]: Tracing session auto-20240326-102502 created with ID 0 by uid = 1000, gid = 1000 (in session_create() at session.c:1348)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.245194420 [Client management]: URI string: file:///home/ubuntu/lttng-traces/auto-20240326-102502 (in uri_parse() at uri.c:298)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.245236509 [Client management]: URI file destination: /home/ubuntu/lttng-traces/auto-20240326-102502 (in uri_parse() at uri.c:335)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.245250595 [Client management]: URI dtype: 3, proto: 0, host: , subdir: , ctrl: 0, data: 0 (in uri_parse() at uri.c:510)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:25:02.245308722 [Client management]: Setting trace directory path from URI to /home/ubuntu/lttng-traces/auto-20240326-102502 (in add_uri_to_consumer() at cmd.c:719)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.245415847 [Client management]: Sending response (size: 8262, retcode: Success (10)) (in thread_manage_clients() at client.c:2683)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.245506758 [Client management]: Accepting client command ... (in thread_manage_clients() at client.c:2534)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.246319433 [Client management]: Wait for client response (in thread_manage_clients() at client.c:2576)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.246362467 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.c:2604)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.246379985 [Client management]: Incomplete recv() from client... continuing (in thread_manage_clients() at client.c:2608)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.246410683 [Client management]: Accepting client command ... (in thread_manage_clients() at client.c:2534)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.246424345 [Client management]: Wait for client response (in thread_manage_clients() at client.c:2576)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.246448259 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.c:2604)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.246504151 [Client management]: Processing client command 'LTTNG_LIST_SESSIONS' (13) (in process_client_msg() at client.c:1016)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.246541958 [Client management]: Counting number of available session for UID 1000 (in lttng_sessions_count() at client.c:596)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.246559541 [Client management]: Getting all available session for UID 1000 GID 1000 (in cmd_list_lttng_sessions() at cmd.c:3947)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.246607560 [Client management]: Sending response (size: 4409, retcode: Success (10)) (in thread_manage_clients() at client.c:2683)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.246653505 [Client management]: Accepting client command ... (in thread_manage_clients() at client.c:2534)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.257444547 [Client management]: Wait for client response (in thread_manage_clients() at client.c:2576)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.257517451 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.c:2604)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.257553465 [Client management]: Incomplete recv() from client... continuing (in thread_manage_clients() at client.c:2608)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.257586532 [Client management]: Accepting client command ... (in thread_manage_clients() at client.c:2534)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.257599169 [Client management]: Wait for client response (in thread_manage_clients() at client.c:2576)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.257620949 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.c:2604)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.257665299 [Client management]: Processing client command 'LTTNG_ENABLE_CHANNEL' (5) (in process_client_msg() at client.c:1016)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.257680606 [Client management]: Getting session auto-20240326-102502 by name (in process_client_msg() at client.c:1133)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:25:02.257691765 [Client management]: Trying to find session by name auto-20240326-102502 (in session_find_by_name() at session.c:1143)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.257703728 [Client management]: Creating UST session (in create_ust_session() at client.c:510)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.257737397 [Client management]: Created hashtable size 4 at 0x7f5fac00d110 of type STRING (in lttng_ht_new() at hashtable.c:152)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.257752214 [Client management]: Created hashtable size 4 at 0x7f5fac00d8a0 of type U64 (in lttng_ht_new() at hashtable.c:152)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.257820129 [Client management]: Created hashtable size 4 at 0x7f5fac00f6e0 of type ULONG (in lttng_ht_new() at hashtable.c:152)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:25:02.257831631 [Client management]: UST trace session create successful (in trace_ust_create_session() at trace-ust.c:324)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.257842405 [Client management]: Copying tracing session consumer output in UST session (in copy_session_consumer() at client.c:454)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.257902341 [Client management]: Created hashtable size 4 at 0x7f5fac00fe70 of type ULONG (in lttng_ht_new() at hashtable.c:152)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.257920004 [Client management]: Copy session consumer subdir ust (in copy_session_consumer() at client.c:476)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.257948519 [Client management]: Spawning consumerd (in spawn_consumerd() at client.c:204)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.258006573 [HT cleanup]: Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:125)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.258108314 [HT cleanup]: Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:25:02.259418538 [Client management]: Consumer pid 54528 (in start_consumerd() at client.c:390)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:25:02.259500367 [Client management]: Spawning consumer control thread (in start_consumerd() at client.c:393)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:02.259631374 [Client management]: Using 64-bit UST consumer at: /usr/lib/x86_64-linux-gnu/lttng/libexec/lttng-consumerd (in spawn_consumerd() at client.c:284)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.259699956 [Client management]: Waiting for consumer management thread to be ready (in wait_until_thread_is_ready() at manage-consumer.c:46)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.260057290 [Consumer management]: Entering thread entry point (in launch_thread() at thread.c:65)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.260095942 [Consumer management]: [thread] Manage consumer started (in thread_consumer_management() at manage-consumer.c:65)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: libringbuffer-clients[54528/54528]: LTT : ltt ring buffer client "relay-metadata-mmap" init

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: (in lttng_ring_buffer_metadata_client_init() at ../../src/common/ringbuffer-clients/metadata-template.h:364)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: libringbuffer-clients[54528/54528]: LTT : ltt ring buffer client "relay-overwrite-mmap" init

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: (in lttng_ring_buffer_client_overwrite_init() at ../../src/common/ringbuffer-clients/template.h:826)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: libringbuffer-clients[54528/54528]: LTT : ltt ring buffer client "relay-overwrite-rt-mmap" init

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: (in lttng_ring_buffer_client_overwrite_rt_init() at ../../src/common/ringbuffer-clients/template.h:826)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: libringbuffer-clients[54528/54528]: LTT : ltt ring buffer client "relay-discard-mmap" init

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: (in lttng_ring_buffer_client_discard_init() at ../../src/common/ringbuffer-clients/template.h:826)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: libringbuffer-clients[54528/54528]: LTT : ltt ring buffer client "relay-discard-rt-mmap" init

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: (in lttng_ring_buffer_client_discard_rt_init() at ../../src/common/ringbuffer-clients/template.h:826)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:02.319212221 [54528/54528]: Health check time delta in seconds set to 20 (in health_init() at health.c:62)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: DBG3 - 10:25:02.319732554 [54528/54528]: Created hashtable size 4 at 0x55de709f7550 of type U64 (in lttng_ht_new() at hashtable.c:152)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: DBG3 - 10:25:02.319847346 [54528/54528]: Created hashtable size 4 at 0x55de709f7ce0 of type U64 (in lttng_ht_new() at hashtable.c:152)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: DBG3 - 10:25:02.319873701 [54528/54528]: Created hashtable size 4 at 0x55de709f8ec0 of type U64 (in lttng_ht_new() at hashtable.c:152)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: DBG3 - 10:25:02.319890117 [54528/54528]: Created hashtable size 4 at 0x55de709f95c0 of type U64 (in lttng_ht_new() at hashtable.c:152)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: DBG3 - 10:25:02.319912128 [54528/54528]: Created hashtable size 4 at 0x55de709f9cc0 of type U64 (in lttng_ht_new() at hashtable.c:152)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: DBG3 - 10:25:02.319928812 [54528/54528]: Created hashtable size 4 at 0x55de709fa3c0 of type U64 (in lttng_ht_new() at hashtable.c:152)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: DBG3 - 10:25:02.319952204 [54528/54528]: Created hashtable size 4 at 0x55de709fab50 of type U64 (in lttng_ht_new() at hashtable.c:152)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:02.320062033 [54528/54528]: TCP inet operation timeout set to 216 sec (in lttcomm_inet_init() at inet.c:545)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:02.320153638 [54528/54528]: Connecting to error socket /var/run/lttng/ustconsumerd64/error (in main() at lttng-consumerd.c:477)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:25:02.320365489 [Consumer management]: Receiving code from consumer err_sock (in thread_consumer_management() at manage-consumer.c:162)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:02.320593439 [54528/54532]: [thread] Manage health check started (in thread_manage_health() at health-consumerd.c:157)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:02.321370606 [54528/54532]: epoll set max size is 1783184 (in compat_epoll_set_max_size() at poll.c:350)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:02.321416546 [54528/54532]: Health check ready (in thread_manage_health() at health-consumerd.c:237)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: DBG3 - 10:25:02.421398786 [54528/54534]: Created hashtable size 4 at 0x7fe8cc000b90 of type U64 (in lttng_ht_new() at hashtable.c:152)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:02.421509764 [54528/54534]: Thread channel poll started (in consumer_thread_channel_poll() at consumer.c:2942)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:02.421569850 [54528/54534]: Channel main loop started (in consumer_thread_channel_poll() at consumer.c:2957)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:02.421633414 [54528/54534]: Channel poll wait (in consumer_thread_channel_poll() at consumer.c:2962)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:02.421567951 [54528/54535]: Thread metadata poll started (in consumer_thread_metadata_poll() at consumer.c:2348)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:02.421668581 [54528/54536]: Updating poll fd array (in update_poll_array() at consumer.c:1179)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:02.421822847 [54528/54536]: polling on 2 fd (in consumer_thread_data_poll() at consumer.c:2631)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:02.421835807 [54528/54535]: Metadata main loop started (in consumer_thread_metadata_poll() at consumer.c:2364)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:02.421879890 [54528/54535]: Metadata poll wait (in consumer_thread_metadata_poll() at consumer.c:2370)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:02.421975706 [54528/54537]: Creating command socket /var/run/lttng/ustconsumerd64/command (in consumer_thread_sessiond_poll() at consumer.c:3205)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:02.422083056 [54528/54537]: Sending ready command to lttng-sessiond (in consumer_thread_sessiond_poll() at consumer.c:3218)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.422342834 [Consumer management]: Consumer command socket ready (fd: 69) (in thread_consumer_management() at manage-consumer.c:204)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:02.422355972 [54528/54537]: Connection on client_socket (in consumer_thread_sessiond_poll() at consumer.c:3240)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.422364836 [Consumer management]: Consumer metadata socket ready (fd: 70) (in thread_consumer_management() at manage-consumer.c:205)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:02.422388511 [54528/54537]: Metadata connection on client_socket (in set_metadata_socket() at consumer.c:3166)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.422426915 [Consumer management]: Sending consumer initialization command (in consumer_init() at consumer.c:1791)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:02.422541305 [54528/54537]: Incoming command on sock (in consumer_thread_sessiond_poll() at consumer.c:3286)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:02.422696931 [54528/54537]: Received session daemon UUID: e196cba6-8a9c-45e5-82fc-8edd9fe7c9d1 (in lttng_consumer_init_command() at consumer.c:4715)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:02.422739632 [54528/54537]: Received command on sock (in consumer_thread_sessiond_poll() at consumer.c:3302)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.422780224 [Consumer management]: Sending SET_CHANNEL_MONITOR_PIPE command to consumer (in consumer_send_pipe() at consumer.c:1230)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:02.422869925 [54528/54537]: Incoming command on sock (in consumer_thread_sessiond_poll() at consumer.c:3286)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.422967486 [Consumer management]: Sending channel monitor pipe 18 to consumer on socket 69 (in consumer_send_pipe() at consumer.c:1236)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:02.423067374 [54528/54537]: Received channel monitor pipe (29) (in lttng_ustconsumer_recv_cmd() at ust-consumer.c:2015)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:02.423098753 [54528/54537]: Channel monitor pipe set as non-blocking (in lttng_ustconsumer_recv_cmd() at ust-consumer.c:2038)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:02.423145258 [54528/54537]: Received command on sock (in consumer_thread_sessiond_poll() at consumer.c:3302)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:25:02.423181771 [Consumer management]: channel monitor pipe successfully sent (in consumer_send_pipe() at consumer.c:1244)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.423326204 [Consumer management]: Marking consumer management thread as ready (in mark_thread_as_ready() at manage-consumer.c:31)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.423476924 [Client management]: Consumer management thread is ready (in wait_until_thread_is_ready() at manage-consumer.c:48)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.423517066 [Client management]: Consumer socket created (fd: 69) and added to output (in consumer_create_socket() at consumer.c:351)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.423557533 [Client management]: Setting relayd for session auto-20240326-102502 (in cmd_setup_relayd() at cmd.c:1004)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.423614646 [Client management]: Enabling channel chan_ust for session auto-20240326-102502 (in cmd_enable_channel_internal() at cmd.c:1332)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:25:02.423649515 [Client management]: Trace UST channel chan_ust not found by name (in trace_ust_find_channel_by_name() at trace-ust.c:188)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.423738693 [Client management]: Created hashtable size 4 at 0x7f5fac01b270 of type STRING (in lttng_ht_new() at hashtable.c:152)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.423766994 [Client management]: Created hashtable size 4 at 0x7f5fac01b9c0 of type ULONG (in lttng_ht_new() at hashtable.c:152)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:25:02.423780795 [Client management]: Trace UST channel chan_ust created (in trace_ust_create_channel() at trace-ust.c:402)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:25:02.423797382 [Client management]: Channel chan_ust is being created for UST with buffer 1 and id 0 (in channel_ust_create() at channel.c:451)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:25:02.423833779 [Client management]: Channel chan_ust created successfully (in channel_ust_create() at channel.c:481)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.423863367 [Client management]: Sending response (size: 24, retcode: Success (10)) (in thread_manage_clients() at client.c:2683)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.423913794 [Client management]: Accepting client command ... (in thread_manage_clients() at client.c:2534)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.433370763 [Client management]: Wait for client response (in thread_manage_clients() at client.c:2576)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.433451871 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.c:2604)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.433470683 [Client management]: Incomplete recv() from client... continuing (in thread_manage_clients() at client.c:2608)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.433507187 [Client management]: Accepting client command ... (in thread_manage_clients() at client.c:2534)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.433522135 [Client management]: Wait for client response (in thread_manage_clients() at client.c:2576)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.433546077 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.c:2604)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.433583752 [Client management]: Processing client command 'LTTNG_ADD_CONTEXT' (0) (in process_client_msg() at client.c:1016)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.433599031 [Client management]: Getting session auto-20240326-102502 by name (in process_client_msg() at client.c:1133)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:25:02.433611739 [Client management]: Trying to find session by name auto-20240326-102502 (in session_find_by_name() at session.c:1143)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.433627877 [Client management]: Consumer socket created (fd: 69) and added to output (in consumer_create_socket() at consumer.c:351)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.433640528 [Client management]: Setting relayd for session auto-20240326-102502 (in cmd_setup_relayd() at cmd.c:1004)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:25:02.433733562 [Client management]: Trace UST channel chan_ust found by name (in trace_ust_find_channel_by_name() at trace-ust.c:183)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.433753266 [Client management]: Context UST 1 added to channel chan_ust (in add_uctx_to_channel() at context.c:176)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.433770092 [Client management]: Sending response (size: 24, retcode: Success (10)) (in thread_manage_clients() at client.c:2683)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.433808058 [Client management]: Accepting client command ... (in thread_manage_clients() at client.c:2534)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.434012089 [Client management]: Wait for client response (in thread_manage_clients() at client.c:2576)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.434040722 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.c:2604)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.434055153 [Client management]: Incomplete recv() from client... continuing (in thread_manage_clients() at client.c:2608)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.434080435 [Client management]: Accepting client command ... (in thread_manage_clients() at client.c:2534)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.434094677 [Client management]: Wait for client response (in thread_manage_clients() at client.c:2576)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.434116342 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.c:2604)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.434140248 [Client management]: Processing client command 'LTTNG_ADD_CONTEXT' (0) (in process_client_msg() at client.c:1016)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.434152823 [Client management]: Getting session auto-20240326-102502 by name (in process_client_msg() at client.c:1133)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:25:02.434164577 [Client management]: Trying to find session by name auto-20240326-102502 (in session_find_by_name() at session.c:1143)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.434176498 [Client management]: Consumer socket created (fd: 69) and added to output (in consumer_create_socket() at consumer.c:351)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.434187579 [Client management]: Setting relayd for session auto-20240326-102502 (in cmd_setup_relayd() at cmd.c:1004)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:25:02.434225135 [Client management]: Trace UST channel chan_ust found by name (in trace_ust_find_channel_by_name() at trace-ust.c:183)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.434244768 [Client management]: Context UST 4 added to channel chan_ust (in add_uctx_to_channel() at context.c:176)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.434259868 [Client management]: Sending response (size: 24, retcode: Success (10)) (in thread_manage_clients() at client.c:2683)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.434297986 [Client management]: Accepting client command ... (in thread_manage_clients() at client.c:2534)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.434475877 [Client management]: Wait for client response (in thread_manage_clients() at client.c:2576)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.434503475 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.c:2604)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.434517784 [Client management]: Incomplete recv() from client... continuing (in thread_manage_clients() at client.c:2608)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.434543226 [Client management]: Accepting client command ... (in thread_manage_clients() at client.c:2534)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.434556020 [Client management]: Wait for client response (in thread_manage_clients() at client.c:2576)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.434578407 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.c:2604)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.434601199 [Client management]: Processing client command 'LTTNG_ADD_CONTEXT' (0) (in process_client_msg() at client.c:1016)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.434613540 [Client management]: Getting session auto-20240326-102502 by name (in process_client_msg() at client.c:1133)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:25:02.434625241 [Client management]: Trying to find session by name auto-20240326-102502 (in session_find_by_name() at session.c:1143)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.434637420 [Client management]: Consumer socket created (fd: 69) and added to output (in consumer_create_socket() at consumer.c:351)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.434648846 [Client management]: Setting relayd for session auto-20240326-102502 (in cmd_setup_relayd() at cmd.c:1004)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:25:02.434688929 [Client management]: Trace UST channel chan_ust found by name (in trace_ust_find_channel_by_name() at trace-ust.c:183)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.434705563 [Client management]: Context UST 3 added to channel chan_ust (in add_uctx_to_channel() at context.c:176)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.434719107 [Client management]: Sending response (size: 24, retcode: Success (10)) (in thread_manage_clients() at client.c:2683)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.434752938 [Client management]: Accepting client command ... (in thread_manage_clients() at client.c:2534)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.434909154 [Client management]: Wait for client response (in thread_manage_clients() at client.c:2576)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.434936589 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.c:2604)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.434950619 [Client management]: Incomplete recv() from client... continuing (in thread_manage_clients() at client.c:2608)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.434975216 [Client management]: Accepting client command ... (in thread_manage_clients() at client.c:2534)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.434987979 [Client management]: Wait for client response (in thread_manage_clients() at client.c:2576)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.435010768 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.c:2604)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.435067285 [Client management]: Processing client command 'LTTNG_ADD_CONTEXT' (0) (in process_client_msg() at client.c:1016)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.435102480 [Client management]: Getting session auto-20240326-102502 by name (in process_client_msg() at client.c:1133)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:25:02.435114840 [Client management]: Trying to find session by name auto-20240326-102502 (in session_find_by_name() at session.c:1143)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.435126963 [Client management]: Consumer socket created (fd: 69) and added to output (in consumer_create_socket() at consumer.c:351)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.435150785 [Client management]: Setting relayd for session auto-20240326-102502 (in cmd_setup_relayd() at cmd.c:1004)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:25:02.435189302 [Client management]: Trace UST channel chan_ust found by name (in trace_ust_find_channel_by_name() at trace-ust.c:183)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.435217545 [Client management]: Context UST 0 added to channel chan_ust (in add_uctx_to_channel() at context.c:176)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.435231604 [Client management]: Sending response (size: 24, retcode: Success (10)) (in thread_manage_clients() at client.c:2683)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.435281679 [Client management]: Accepting client command ... (in thread_manage_clients() at client.c:2534)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.443965515 [Client management]: Wait for client response (in thread_manage_clients() at client.c:2576)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.444017863 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.c:2604)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.444033422 [Client management]: Incomplete recv() from client... continuing (in thread_manage_clients() at client.c:2608)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.444064926 [Client management]: Accepting client command ... (in thread_manage_clients() at client.c:2534)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.444077812 [Client management]: Wait for client response (in thread_manage_clients() at client.c:2576)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.444098074 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.c:2604)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.444146712 [Client management]: Processing client command 'LTTNG_ENABLE_EVENT' (6) (in process_client_msg() at client.c:1016)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.444161749 [Client management]: Getting session auto-20240326-102502 by name (in process_client_msg() at client.c:1133)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:25:02.444172845 [Client management]: Trying to find session by name auto-20240326-102502 (in session_find_by_name() at session.c:1143)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.444186996 [Client management]: Consumer socket created (fd: 69) and added to output (in consumer_create_socket() at consumer.c:351)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.444197939 [Client management]: Setting relayd for session auto-20240326-102502 (in cmd_setup_relayd() at cmd.c:1004)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.444253061 [Client management]: Enable event command for event '*' (in _cmd_enable_event() at cmd.c:2088)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:25:02.444267667 [Client management]: Trace UST channel chan_ust found by name (in trace_ust_find_channel_by_name() at trace-ust.c:183)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:25:02.444292745 [Client management]: Trace UST event * NOT found (in trace_ust_find_event() at trace-ust.c:226)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:25:02.444317175 [Client management]: Trace UST event *, loglevel (0,-1) created (in trace_ust_create_event() at trace-ust.c:523)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.444333192 [Client management]: Sending response (size: 24, retcode: Success (10)) (in thread_manage_clients() at client.c:2683)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.444367505 [Client management]: Accepting client command ... (in thread_manage_clients() at client.c:2534)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.452544223 [Client management]: Wait for client response (in thread_manage_clients() at client.c:2576)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.452622101 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.c:2604)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.452640003 [Client management]: Incomplete recv() from client... continuing (in thread_manage_clients() at client.c:2608)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.452674513 [Client management]: Accepting client command ... (in thread_manage_clients() at client.c:2534)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.452691262 [Client management]: Wait for client response (in thread_manage_clients() at client.c:2576)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.452750787 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.c:2604)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.452800269 [Client management]: Processing client command 'LTTNG_START_TRACE' (16) (in process_client_msg() at client.c:1016)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.452817072 [Client management]: Getting session auto-20240326-102502 by name (in process_client_msg() at client.c:1133)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:25:02.452829828 [Client management]: Trying to find session by name auto-20240326-102502 (in session_find_by_name() at session.c:1143)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.452851745 [Client management]: Creating initial trace chunk of session "auto-20240326-102502" (in cmd_start_trace() at cmd.c:2774)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.452892284 [Client management]: Creating trace chunk: chunk_id = 0, creation time = 20240326-102502 (in lttng_trace_chunk_create() at trace-chunk.c:427)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.452907949 [Client management]: Chunk name set to "(none)" (in lttng_trace_chunk_create() at trace-chunk.c:458)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.452920643 [Client management]: Creating base output directory of session "auto-20240326-102502" at /home/ubuntu/lttng-traces/auto-20240326-102502 (in session_create_new_trace_chunk() at session.c:701)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.453202104 [Client management]: mkdirat() recursive fd = -100 (AT_FDCWD), path = /home/ubuntu/lttng-traces/auto-20240326-102502, mode = 504, uid = 1000, gid = 1000 (in run_as_mkdirat_recursive() at runas.c:1689)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.453261935 [Client management]: Using run_as worker (in run_as() at runas.c:1646)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.458186998 [Client management]: Creating trace chunk subdirectory "ust" (in lttng_trace_chunk_create_subdirectory() at trace-chunk.c:1226)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.458259769 [Client management]: mkdirat() recursive fd = 71, path = ust, mode = 504, uid = 1000, gid = 1000 (in run_as_mkdirat_recursive() at runas.c:1689)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.458287377 [Client management]: Using run_as worker (in run_as() at runas.c:1646)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.459628582 [Client management]: Adding new top-level directory "ust" to trace chunk "(unnamed)" (in add_top_level_directory_unique() at trace-chunk.c:1199)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.459664559 [Client management]: Sending consumer create trace chunk command: relayd_id = -1, session_id = 0, chunk_id = 0, creation_timestamp = 20240326T102502-0400 (in consumer_create_trace_chunk() at consumer.c:1941)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:02.459815859 [54528/54537]: Incoming command on sock (in consumer_thread_sessiond_poll() at consumer.c:3286)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.459931388 [Client management]: Sending trace chunk domain directory fd to consumer (in consumer_create_trace_chunk() at consumer.c:1956)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:02.460088432 [54528/54537]: Received trace chunk domain directory fd (32) (in lttng_ustconsumer_recv_cmd() at ust-consumer.c:2187)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:02.460246035 [54528/54537]: Consumer create trace chunk command: relay_id = (none), session_id = 0, chunk_id = 0, chunk_override_name = (none), chunk_creation_timestamp = 20240326T102502-0400 (in lttng_consumer_create_trace_chunk() at consumer.c:4758)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:02.460289067 [54528/54537]: Creating trace chunk: chunk_id = 0, creation time = 20240326-102502 (in lttng_trace_chunk_create() at trace-chunk.c:427)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:02.460304021 [54528/54537]: Chunk name set to "(none)" (in lttng_trace_chunk_create() at trace-chunk.c:458)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:02.460387207 [54528/54537]: Received command on sock (in consumer_thread_sessiond_poll() at consumer.c:3302)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.460442585 [Client management]: Starting all UST traces (in ust_app_start_trace_all() at ust-app.c:5652)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.460467304 [Client management]: Clearing stream quiescent state for all ust apps (in ust_app_clear_quiescent_session() at ust-app.c:5520)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.460492753 [Client management]: Opening packets of session channels: session name = auto-20240326-102502, session id = 0 (in session_open_packets() at session.c:900)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.460525075 [Client management]: Sending response (size: 24, retcode: Success (10)) (in thread_manage_clients() at client.c:2683)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.460572623 [Client management]: Accepting client command ... (in thread_manage_clients() at client.c:2534)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: libust[54505/54516]: Unix socket peercred [ pid: 54542, uid: 1000, gid: 1000 ], application registered claiming [ pid: 54542, ppid: 54525, uid: 1000, gid: 1000 ] (in get_cred() at ustctl.c:2386)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.478200643 [UST application registration]: UST registration received with pid:54542 ppid:54525 uid:1000 gid:1000 sock:64 name:hello (version 9.0) (in thread_application_registration() at register.c:311)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.478259941 [UST application registration]: Futex n to 1 wake done (in futex_nto1_wake() at futex.c:121)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.478276478 [UST application registration]: Accepting application registration (in thread_application_registration() at register.c:207)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: libust[54505/54516]: Unix socket peercred [ pid: 54542, uid: 1000, gid: 1000 ], application registered claiming [ pid: 54542, ppid: 54525, uid: 1000, gid: 1000 ] (in get_cred() at ustctl.c:2386)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.478329306 [UST application registration]: UST registration received with pid:54542 ppid:54525 uid:1000 gid:1000 sock:72 name:hello (version 9.0) (in thread_application_registration() at register.c:311)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.478344799 [UST application registration]: Futex n to 1 wake done (in futex_nto1_wake() at futex.c:121)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.478355945 [UST application registration]: Accepting application registration (in thread_application_registration() at register.c:207)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.478355945 [UST registration dispatch]: Futex n to 1 wait done (in futex_nto1_wait() at futex.c:104)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.478399999 [UST registration dispatch]: Futex n to 1 prepare done (in futex_nto1_prepare() at futex.c:67)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.478415660 [UST registration dispatch]: Dispatching UST registration pid:54542 ppid:54525 uid:1000 gid:1000 sock:64 name:hello (version 9.0) (in thread_dispatch_ust_registration() at dispatch.c:286)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.478486066 [UST registration dispatch]: UST app creating application for socket 64 (in ust_app_create() at ust-app.c:3947)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.478557825 [UST registration dispatch]: Created hashtable size 4 at 0x7f5f84000da0 of type U64 (in lttng_ht_new() at hashtable.c:152)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.478574970 [UST registration dispatch]: Created hashtable size 4 at 0x7f5f84001530 of type ULONG (in lttng_ht_new() at hashtable.c:152)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.478595782 [UST registration dispatch]: Created hashtable size 4 at 0x7f5f84001cc0 of type ULONG (in lttng_ht_new() at hashtable.c:152)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.478610986 [UST registration dispatch]: Created hashtable size 4 at 0x7f5f84002450 of type U64 (in lttng_ht_new() at hashtable.c:152)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.478649000 [UST registration dispatch]: Dispatching UST registration pid:54542 ppid:54525 uid:1000 gid:1000 sock:72 name:hello (version 9.0) (in thread_dispatch_ust_registration() at dispatch.c:286)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.478663064 [UST registration dispatch]: UST app notify socket 72 is set (in thread_dispatch_ust_registration() at dispatch.c:353)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.478689735 [UST registration dispatch]: App registered with pid:54542 ppid:54525 uid:1000 gid:1000 sock =64 name:hello notify_sock =72 (version 9.0) (in ust_app_add() at ust-app.c:4066)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: libust[54505/54515]: received tracer version (in lttng_ust_ctl_tracer_version() at ustctl.c:833)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: libust[54505/54515]: received event_notifier group handle 1 (in lttng_ust_ctl_create_event_notifier_group() at ustctl.c:660)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.479153113 [UST registration dispatch]: Beginning of waiter "wait" period (in lttng_waiter_wait() at waiter.c:46)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.479242822 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.c:670)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.479308364 [Notification]: Handling fd (33) activity (1) (in thread_notification() at notification-thread.c:694)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.479343859 [Notification]: Received `ADD_TRACER_EVENT_SOURCE` command (in handle_notification_thread_command() at notification-thread-events.c:3162)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.479360902 [Notification]: Adding tracer event source fd to poll set: tracer_event_source_fd = 73, domain = 'ust' (in handle_notification_thread_command_add_tracer_event_source() at notification-thread-events.c:2037)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.479401509 [Notification]: Entering poll wait (in thread_notification() at notification-thread.c:668)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.479455014 [UST registration dispatch]: End of waiter "wait" period (in lttng_waiter_wait() at waiter.c:106)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:25:02.481810435 [UST registration dispatch]: UST application global event notifier rules update: app = 'hello', pid = 54542) (in ust_app_global_update_event_notifier_rules() at ust-app.c:6125)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.481865648 [UST registration dispatch]: Beginning of waiter "wait" period (in lttng_waiter_wait() at waiter.c:46)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.481928631 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.c:670)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.481953180 [Notification]: Handling fd (33) activity (1) (in thread_notification() at notification-thread.c:694)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.481970148 [Notification]: Received `LIST_TRIGGERS` command (in handle_notification_thread_command() at notification-thread-events.c:3162)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.482004154 [Notification]: Entering poll wait (in thread_notification() at notification-thread.c:668)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.482016654 [Application notification]: [ust-thread] Manage notify return from poll on 2 fds (in thread_application_notification() at notify-apps.c:80)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.482050617 [Application notification]: UST thread notify added sock 72 to pollset (in thread_application_notification() at notify-apps.c:134)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.482062930 [Application notification]: [ust-thread] Manage notify polling (in thread_application_notification() at notify-apps.c:74)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.482086849 [UST registration dispatch]: End of waiter "wait" period (in lttng_waiter_wait() at waiter.c:106)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:25:02.482128768 [UST registration dispatch]: UST app global update for app sock 64 for session id 0 (in ust_app_global_update() at ust-app.c:6092)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:25:02.482155130 [UST registration dispatch]: UST app pid: 54542 session id 0 not found, creating it (in find_or_create_ust_app_session() at ust-app.c:2664)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.482203035 [UST registration dispatch]: Created hashtable size 4 at 0x7f5f84007fc0 of type STRING (in lttng_ht_new() at hashtable.c:152)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:25:02.482248920 [UST registration dispatch]: Shadow copy of session handle -1 (in shadow_copy_session() at ust-app.c:2389)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.482356349 [UST registration dispatch]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.c:193)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.482392969 [UST registration dispatch]: Created hashtable size 4 at 0x7f5f8400a7d0 of type U64 (in lttng_ht_new() at hashtable.c:152)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.482405659 [UST registration dispatch]: Buffer registry per UID created id: 0, ABI: 64, uid: 1000, domain: 2 (in buffer_reg_uid_create() at buffer-registry.c:142)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.482456476 [UST registration dispatch]: Created hashtable size 4 at 0x7f5f8400e040 of type STRING (in lttng_ht_new() at hashtable.c:152)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.482472065 [UST registration dispatch]: Created hashtable size 4 at 0x7f5f8400e7d0 of type U64 (in lttng_ht_new() at hashtable.c:152)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.482494853 [UST registration dispatch]: Append to metadata: "/* CTF 1.8 */

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: " (in lttng_metadata_printf() at ust-metadata.c:137)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.482521387 [UST registration dispatch]: Append to metadata: "typealias integer { size = 8; align = 8; signed = false; } := uint8_t;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: typealias integer { size = 16; align = 8; signed = false; } := uint16_t;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: typealias integer { size = 32; align = 8; signed = false; } := uint32_t;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: typealias integer { size = 64; align = 8; signed = false; } := uint64_t;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: typealias integer { size = 64; align = 8; signed = false; } := unsigned long;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: typealias integer { size = 5; align = 1; signed = false; } := uint5_t;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: typealias integer { size = 27; align = 1; signed = false; } := uint27_t;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: trace {

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: major = 1;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: minor = 8;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: uuid = "1e16cc09-d007-409d-b4c3-61dfce2f06af";

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: byte_order = le;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: packet.header := struct {

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: uint32_t magic;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: uint8_t uuid[16];

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: uint32_t stream_id;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: uint64_t stream_instance_id;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: };

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: };

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: " (in lttng_metadata_printf() at ust-metadata.c:137)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.482538524 [UST registration dispatch]: Append to metadata: "env {

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: domain = "ust";

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: tracer_name = "lttng-ust";

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: tracer_major = 2;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: tracer_minor = 13;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: tracer_buffering_scheme = "uid";

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: tracer_buffering_id = 1000;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: architecture_bit_width = 64;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: " (in lttng_metadata_printf() at ust-metadata.c:137)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.482552657 [UST registration dispatch]: Session 0 found by id. (in session_find_by_id() at session.c:1181)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.482565583 [UST registration dispatch]: Append to metadata: " trace_name = "" (in lttng_metadata_printf() at ust-metadata.c:137)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.482578228 [UST registration dispatch]: Append to metadata: "a" (in lttng_metadata_printf() at ust-metadata.c:137)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.482590612 [UST registration dispatch]: Append to metadata: "u" (in lttng_metadata_printf() at ust-metadata.c:137)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.482602778 [UST registration dispatch]: Append to metadata: "t" (in lttng_metadata_printf() at ust-metadata.c:137)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.482613913 [UST registration dispatch]: Append to metadata: "o" (in lttng_metadata_printf() at ust-metadata.c:137)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.482625585 [UST registration dispatch]: Append to metadata: "";

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: " (in lttng_metadata_printf() at ust-metadata.c:137)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.482647727 [UST registration dispatch]: Append to metadata: " trace_creation_datetime = "20240326T102502-0400";

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: hostname = "dorsal-vm2";

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: " (in lttng_metadata_printf() at ust-metadata.c:137)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.482661753 [UST registration dispatch]: Append to metadata: "};

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: " (in lttng_metadata_printf() at ust-metadata.c:137)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.482674944 [UST registration dispatch]: Append to metadata: "clock {

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: name = "monotonic";

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: " (in lttng_metadata_printf() at ust-metadata.c:137)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.482728671 [UST registration dispatch]: Append to metadata: " uuid = "007c29fa-d7f5-498d-a2b4-5527734c3ec9";

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: " (in lttng_metadata_printf() at ust-metadata.c:137)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.482768532 [UST registration dispatch]: Append to metadata: " description = "Monotonic Clock";

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: freq = 1000000000; /* Frequency, in Hz */

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: /* clock value offset from Epoch is: offset * (1/freq) */

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: offset = 1711121552733009992;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: };

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: " (in lttng_metadata_printf() at ust-metadata.c:137)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.482784610 [UST registration dispatch]: Append to metadata: "typealias integer {

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: size = 27; align = 1; signed = false;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: map = clock.monotonic.value;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: } := uint27_clock_monotonic_t;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: typealias integer {

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: size = 32; align = 8; signed = false;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: map = clock.monotonic.value;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: } := uint32_clock_monotonic_t;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: typealias integer {

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: size = 64; align = 8; signed = false;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: map = clock.monotonic.value;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: } := uint64_clock_monotonic_t;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: " (in lttng_metadata_printf() at ust-metadata.c:137)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.482797908 [UST registration dispatch]: Append to metadata: "struct packet_context {

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: uint64_clock_monotonic_t timestamp_begin;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: uint64_clock_monotonic_t timestamp_end;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: uint64_t content_size;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: uint64_t packet_size;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: uint64_t packet_seq_num;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: unsigned long events_discarded;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: uint32_t cpu_id;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: };

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: " (in lttng_metadata_printf() at ust-metadata.c:137)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.482820246 [UST registration dispatch]: Append to metadata: "struct event_header_compact {

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: enum : uint5_t { compact = 0 ... 30, extended = 31 } id;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: variant <id> {

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: struct {

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: uint27_clock_monotonic_t timestamp;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: } compact;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: struct {

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: uint32_t id;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: uint64_clock_monotonic_t timestamp;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: } extended;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: } v;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: } align(8);

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: struct event_header_large {

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: enum : uint16_t { compact = 0 ... 65534, extended = 65535 } id;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: variant <id> {

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: struct {

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: uint32_clock_monotonic_t timestamp;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: } compact;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: struct {

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: uint32_t id;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: uint64_clock_monotonic_t timestamp;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: } extended;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: } v;

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: } align(8);

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: " (in lttng_metadata_printf() at ust-metadata.c:137)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.482833055 [UST registration dispatch]: Buffer registry per UID adding to global registry with id: 0 (in buffer_reg_uid_add() at buffer-registry.c:164)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.482848533 [UST registration dispatch]: UST app buffer registry per UID created successfully (in setup_buffer_reg_uid() at ust-app.c:2628)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: libust[54505/54515]: received session handle 3 (in lttng_ust_ctl_create_session() at ustctl.c:276)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:25:02.483096934 [UST registration dispatch]: UST app session created successfully with handle 3 (in find_or_create_ust_app_session() at ust-app.c:2739)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.483120831 [UST registration dispatch]: Created hashtable size 4 at 0x7f5f8400fe80 of type ULONG (in lttng_ht_new() at hashtable.c:152)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.483168045 [UST registration dispatch]: Created hashtable size 4 at 0x7f5f84011ef0 of type STRING (in lttng_ht_new() at hashtable.c:152)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.483192909 [UST registration dispatch]: UST app channel chan_ust allocated (in alloc_ust_app_channel() at ust-app.c:1224)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:25:02.483227655 [UST registration dispatch]: UST app shadow copy of channel chan_ust started (in shadow_copy_channel() at ust-app.c:2346)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.483241103 [UST registration dispatch]: UST app shadow copy of channel chan_ust done (in shadow_copy_channel() at ust-app.c:2372)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.483255360 [UST registration dispatch]: UST app creating channel chan_ust with per UID buffers (in create_channel_per_uid() at ust-app.c:3379)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.483268172 [UST registration dispatch]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.c:193)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:25:02.483304888 [UST registration dispatch]: UST app creating buffer registry channel for chan_ust (in create_buffer_reg_channel() at ust-app.c:3200)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.483328979 [UST registration dispatch]: Buffer registry channel create with key: 0 (in buffer_reg_channel_create() at buffer-registry.c:370)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.483357187 [UST registration dispatch]: Created hashtable size 4 at 0x7f5f840125f0 of type STRING (in lttng_ht_new() at hashtable.c:152)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.483371855 [UST registration dispatch]: Session 0 found by id. (in session_find_by_id() at session.c:1181)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:25:02.483406688 [UST registration dispatch]: Asking UST consumer for channel (in ask_channel_creation() at ust-consumer.c:57)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.483448728 [UST registration dispatch]: Consumer trace path relative to current trace chunk: "ust/uid/1000/64-bit" (in setup_channel_trace_path() at consumer.c:72)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.483462942 [UST registration dispatch]: Creating trace chunk subdirectory "ust/uid/1000/64-bit/index" (in lttng_trace_chunk_create_subdirectory() at trace-chunk.c:1226)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.483700035 [UST registration dispatch]: mkdirat() recursive fd = 71, path = ust/uid/1000/64-bit/index, mode = 504, uid = 1000, gid = 1000 (in run_as_mkdirat_recursive() at runas.c:1689)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:02.483729090 [UST registration dispatch]: Using run_as worker (in run_as() at runas.c:1646)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:02.485840100 [UST registration dispatch]: UST registry channel finding key 0 (in ust_registry_channel_find() at ust-registry.c:816)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:02.485957122 [54528/54537]: Incoming command on sock (in consumer_thread_sessiond_poll() at consumer.c:3286)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:02.486126601 [54528/54537]: Allocated channel (key 1) (in consumer_allocate_channel() at consumer.c:1111)

Mar 26 10:25:02 dorsal-vm2 lttng-sessiond[54528]: DBG3 - 10:25:02.486166498 [54528/54537]: Creating channel to ustctl with attr: [overwrite: 0, subbuf_size: 67108864, num_subbuf: 8, switch_timer_interval: 0, read_timer_interval: 0, output: 0, type: 0 (in create_ust_channel() at ust-consumer.c:400)

Mar 26 10:25:05 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:05.521093304 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.c:670)

Mar 26 10:25:05 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:05.521187853 [Notification]: Handling fd (73) activity (16) (in thread_notification() at notification-thread.c:694)

Mar 26 10:25:05 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:05.521266519 [Notification]: Removing tracer event source from poll set: tracer_event_source_fd = 73, domain = 'ust' (in remove_tracer_event_source_from_pollset() at notification-thread-events.c:2140)

Mar 26 10:25:05 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:05.521345996 [Notification]: Entering poll wait (in thread_notification() at notification-thread.c:668)

Mar 26 10:25:05 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:05.521940418 [Application notification]: [ust-thread] Manage notify return from poll on 3 fds (in thread_application_notification() at notify-apps.c:80)

Mar 26 10:25:05 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:05.521981504 [Application notification]: UST app receiving notify from sock 72 (in ust_app_recv_notify() at ust-app.c:6775)

Mar 26 10:25:05 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:05.522018505 [Application notification]: UST app recv notify failed. Application died: sock = 72 (in ust_app_recv_notify() at ust-app.c:6780)

Mar 26 10:25:05 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:05.522037409 [Application notification]: UST app notify socket unregister 72 (in ust_app_notify_sock_unregister() at ust-app.c:6952)

Mar 26 10:25:05 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:05.522078828 [Application notification]: [ust-thread] Manage notify polling (in thread_application_notification() at notify-apps.c:74)

Mar 26 10:25:05 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:05.530920601 [Client management]: Wait for client response (in thread_manage_clients() at client.c:2576)

Mar 26 10:25:05 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:05.530998448 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.c:2604)

Mar 26 10:25:05 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:05.531016050 [Client management]: Incomplete recv() from client... continuing (in thread_manage_clients() at client.c:2608)

Mar 26 10:25:05 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:05.531043727 [Client management]: Accepting client command ... (in thread_manage_clients() at client.c:2534)

Mar 26 10:25:05 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:05.531062069 [Client management]: Wait for client response (in thread_manage_clients() at client.c:2576)

Mar 26 10:25:05 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:05.531086339 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.c:2604)

Mar 26 10:25:05 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:05.531126416 [Client management]: Processing client command 'LTTNG_STOP_TRACE' (17) (in process_client_msg() at client.c:1016)

Mar 26 10:25:05 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:05.531145422 [Client management]: Getting session auto-20240326-102502 by name (in process_client_msg() at client.c:1133)

Mar 26 10:25:27 dorsal-vm2 lttng-sessiond[54528]: libringbuffer[54528/54537]: Error: zero_file: No space left on device (in _shm_object_table_alloc_shm() at ringbuffer/shm.c:131)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:28.184977769 [54528/54537]: UST consumer cleaning stream list (in destroy_channel() at ust-consumer.c:64)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:28.185101712 [54528/54537]: Received command on sock (in consumer_thread_sessiond_poll() at consumer.c:3302)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: Error: ask_channel_creation consumer command failed

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: Error: Error creating UST channel "chan_ust" on the consumer daemon

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:28.185353220 [UST registration dispatch]: UST registry channel finding key 0 (in ust_registry_channel_find() at ust-registry.c:816)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:28.185420027 [UST registration dispatch]: Buffer registry channel destroy with key 0 (in buffer_reg_channel_destroy() at buffer-registry.c:542)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:28.185463720 [UST registration dispatch]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.c:193)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:28.185514091 [UST registration dispatch]: Created hashtable size 4 at 0x7f5f84012f20 of type ULONG (in lttng_ht_new() at hashtable.c:152)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:28.185532756 [UST registration dispatch]: Created hashtable size 4 at 0x7f5f840136b0 of type STRING (in lttng_ht_new() at hashtable.c:152)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:28.185547852 [UST registration dispatch]: UST app channel metadata allocated (in alloc_ust_app_channel() at ust-app.c:1224)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:28.185578930 [UST registration dispatch]: Session 0 found by id. (in session_find_by_id() at session.c:1181)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:25:28.185596308 [UST registration dispatch]: Asking UST consumer for channel (in ask_channel_creation() at ust-consumer.c:57)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:28.185640261 [UST registration dispatch]: Consumer trace path relative to current trace chunk: "ust/uid/1000/64-bit" (in setup_channel_trace_path() at consumer.c:72)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.185670573 [UST registration dispatch]: Creating trace chunk subdirectory "ust/uid/1000/64-bit/index" (in lttng_trace_chunk_create_subdirectory() at trace-chunk.c:1226)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:28.185739371 [UST registration dispatch]: mkdirat() recursive fd = 71, path = ust/uid/1000/64-bit/index, mode = 504, uid = 1000, gid = 1000 (in run_as_mkdirat_recursive() at runas.c:1689)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.185777518 [UST registration dispatch]: Using run_as worker (in run_as() at runas.c:1646)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:28.187987892 [54528/54537]: Incoming command on sock (in consumer_thread_sessiond_poll() at consumer.c:3286)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:28.188066334 [54528/54537]: Allocated channel (key 2) (in consumer_allocate_channel() at consumer.c:1111)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG3 - 10:25:28.188079270 [54528/54537]: Creating channel to ustctl with attr: [overwrite: -1, subbuf_size: 4096, num_subbuf: 2, switch_timer_interval: 0, read_timer_interval: 0, output: 0, type: 1 (in create_ust_channel() at ust-consumer.c:400)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG3 - 10:25:28.188392977 [54528/54537]: Allocated stream metadata (key 39, chan_key 2 relayd_id 18446744073709551615, session_id 0 (in consumer_stream_create() at consumer-stream.c:735)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:28.188440481 [54528/54537]: Opening stream output file "uid/1000/64-bit/metadata" (in consumer_stream_create_output_files() at consumer-stream.c:1198)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:28.188461892 [54528/54537]: Opening trace chunk file "uid/1000/64-bit/metadata" (in _lttng_trace_chunk_open_fs_handle_locked() at trace-chunk.c:1364)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:28.188472579 [54528/54537]: Adding new file "uid/1000/64-bit/metadata" to trace chunk "(unnamed)" (in lttng_trace_chunk_add_file() at trace-chunk.c:1314)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG3 - 10:25:28.188611317 [54528/54537]: openat() fd = 32, path = uid/1000/64-bit/metadata, flags = 241, mode = 432, uid 1000, gid 1000 (in run_as_openat() at runas.c:1758)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:28.188647284 [54528/54537]: Using run_as worker (in run_as() at runas.c:1646)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:28.191534127 [54528/54537]: UST consumer add stream metadata (key: 39) with relayd id 0 (in create_ust_streams() at ust-consumer.c:329)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:28.191592980 [54528/54537]: Allocated metadata cache: current capacity = 4096 (in consumer_metadata_cache_allocate() at consumer-metadata-cache.c:157)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:28.191636313 [54528/54537]: UST consumer channel added (key: 2) (in add_channel() at ust-consumer.c:119)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:28.191664915 [54528/54537]: Received command on sock (in consumer_thread_sessiond_poll() at consumer.c:3302)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:25:28.191725516 [UST registration dispatch]: UST ask channel 2 successfully done with 1 stream(s) (in ask_channel_creation() at ust-consumer.c:179)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:25:28.191783355 [UST registration dispatch]: Consumer setup metadata channel key 2 (in consumer_setup_metadata() at consumer.c:1427)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:28.191877744 [54528/54537]: Incoming command on sock (in consumer_thread_sessiond_poll() at consumer.c:3286)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:28.191930811 [54528/54537]: UST consumer setup metadata key 2 (in setup_metadata() at ust-consumer.c:880)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG3 - 10:25:28.191955721 [54528/54537]: Adding metadata stream 39 to hash table (in consumer_add_metadata_stream() at consumer.c:2214)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:28.191998870 [54528/54535]: Metadata poll return from wait with 1 fd(s) (in consumer_thread_metadata_poll() at consumer.c:2372)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:28.192010824 [54528/54535]: Metadata event caught in thread (in consumer_thread_metadata_poll() at consumer.c:2375)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:28.192026246 [54528/54535]: Adding metadata stream 39 to poll set (in consumer_thread_metadata_poll() at consumer.c:2423)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:28.192044155 [54528/54535]: Metadata poll wait (in consumer_thread_metadata_poll() at consumer.c:2370)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:28.192079362 [54528/54537]: Received command on sock (in consumer_thread_sessiond_poll() at consumer.c:3302)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:25:28.192134926 [UST registration dispatch]: UST metadata with key 2 created for app pid 54542 (in create_ust_app_metadata() at ust-app.c:3892)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:28.192154496 [UST registration dispatch]: UST app deleting channel metadata (in delete_ust_app_channel() at ust-app.c:544)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.192266386 [UST registration dispatch]: Starting tracing for ust app pid 54542 (in ust_app_start_trace() at ust-app.c:5104)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:28.192292914 [UST registration dispatch]: UST app start session failed. Application is dead: pid = 54542, sock = 64 (in ust_app_start_trace() at ust-app.c:5144)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: libust[54505/54515]: Sending register done command to 64 (in lttng_ust_ctl_register_done() at ustctl.c:249)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.192387496 [UST registration dispatch]: Woken up but nothing in the UST command queue (in thread_dispatch_ust_registration() at dispatch.c:279)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:25:28.192534880 [Client management]: Trying to find session by name auto-20240326-102502 (in session_find_by_name() at session.c:1143)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.192613851 [Client management]: Begin stop session "auto-20240326-102502" (id 0) (in cmd_stop_trace() at cmd.c:2886)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.192635601 [Client management]: Stopping all UST traces (in ust_app_stop_trace_all() at ust-app.c:5689)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.192654967 [Client management]: Stopping tracing for ust app pid 54542 (in ust_app_stop_trace() at ust-app.c:5208)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.192677282 [Client management]: Flushing session buffers for all ust apps (in ust_app_flush_session() at ust-app.c:5375)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:25:28.192841128 [Client management]: Consumer push metadata to consumer socket 69 (in consumer_push_metadata() at consumer.c:1462)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:28.192976577 [54528/54537]: Incoming command on sock (in consumer_thread_sessiond_poll() at consumer.c:3286)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:28.193809730 [54528/54537]: UST consumer push metadata key 2 of len 2423 (in lttng_ustconsumer_recv_cmd() at ust-consumer.c:1774)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:28.193886587 [Client management]: Consumer pushing metadata on sock 69 of len 2423 (in consumer_push_metadata() at consumer.c:1479)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:28.193971664 [54528/54537]: UST consumer push metadata key 2 of len 2423 (in lttng_ustconsumer_recv_metadata() at ust-consumer.c:1287)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:28.194031912 [54528/54537]: Writing 2423 bytes from offset 0 in metadata cache (in consumer_metadata_cache_write() at consumer-metadata-cache.c:96)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:28.194054127 [54528/54537]: Waking up metadata poll thread (writing to pipe): channel name = 'metadata' (in consumer_metadata_wakeup_pipe() at consumer.c:890)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:28.194101259 [54528/54537]: Beginning of waiter "wait" period (in lttng_waiter_wait() at waiter.c:46)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:28.194264980 [54528/54535]: Metadata poll return from wait with 2 fd(s) (in consumer_thread_metadata_poll() at consumer.c:2372)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:28.194278910 [54528/54535]: Metadata event caught in thread (in consumer_thread_metadata_poll() at consumer.c:2375)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:28.194290535 [54528/54535]: Metadata available on fd 39 (in consumer_thread_metadata_poll() at consumer.c:2462)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.194284029 [UST application management]: Apps thread return from poll on 2 fds (in thread_application_management() at manage-apps.c:94)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.194349456 [UST application management]: Apps with sock 64 added to poll set (in thread_application_management() at manage-apps.c:145)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.194364429 [UST application management]: Apps thread polling (in thread_application_management() at manage-apps.c:88)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.194405062 [UST application management]: Apps thread return from poll on 3 fds (in thread_application_management() at manage-apps.c:94)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.194430283 [UST application management]: PID 54542 unregistering with sock 64 (in ust_app_unregister_by_socket() at ust-app.c:4337)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:28.194452892 [UST application management]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.c:193)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:28.194519011 [54528/54535]: Consumer mmap write() ret 4096 (len 4096) (in lttng_consumer_on_read_subbuffer_mmap() at consumer.c:1728)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:25:28.194563341 [UST application management]: Consumer push metadata to consumer socket 69 (in consumer_push_metadata() at consumer.c:1462)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:28.194617928 [54528/54537]: End of waiter "wait" period (in lttng_waiter_wait() at waiter.c:106)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:28.194720016 [54528/54535]: Check is rotate ready for stream 39 ready 0 rotate_position 18446744073709551615 last_sequence_number 18446744073709551615 (in lttng_consumer_stream_is_rotate_ready() at consumer.c:4476)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:28.194751968 [54528/54535]: Metadata poll wait (in consumer_thread_metadata_poll() at consumer.c:2370)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:28.194822798 [54528/54537]: Beginning of waiter "wait" period (in lttng_waiter_wait() at waiter.c:46)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:28.194846955 [54528/54537]: End of waiter "wait" period (in lttng_waiter_wait() at waiter.c:106)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.194953041 [Client management]: Completed stop session "auto-20240326-102502" (id 0) (in cmd_stop_trace() at cmd.c:2910)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.195009933 [Client management]: Sending response (size: 24, retcode: Success (10)) (in thread_manage_clients() at client.c:2683)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.195541843 [Client management]: Accepting client command ... (in thread_manage_clients() at client.c:2534)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.195570956 [Client management]: Wait for client response (in thread_manage_clients() at client.c:2576)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.195608686 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.c:2604)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.195626889 [Client management]: Incomplete recv() from client... continuing (in thread_manage_clients() at client.c:2608)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.195656754 [Client management]: Accepting client command ... (in thread_manage_clients() at client.c:2534)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.195677242 [Client management]: Wait for client response (in thread_manage_clients() at client.c:2576)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.195707275 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.c:2604)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:28.195749147 [54528/54537]: Received command on sock (in consumer_thread_sessiond_poll() at consumer.c:3302)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:28.195789818 [54528/54537]: Incoming command on sock (in consumer_thread_sessiond_poll() at consumer.c:3286)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.195783583 [Client management]: Processing client command 'LTTNG_DATA_PENDING' (24) (in process_client_msg() at client.c:1016)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.195810518 [Client management]: Getting session auto-20240326-102502 by name (in process_client_msg() at client.c:1133)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:28.195839519 [54528/54537]: UST consumer push metadata key 2 of len 2423 (in lttng_ustconsumer_recv_cmd() at ust-consumer.c:1774)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:28.195901518 [UST application management]: Consumer pushing metadata on sock 69 of len 2423 (in consumer_push_metadata() at consumer.c:1479)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:25:28.195972057 [Client management]: Trying to find session by name auto-20240326-102502 (in session_find_by_name() at session.c:1143)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.196016790 [Client management]: Data pending for session auto-20240326-102502 (in cmd_data_pending() at cmd.c:4008)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:28.196038169 [54528/54537]: UST consumer push metadata key 2 of len 2423 (in lttng_ustconsumer_recv_metadata() at ust-consumer.c:1287)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:28.196077245 [54528/54537]: Writing 2423 bytes from offset 0 in metadata cache (in consumer_metadata_cache_write() at consumer-metadata-cache.c:96)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:28.196054753 [Client management]: Consumer data pending for id 0 (in consumer_is_data_pending() at consumer.c:1272)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:28.196117479 [54528/54537]: Received command on sock (in consumer_thread_sessiond_poll() at consumer.c:3302)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.196169693 [UST application management]: Apps thread polling (in thread_application_management() at manage-apps.c:88)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:28.196293377 [54528/54537]: Incoming command on sock (in consumer_thread_sessiond_poll() at consumer.c:3286)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:28.196357399 [54528/54537]: UST consumer data pending command for id 0 (in lttng_ustconsumer_recv_cmd() at ust-consumer.c:1482)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:28.196370180 [54528/54537]: Consumer data pending command on session id 0 (in consumer_data_pending() at consumer.c:3775)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:28.196383542 [54528/54537]: UST consumer checking data pending (in lttng_ustconsumer_data_pending() at ust-consumer.c:3166)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:28.196395360 [54528/54537]: UST consumer metadata pending check: contiguous 2423 vs pushed 2423 (in lttng_ustconsumer_data_pending() at ust-consumer.c:3192)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54528]: DBG1 - 10:25:28.196422077 [54528/54537]: Received command on sock (in consumer_thread_sessiond_poll() at consumer.c:3302)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.196459313 [Client management]: Consumer data is NOT pending for session id 0 (in consumer_is_data_pending() at consumer.c:1307)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.196488221 [Client management]: Sending response (size: 25, retcode: Success (10)) (in thread_manage_clients() at client.c:2683)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.196877161 [Client management]: Accepting client command ... (in thread_manage_clients() at client.c:2534)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.196898167 [Client management]: Wait for client response (in thread_manage_clients() at client.c:2576)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.196921748 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.c:2604)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.196935271 [Client management]: Incomplete recv() from client... continuing (in thread_manage_clients() at client.c:2608)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.196957070 [Client management]: Accepting client command ... (in thread_manage_clients() at client.c:2534)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.196971734 [Client management]: Wait for client response (in thread_manage_clients() at client.c:2576)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.196994024 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.c:2604)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.197085463 [Client management]: Processing client command 'LTTNG_LIST_SESSIONS' (13) (in process_client_msg() at client.c:1016)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.197101718 [Client management]: Counting number of available session for UID 1000 (in lttng_sessions_count() at client.c:596)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.197124516 [Client management]: Getting all available session for UID 1000 GID 1000 (in cmd_list_lttng_sessions() at cmd.c:3947)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.197146871 [Client management]: Sending response (size: 4409, retcode: Success (10)) (in thread_manage_clients() at client.c:2683)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.197371072 [Client management]: Accepting client command ... (in thread_manage_clients() at client.c:2534)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.197389471 [Client management]: Wait for client response (in thread_manage_clients() at client.c:2576)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.197419910 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.c:2604)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.197433858 [Client management]: Incomplete recv() from client... continuing (in thread_manage_clients() at client.c:2608)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.197453505 [Client management]: Accepting client command ... (in thread_manage_clients() at client.c:2534)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.197464231 [Client management]: Wait for client response (in thread_manage_clients() at client.c:2576)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.197480400 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.c:2604)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.197523504 [Client management]: Processing client command 'LTTNG_LIST_DOMAINS' (11) (in process_client_msg() at client.c:1016)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.197539805 [Client management]: Getting session auto-20240326-102502 by name (in process_client_msg() at client.c:1133)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:25:28.197550732 [Client management]: Trying to find session by name auto-20240326-102502 (in session_find_by_name() at session.c:1143)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:28.197563676 [Client management]: Listing domains found UST global domain (in cmd_list_domains() at cmd.c:3652)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.197578573 [Client management]: Sending response (size: 332, retcode: Success (10)) (in thread_manage_clients() at client.c:2683)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.197778800 [Client management]: Accepting client command ... (in thread_manage_clients() at client.c:2534)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.197797412 [Client management]: Wait for client response (in thread_manage_clients() at client.c:2576)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.197819418 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.c:2604)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.197834030 [Client management]: Incomplete recv() from client... continuing (in thread_manage_clients() at client.c:2608)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.197856006 [Client management]: Accepting client command ... (in thread_manage_clients() at client.c:2534)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.197866623 [Client management]: Wait for client response (in thread_manage_clients() at client.c:2576)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.197883246 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.c:2604)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.197926803 [Client management]: Processing client command 'LTTNG_LIST_CHANNELS' (10) (in process_client_msg() at client.c:1016)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.197944688 [Client management]: Getting session auto-20240326-102502 by name (in process_client_msg() at client.c:1133)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:25:28.197956506 [Client management]: Trying to find session by name auto-20240326-102502 (in session_find_by_name() at session.c:1143)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:28.197969715 [Client management]: Consumer socket created (fd: 69) and added to output (in consumer_create_socket() at consumer.c:351)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.197981198 [Client management]: Setting relayd for session auto-20240326-102502 (in cmd_setup_relayd() at cmd.c:1004)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.197992691 [Client management]: Listing channels for session auto-20240326-102502 (in cmd_list_channels() at cmd.c:3725)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.198039890 [Client management]: Sending response (size: 120, retcode: Success (10)) (in thread_manage_clients() at client.c:2683)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.198631352 [Client management]: Accepting client command ... (in thread_manage_clients() at client.c:2534)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:28.202631621 [54505/54538]: Call RCU deleting app PID 54542 (in delete_ust_app_rcu() at ust-app.c:1119)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:28.202708258 [HT cleanup]: Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:125)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:28.202732228 [54505/54538]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.c:193)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:28.202760506 [54505/54538]: No metadata to push for metadata key 2 (in ust_app_push_metadata() at ust-app.c:680)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:28.202793425 [HT cleanup]: Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:28.202814114 [HT cleanup]: Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:125)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:28.202824081 [54505/54538]: UST app deleting channel chan_ust (in delete_ust_app_channel() at ust-app.c:544)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:28.202833477 [HT cleanup]: Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:28.202845573 [54505/54538]: UST app release session handle failed. Application is dead: pid = 54542, sock = -1 (in delete_ust_app_session() at ust-app.c:971)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:28.202849881 [HT cleanup]: Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:125)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:28.202873733 [HT cleanup]: Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.202882142 [54505/54538]: Beginning of waiter "wait" period (in lttng_waiter_wait() at waiter.c:46)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:28.202890919 [HT cleanup]: Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:125)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:28.202923570 [HT cleanup]: Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:28.202940539 [HT cleanup]: Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:125)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:28.202960223 [HT cleanup]: Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:28.202993347 [HT cleanup]: Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:125)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.202955105 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.c:670)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.203061456 [Notification]: Handling fd (33) activity (1) (in thread_notification() at notification-thread.c:694)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.203084751 [Notification]: Received `REMOVE_TRACER_EVENT_SOURCE` command (in handle_notification_thread_command() at notification-thread-events.c:3162)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:28.203029030 [HT cleanup]: Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:28.203148764 [HT cleanup]: Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:125)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.203160276 [54505/54538]: End of waiter "wait" period (in lttng_waiter_wait() at waiter.c:106)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:28.203183047 [HT cleanup]: Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.203149700 [Notification]: Entering poll wait (in thread_notification() at notification-thread.c:668)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG2 - 10:25:28.203218531 [54505/54538]: UST app pid 54542 deleted (in delete_ust_app() at ust-app.c:1103)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.207723008 [Client management]: Wait for client response (in thread_manage_clients() at client.c:2576)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.207779358 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.c:2604)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.207801703 [Client management]: Incomplete recv() from client... continuing (in thread_manage_clients() at client.c:2608)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.207835204 [Client management]: Accepting client command ... (in thread_manage_clients() at client.c:2534)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.207852795 [Client management]: Wait for client response (in thread_manage_clients() at client.c:2576)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.207875807 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.c:2604)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.207937687 [Client management]: Processing client command 'LTTNG_LIST_SESSIONS' (13) (in process_client_msg() at client.c:1016)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.207960962 [Client management]: Counting number of available session for UID 1000 (in lttng_sessions_count() at client.c:596)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.207981795 [Client management]: Getting all available session for UID 1000 GID 1000 (in cmd_list_lttng_sessions() at cmd.c:3947)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.208005449 [Client management]: Sending response (size: 4409, retcode: Success (10)) (in thread_manage_clients() at client.c:2683)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG1 - 10:25:28.208061765 [Client management]: Accepting client command ... (in thread_manage_clients() at client.c:2534)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:28.213451974 [HT cleanup]: Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:125)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:28.213547802 [HT cleanup]: Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:28.213566441 [HT cleanup]: Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:125)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:28.213632049 [HT cleanup]: Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:28.213655267 [HT cleanup]: Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:125)

Mar 26 10:25:28 dorsal-vm2 lttng-sessiond[54505]: DBG3 - 10:25:28.213728507 [HT cleanup]: Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)