Project

General

Profile

Bug #1243 » sessiond.log

output of lttng-sessiond -vvv - Matthew Khouzam, 03/06/2020 09:35 PM

 
DEBUG1 - 21:30:25.376260293 [8383/8383]: [sessiond configuration]
DEBUG1 - 21:30:25.376301969 [8383/8383]: version 2.12.0-rc1
DEBUG1 - 21:30:25.376305079 [8383/8383]: verbose: 3
DEBUG1 - 21:30:25.376307278 [8383/8383]: verbose consumer: 0
DEBUG1 - 21:30:25.376309416 [8383/8383]: quiet mode: False
DEBUG1 - 21:30:25.376311595 [8383/8383]: agent_tcp_port: [5345, 5354]
DEBUG1 - 21:30:25.376313863 [8383/8383]: application socket timeout: 5
DEBUG1 - 21:30:25.376315968 [8383/8383]: no-kernel: False
DEBUG1 - 21:30:25.376318110 [8383/8383]: background: False
DEBUG1 - 21:30:25.376320257 [8383/8383]: daemonize: False
DEBUG1 - 21:30:25.376322353 [8383/8383]: signal parent on start: False
DEBUG1 - 21:30:25.376324525 [8383/8383]: tracing group name: tracing
DEBUG1 - 21:30:25.376326551 [8383/8383]: kmod_probe_list: None
DEBUG1 - 21:30:25.376328577 [8383/8383]: kmod_extra_probe_list: None
DEBUG1 - 21:30:25.376338715 [8383/8383]: rundir: /var/run/lttng
DEBUG1 - 21:30:25.376340795 [8383/8383]: application socket path: /var/run/lttng/lttng-ust-sock-8
DEBUG1 - 21:30:25.376342868 [8383/8383]: client socket path: /var/run/lttng/client-lttng-sessiond
DEBUG1 - 21:30:25.376344925 [8383/8383]: wait shm path: /lttng-ust-wait-8
DEBUG1 - 21:30:25.376346980 [8383/8383]: health socket path: /var/run/lttng/sessiond-health
DEBUG1 - 21:30:25.376349023 [8383/8383]: LTTNG_UST_CLOCK_PLUGIN: None
DEBUG1 - 21:30:25.376351019 [8383/8383]: pid file path: /var/run/lttng/lttng-sessiond.pid
DEBUG1 - 21:30:25.376353090 [8383/8383]: lock file path: /var/run/lttng/lttng-sessiond.lck
DEBUG1 - 21:30:25.376355131 [8383/8383]: session load path: None
DEBUG1 - 21:30:25.376357103 [8383/8383]: agent port file path: /var/run/lttng/agent.port
DEBUG1 - 21:30:25.376359105 [8383/8383]: consumerd32 path: /var/run/lttng/ustconsumerd32
DEBUG1 - 21:30:25.376361107 [8383/8383]: consumerd32 bin path: Unknown
DEBUG1 - 21:30:25.376363094 [8383/8383]: consumerd32 lib dir: Unknown
DEBUG1 - 21:30:25.376365082 [8383/8383]: consumerd32 err unix sock path:/var/run/lttng/ustconsumerd32/error
DEBUG1 - 21:30:25.376367142 [8383/8383]: consumerd32 cmd unix sock path:/var/run/lttng/ustconsumerd32/command
DEBUG1 - 21:30:25.376369157 [8383/8383]: consumerd64 path: /var/run/lttng/ustconsumerd64
DEBUG1 - 21:30:25.376371146 [8383/8383]: consumerd64 bin path: /usr/lib/x86_64-linux-gnu/lttng/libexec/lttng-consumerd
DEBUG1 - 21:30:25.376373214 [8383/8383]: consumerd64 lib dir: /usr/lib/x86_64-linux-gnu
DEBUG1 - 21:30:25.376375261 [8383/8383]: consumerd64 err unix sock path:/var/run/lttng/ustconsumerd64/error
DEBUG1 - 21:30:25.376377263 [8383/8383]: consumerd64 cmd unix sock path:/var/run/lttng/ustconsumerd64/command
DEBUG1 - 21:30:25.376379252 [8383/8383]: kconsumerd path: /var/run/lttng/kconsumerd
DEBUG1 - 21:30:25.376381241 [8383/8383]: kconsumerd err unix sock path: /var/run/lttng/kconsumerd/error
DEBUG1 - 21:30:25.376383208 [8383/8383]: kconsumerd cmd unix sock path: /var/run/lttng/kconsumerd/command
DEBUG1 - 21:30:25.376386865 [8383/8383]: Starting lttng-sessiond {4477f5c0-a040-46ea-b1ae-eff8ff793e4e} (in sessiond_uuid_log() at main.c:1282)
DEBUG3 - 21:30:25.376389484 [8383/8383]: Creating LTTng run directory: /var/run/lttng (in create_lttng_rundir() at main.c:995)
DEBUG1 - 21:30:25.376592189 [8384/8384]: Resetting run_as worker signal handlers to default (in reset_sighandler() at runas.c:1117)
DEBUG1 - 21:30:25.376656518 [8384/8384]: run_as signal handler set for SIGTERM and SIGINT (in set_worker_sighandlers() at runas.c:1178)
DEBUG1 - 21:30:25.377758142 [8383/8383]: Health check time delta in seconds set to 20 (in health_init() at health.c:63)
DEBUG1 - 21:30:25.377882241 [8383/8385]: Launching "HT cleanup" thread (in launch_thread() at thread.c:64)
DEBUG1 - 21:30:25.377901955 [8383/8385]: [ht-thread] startup. (in thread_ht_cleanup() at ht-cleanup.c:98)
DEBUG1 - 21:30:25.377932090 [8383/8385]: epoll set max size is 3331051 (in compat_epoll_set_max_size() at compat-epoll.c:346)
DEBUG3 - 21:30:25.377971413 [8383/8385]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)
DEBUG3 - 21:30:25.378029241 [8383/8383]: Created hashtable size 4 at 0x5652d1320a60 of type 1 (in lttng_ht_new() at hashtable.c:135)
DEBUG3 - 21:30:25.378039615 [8383/8383]: Created hashtable size 4 at 0x5652d1320fa0 of type 1 (in lttng_ht_new() at hashtable.c:135)
DEBUG3 - 21:30:25.378045534 [8383/8383]: Created hashtable size 4 at 0x5652d1321e00 of type 1 (in lttng_ht_new() at hashtable.c:135)
DEBUG3 - 21:30:25.378050587 [8383/8383]: Created hashtable size 4 at 0x5652d1322300 of type 1 (in lttng_ht_new() at hashtable.c:135)
DEBUG2 - 21:30:25.378054565 [8383/8383]: Creating consumer directory: /var/run/lttng/kconsumerd (in set_consumer_sockets() at main.c:1037)
DEBUG1 - 21:30:25.408724225 [8383/8383]: Modprobe successfully lttng-ring-buffer-client-discard (in modprobe_lttng() at modprobe.c:337)
DEBUG1 - 21:30:25.411088708 [8383/8383]: Modprobe successfully lttng-ring-buffer-client-overwrite (in modprobe_lttng() at modprobe.c:337)
DEBUG1 - 21:30:25.413756594 [8383/8383]: Modprobe successfully lttng-ring-buffer-metadata-client (in modprobe_lttng() at modprobe.c:337)
DEBUG1 - 21:30:25.416138527 [8383/8383]: Modprobe successfully lttng-ring-buffer-client-mmap-discard (in modprobe_lttng() at modprobe.c:337)
DEBUG1 - 21:30:25.418465408 [8383/8383]: Modprobe successfully lttng-ring-buffer-client-mmap-overwrite (in modprobe_lttng() at modprobe.c:337)
DEBUG1 - 21:30:25.420773383 [8383/8383]: Modprobe successfully lttng-ring-buffer-metadata-mmap-client (in modprobe_lttng() at modprobe.c:337)
DEBUG2 - 21:30:25.420801435 [8383/8383]: Kernel tracer version validated (2.11, ABI 2.3) (in kernel_validate_version() at kernel.c:1294)
DEBUG1 - 21:30:25.423081090 [8383/8383]: Modprobe successfully lttng-probe-asoc (in modprobe_lttng() at modprobe.c:337)
DEBUG1 - 21:30:25.425640174 [8383/8383]: Modprobe successfully lttng-probe-block (in modprobe_lttng() at modprobe.c:337)
DEBUG1 - 21:30:25.427310797 [8383/8383]: Unable to load optional module lttng-probe-btrfs; continuing (in modprobe_lttng() at modprobe.c:333)
DEBUG1 - 21:30:25.429383198 [8383/8383]: Modprobe successfully lttng-probe-compaction (in modprobe_lttng() at modprobe.c:337)
DEBUG1 - 21:30:25.430775112 [8383/8383]: Unable to load optional module lttng-probe-ext3; continuing (in modprobe_lttng() at modprobe.c:333)
DEBUG1 - 21:30:25.432048799 [8383/8383]: Unable to load optional module lttng-probe-ext4; continuing (in modprobe_lttng() at modprobe.c:333)
DEBUG1 - 21:30:25.434080837 [8383/8383]: Modprobe successfully lttng-probe-gpio (in modprobe_lttng() at modprobe.c:337)
DEBUG1 - 21:30:25.436463014 [8383/8383]: Modprobe successfully lttng-probe-i2c (in modprobe_lttng() at modprobe.c:337)
DEBUG1 - 21:30:25.438669363 [8383/8383]: Modprobe successfully lttng-probe-irq (in modprobe_lttng() at modprobe.c:337)
DEBUG1 - 21:30:25.440275691 [8383/8383]: Unable to load optional module lttng-probe-jbd; continuing (in modprobe_lttng() at modprobe.c:333)
DEBUG1 - 21:30:25.442495025 [8383/8383]: Modprobe successfully lttng-probe-jbd2 (in modprobe_lttng() at modprobe.c:337)
DEBUG1 - 21:30:25.445035941 [8383/8383]: Modprobe successfully lttng-probe-kmem (in modprobe_lttng() at modprobe.c:337)
DEBUG1 - 21:30:25.447490061 [8383/8383]: Modprobe successfully lttng-probe-kvm (in modprobe_lttng() at modprobe.c:337)
DEBUG1 - 21:30:25.449394364 [8383/8383]: Unable to load optional module lttng-probe-kvm-x86; continuing (in modprobe_lttng() at modprobe.c:333)
DEBUG1 - 21:30:25.451022640 [8383/8383]: Unable to load optional module lttng-probe-kvm-x86-mmu; continuing (in modprobe_lttng() at modprobe.c:333)
DEBUG1 - 21:30:25.452768283 [8383/8383]: Unable to load optional module lttng-probe-lock; continuing (in modprobe_lttng() at modprobe.c:333)
DEBUG1 - 21:30:25.455523968 [8383/8383]: Modprobe successfully lttng-probe-module (in modprobe_lttng() at modprobe.c:337)
DEBUG1 - 21:30:25.459283597 [8383/8383]: Modprobe successfully lttng-probe-napi (in modprobe_lttng() at modprobe.c:337)
DEBUG1 - 21:30:25.462131602 [8383/8383]: Modprobe successfully lttng-probe-net (in modprobe_lttng() at modprobe.c:337)
DEBUG1 - 21:30:25.464711559 [8383/8383]: Modprobe successfully lttng-probe-power (in modprobe_lttng() at modprobe.c:337)
DEBUG1 - 21:30:25.466238680 [8383/8383]: Unable to load optional module lttng-probe-preemptirq; continuing (in modprobe_lttng() at modprobe.c:333)
DEBUG1 - 21:30:25.468201478 [8383/8383]: Modprobe successfully lttng-probe-printk (in modprobe_lttng() at modprobe.c:337)
DEBUG1 - 21:30:25.470328455 [8383/8383]: Modprobe successfully lttng-probe-random (in modprobe_lttng() at modprobe.c:337)
DEBUG1 - 21:30:25.472467012 [8383/8383]: Modprobe successfully lttng-probe-rcu (in modprobe_lttng() at modprobe.c:337)
DEBUG1 - 21:30:25.474186559 [8383/8383]: Unable to load optional module lttng-probe-regmap; continuing (in modprobe_lttng() at modprobe.c:333)
DEBUG1 - 21:30:25.476349860 [8383/8383]: Modprobe successfully lttng-probe-regulator (in modprobe_lttng() at modprobe.c:337)
DEBUG1 - 21:30:25.477842066 [8383/8383]: Unable to load optional module lttng-probe-rpm; continuing (in modprobe_lttng() at modprobe.c:333)
DEBUG1 - 21:30:25.480094749 [8383/8383]: Modprobe successfully lttng-probe-sched (in modprobe_lttng() at modprobe.c:337)
DEBUG1 - 21:30:25.482643203 [8383/8383]: Modprobe successfully lttng-probe-scsi (in modprobe_lttng() at modprobe.c:337)
DEBUG1 - 21:30:25.485227481 [8383/8383]: Modprobe successfully lttng-probe-signal (in modprobe_lttng() at modprobe.c:337)
DEBUG1 - 21:30:25.487697011 [8383/8383]: Modprobe successfully lttng-probe-skb (in modprobe_lttng() at modprobe.c:337)
DEBUG1 - 21:30:25.489984917 [8383/8383]: Modprobe successfully lttng-probe-sock (in modprobe_lttng() at modprobe.c:337)
DEBUG1 - 21:30:25.492439471 [8383/8383]: Modprobe successfully lttng-probe-statedump (in modprobe_lttng() at modprobe.c:337)
DEBUG1 - 21:30:25.494754041 [8383/8383]: Modprobe successfully lttng-probe-sunrpc (in modprobe_lttng() at modprobe.c:337)
DEBUG1 - 21:30:25.497201642 [8383/8383]: Modprobe successfully lttng-probe-timer (in modprobe_lttng() at modprobe.c:337)
DEBUG1 - 21:30:25.499429112 [8383/8383]: Modprobe successfully lttng-probe-udp (in modprobe_lttng() at modprobe.c:337)
DEBUG1 - 21:30:25.501484641 [8383/8383]: Modprobe successfully lttng-probe-vmscan (in modprobe_lttng() at modprobe.c:337)
DEBUG1 - 21:30:25.504240012 [8383/8383]: Modprobe successfully lttng-probe-v4l2 (in modprobe_lttng() at modprobe.c:337)
DEBUG1 - 21:30:25.506455683 [8383/8383]: Modprobe successfully lttng-probe-workqueue (in modprobe_lttng() at modprobe.c:337)
DEBUG1 - 21:30:25.508799955 [8383/8383]: Modprobe successfully lttng-probe-writeback (in modprobe_lttng() at modprobe.c:337)
DEBUG1 - 21:30:25.510217069 [8383/8383]: Unable to load optional module lttng-probe-x86-irq-vectors; continuing (in modprobe_lttng() at modprobe.c:333)
DEBUG1 - 21:30:25.511533272 [8383/8383]: Unable to load optional module lttng-probe-x86-exceptions; continuing (in modprobe_lttng() at modprobe.c:333)
DEBUG1 - 21:30:25.511557307 [8383/8383]: Kernel tracer fd 21 (in init_kernel_tracer() at kernel.c:1742)
DEBUG3 - 21:30:25.511560700 [8383/8383]: Syscall init system call table (in syscall_init_table() at lttng-syscall.c:42)
DEBUG1 - 21:30:25.511825213 [8383/8383]: Reallocating syscall table from 256 to 512 entries (in syscall_init_table() at lttng-syscall.c:88)
DEBUG1 - 21:30:25.512125515 [8383/8383]: Reallocating syscall table from 512 to 1024 entries (in syscall_init_table() at lttng-syscall.c:88)
DEBUG2 - 21:30:25.512335265 [8383/8383]: Creating consumer directory: /var/run/lttng/ustconsumerd64 (in set_consumer_sockets() at main.c:1037)
DEBUG2 - 21:30:25.512396245 [8383/8383]: Creating consumer directory: /var/run/lttng/ustconsumerd32 (in set_consumer_sockets() at main.c:1037)
DEBUG3 - 21:30:25.512446633 [8383/8383]: Created hashtable size 4 at 0x5652d13253d0 of type 2 (in lttng_ht_new() at hashtable.c:135)
DEBUG3 - 21:30:25.512451233 [8383/8383]: Global buffer per UID registry initialized (in buffer_reg_init_uid_registry() at buffer-registry.c:90)
DEBUG3 - 21:30:25.512454305 [8383/8383]: Created hashtable size 4 at 0x5652d1325910 of type 2 (in lttng_ht_new() at hashtable.c:135)
DEBUG3 - 21:30:25.512456524 [8383/8383]: Global buffer per PID registry initialized (in buffer_reg_init_pid_registry() at buffer-registry.c:219)
DEBUG1 - 21:30:25.512458837 [8383/8383]: Command subsystem initialized (in cmd_init() at cmd.c:5442)
DEBUG1 - 21:30:25.512474805 [8383/8383]: Pid 8383 written in file /var/run/lttng/lttng-sessiond.pid (in utils_create_pid_file() at utils.c:614)
DEBUG1 - 21:30:25.512495578 [8383/8383]: TCP inet operation timeout set to 216 sec (in lttcomm_inet_init() at inet.c:545)
DEBUG1 - 21:30:25.512526378 [8383/8383]: Waiting for health management thread to be ready (in wait_until_thread_is_ready() at health.c:35)
DEBUG1 - 21:30:25.512530730 [8383/8526]: Launching "Health management" thread (in launch_thread() at thread.c:64)
DEBUG1 - 21:30:25.512543764 [8383/8526]: [thread] Manage health check started (in thread_manage_health() at health.c:65)
DEBUG1 - 21:30:25.512605389 [8383/8526]: Marking health management thread as ready (in mark_thread_as_ready() at health.c:28)
DEBUG1 - 21:30:25.512612297 [8383/8526]: Health check ready (in thread_manage_health() at health.c:136)
DEBUG1 - 21:30:25.512615824 [8383/8383]: Health management thread is ready (in wait_until_thread_is_ready() at health.c:37)
DEBUG1 - 21:30:25.512647054 [8383/8383]: Waiting for notification thread to be ready (in wait_until_thread_is_ready() at notification-thread.c:387)
DEBUG1 - 21:30:25.512650381 [8383/8527]: Launching "Notification" thread (in launch_thread() at thread.c:64)
DEBUG1 - 21:30:25.512660933 [8383/8527]: [notification-thread] Started notification thread (in thread_notification() at notification-thread.c:521)
DEBUG1 - 21:30:25.512673192 [8383/8527]: [notification-thread] Creating notification channel UNIX socket at /var/run/lttng/sessiond-notification (in notification_channel_socket_create() at notification-thread.c:215)
DEBUG1 - 21:30:25.512714075 [8383/8527]: [notification-thread] Notification channel UNIX socket created (fd = 36) (in notification_channel_socket_create() at notification-thread.c:250)
DEBUG1 - 21:30:25.512733931 [8383/8527]: [notification-thread] Listening on notification channel socket (in init_thread_state() at notification-thread.c:414)
DEBUG1 - 21:30:25.512744632 [8383/8527]: Marking notification thread as ready (in mark_thread_as_ready() at notification-thread.c:380)
DEBUG1 - 21:30:25.512749626 [8383/8527]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:543)
DEBUG1 - 21:30:25.512753296 [8383/8383]: Notification thread is ready (in wait_until_thread_is_ready() at notification-thread.c:389)
DEBUG1 - 21:30:25.512782849 [8383/8528]: Launching "Timer" thread (in launch_thread() at thread.c:64)
DEBUG1 - 21:30:25.512824734 [8383/8383]: Created client socket (fd = 42) (in create_client_sock() at client.c:2133)
DEBUG1 - 21:30:25.512824966 [8383/8529]: Launching "Rotation" thread (in launch_thread() at thread.c:64)
DEBUG1 - 21:30:25.512847646 [8383/8529]: [rotation-thread] Started rotation thread (in thread_rotation() at rotation-thread.c:772)
DEBUG1 - 21:30:25.512864328 [8383/8383]: Waiting for client thread to be ready (in wait_thread_status() at client.c:51)
DEBUG1 - 21:30:25.512867381 [8383/8530]: Launching "Client management" thread (in launch_thread() at thread.c:64)
DEBUG1 - 21:30:25.512877081 [8383/8530]: [thread] Manage client started (in thread_manage_clients() at client.c:2167)
DEBUG1 - 21:30:25.512904595 [8383/8530]: Marking client thread's state as running (in set_thread_status() at client.c:44)
DEBUG1 - 21:30:25.512905509 [8383/8527]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:545)
DEBUG1 - 21:30:25.512918106 [8383/8383]: Client thread is ready (in wait_thread_status() at client.c:54)
DEBUG1 - 21:30:25.512921719 [8383/8527]: [notification-thread] Handling fd (36) activity (1) (in thread_notification() at notification-thread.c:563)
DEBUG1 - 21:30:25.512915149 [8383/8530]: Accepting client command ... (in thread_manage_clients() at client.c:2223)
DEBUG1 - 21:30:25.512928202 [8383/8527]: [notification-thread] Handling new notification channel client connection (in handle_notification_thread_client_connect() at notification-thread-events.c:2414)
DEBUG1 - 21:30:25.512948851 [8383/8527]: Client socket (fd = 47) set as non-blocking (in socket_set_non_blocking() at notification-thread-events.c:2382)
DEBUG1 - 21:30:25.512959016 [8383/8527]: [notification-thread] Added new notification channel client socket (47) to poll set (in handle_notification_thread_client_connect() at notification-thread-events.c:2464)
DEBUG1 - 21:30:25.512969826 [8383/8383]: All permissions are set (in set_permissions() at main.c:983)
DEBUG1 - 21:30:25.512972887 [8383/8527]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:543)
DEBUG1 - 21:30:25.512978380 [8383/8527]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:545)
DEBUG1 - 21:30:25.512981825 [8383/8527]: [notification-thread] Handling fd (47) activity (1) (in thread_notification() at notification-thread.c:563)
DEBUG1 - 21:30:25.512989675 [8383/8527]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:543)
DEBUG1 - 21:30:25.512993846 [8383/8527]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:545)
DEBUG1 - 21:30:25.512997396 [8383/8527]: [notification-thread] Handling fd (47) activity (1) (in thread_notification() at notification-thread.c:563)
DEBUG1 - 21:30:25.513006157 [8383/8527]: [notification-thread] Received handshake from client (uid = 0, gid = 0) with version 1.1 (in client_dispatch_message() at notification-thread-events.c:2765)
DEBUG1 - 21:30:25.513011142 [8383/8527]: [notification-thread] Flushing client (socket fd = 47) outgoing queue (in client_flush_outgoing_queue() at notification-thread-events.c:2562)
DEBUG3 - 21:30:25.513015120 [8383/8383]: Session daemon application socket created (fd = 49) (in create_application_socket() at register.c:69)
DEBUG1 - 21:30:25.513021625 [8383/8527]: [notification-thread] Send command reply (0) (in client_send_command_reply() at notification-thread-events.c:2646)
DEBUG1 - 21:30:25.513025754 [8383/8527]: [notification-thread] Flushing client (socket fd = 47) outgoing queue (in client_flush_outgoing_queue() at notification-thread-events.c:2562)
DEBUG1 - 21:30:25.513034044 [8383/8527]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:543)
DEBUG1 - 21:30:25.513039622 [8383/8383]: Waiting for application registration thread to be ready (in wait_thread_status() at register.c:129)
DEBUG1 - 21:30:25.513043276 [8383/8532]: Launching "UST application registration" thread (in launch_thread() at thread.c:64)
DEBUG1 - 21:30:25.513039791 [8383/8529]: [rotation-thread] Entering poll wait (in thread_rotation() at rotation-thread.c:796)
DEBUG1 - 21:30:25.513058124 [8383/8532]: [thread] Manage application registration started (in thread_application_registration() at register.c:166)
DEBUG1 - 21:30:25.513081277 [8383/8532]: Marking application registration thread's state as running (in set_thread_status() at register.c:122)
DEBUG1 - 21:30:25.513081351 [8383/8531]: Launching "UST registration dispatch" thread (in launch_thread() at thread.c:64)
DEBUG1 - 21:30:25.513091875 [8383/8532]: Accepting application registration (in thread_application_registration() at register.c:205)
DEBUG1 - 21:30:25.513094559 [8383/8383]: Application registration thread is ready (in wait_thread_status() at register.c:132)
DEBUG1 - 21:30:25.513104673 [8383/8531]: [thread] Dispatch UST command started (in thread_dispatch_ust_registration() at dispatch.c:244)
DEBUG1 - 21:30:25.513117594 [8383/8383]: Notifying applications of session daemon state: 1 (in notify_ust_apps() at register.c:90)
DEBUG1 - 21:30:25.513123109 [8383/8531]: Futex n to 1 prepare done (in futex_nto1_prepare() at futex.c:67)
DEBUG1 - 21:30:25.513140280 [8383/8531]: Woken up but nothing in the UST command queue (in thread_dispatch_ust_registration() at dispatch.c:273)
DEBUG1 - 21:30:25.513165825 [8383/8383]: Got the wait shm fd 51 (in get_wait_shm() at shm.c:138)
DEBUG1 - 21:30:25.513181110 [8383/8383]: Futex wait update active 1 (in futex_wait_update() at futex.c:55)
DEBUG1 - 21:30:25.513236220 [8383/8534]: Launching "Application notification" thread (in launch_thread() at thread.c:64)
DEBUG1 - 21:30:25.513250158 [8383/8534]: [ust-thread] Manage application notify command (in thread_application_notification() at notify-apps.c:39)
DEBUG1 - 21:30:25.513256966 [8383/8383]: Waiting for agent management thread to be ready (in wait_until_thread_is_ready() at agent-thread.c:301)
DEBUG1 - 21:30:25.513260273 [8383/8535]: Launching "Agent management" thread (in launch_thread() at thread.c:64)
DEBUG3 - 21:30:25.513272949 [8383/8534]: [ust-thread] Manage notify polling (in thread_application_notification() at notify-apps.c:74)
DEBUG1 - 21:30:25.513266605 [8383/8533]: Launching "UST application management" thread (in launch_thread() at thread.c:64)
DEBUG1 - 21:30:25.513276262 [8383/8535]: [agent-thread] Manage agent application registration. (in thread_agent_management() at agent-thread.c:319)
DEBUG1 - 21:30:25.513287136 [8383/8533]: [thread] Manage application started (in thread_application_management() at manage-apps.c:52)
DEBUG3 - 21:30:25.513301704 [8383/8535]: URI string: tcp://localhost (in uri_parse() at uri.c:298)
DEBUG1 - 21:30:25.513336621 [8383/8533]: Apps thread polling (in thread_application_management() at manage-apps.c:88)
DEBUG2 - 21:30:25.513407615 [8383/8535]: IP address resolved to 127.0.0.1 (in set_ip_address() at uri.c:155)
DEBUG3 - 21:30:25.513412434 [8383/8535]: URI dtype: 1, proto: 1, host: localhost, subdir: , ctrl: 0, data: 0 (in uri_parse() at uri.c:512)
DEBUG3 - 21:30:25.513421976 [8383/8535]: [agent-thread] Trying to bind on port 5345 (in init_tcp_socket() at agent-thread.c:119)
DEBUG1 - 21:30:25.513429640 [8383/8535]: [agent-thread] Listening on TCP port 5345 and socket 60 (in init_tcp_socket() at agent-thread.c:156)
DEBUG1 - 21:30:25.513444842 [8383/8535]: Pid 5345 written in file /var/run/lttng/agent.port (in utils_create_pid_file() at utils.c:614)
DEBUG1 - 21:30:25.513448642 [8383/8535]: Marking agent management thread as ready (in mark_thread_as_ready() at agent-thread.c:294)
DEBUG3 - 21:30:25.513454150 [8383/8535]: [agent-thread] Manage agent polling (in thread_agent_management() at agent-thread.c:373)
DEBUG1 - 21:30:25.513454775 [8383/8383]: Agent management thread is ready (in wait_until_thread_is_ready() at agent-thread.c:303)
DEBUG1 - 21:30:25.513488934 [8383/8536]: Launching "Kernel management" thread (in launch_thread() at thread.c:64)
DEBUG1 - 21:30:25.513501764 [8383/8536]: [thread] Thread manage kernel started (in thread_kernel_management() at manage-kernel.c:173)
DEBUG1 - 21:30:25.513522963 [8383/8536]: Updating kernel poll set (in update_kernel_poll() at manage-kernel.c:37)
DEBUG1 - 21:30:25.513530175 [8383/8536]: Thread kernel polling (in thread_kernel_management() at manage-kernel.c:227)
DEBUG1 - 21:31:07.359929897 [8383/8530]: Wait for client response (in thread_manage_clients() at client.c:2265)
DEBUG1 - 21:31:07.359982977 [8383/8530]: Receiving data from client ... (in thread_manage_clients() at client.c:2310)
DEBUG1 - 21:31:07.359994953 [8383/8530]: Nothing recv() from client... continuing (in thread_manage_clients() at client.c:2314)
DEBUG1 - 21:31:07.360009469 [8383/8530]: Clean command context structure (in clean_command_ctx() at client.c:650)
DEBUG1 - 21:31:07.360016739 [8383/8530]: Accepting client command ... (in thread_manage_clients() at client.c:2223)
DEBUG1 - 21:31:07.360023960 [8383/8530]: Wait for client response (in thread_manage_clients() at client.c:2265)
DEBUG1 - 21:31:07.360037034 [8383/8530]: Receiving data from client ... (in thread_manage_clients() at client.c:2310)
DEBUG1 - 21:31:07.360044975 [8383/8530]: Nothing recv() from client... continuing (in thread_manage_clients() at client.c:2314)
DEBUG1 - 21:31:07.360055162 [8383/8530]: Clean command context structure (in clean_command_ctx() at client.c:650)
DEBUG1 - 21:31:07.360060220 [8383/8530]: Accepting client command ... (in thread_manage_clients() at client.c:2223)
DEBUG1 - 21:31:07.360184084 [8383/8530]: Wait for client response (in thread_manage_clients() at client.c:2265)
DEBUG1 - 21:31:07.360209063 [8383/8530]: Receiving data from client ... (in thread_manage_clients() at client.c:2310)
DEBUG1 - 21:31:07.360217292 [8383/8530]: Nothing recv() from client... continuing (in thread_manage_clients() at client.c:2314)
DEBUG1 - 21:31:07.360229685 [8383/8530]: Clean command context structure (in clean_command_ctx() at client.c:650)
DEBUG1 - 21:31:07.360234849 [8383/8530]: Accepting client command ... (in thread_manage_clients() at client.c:2223)
DEBUG1 - 21:31:07.360249308 [8383/8530]: Wait for client response (in thread_manage_clients() at client.c:2265)
DEBUG1 - 21:31:07.360256563 [8383/8530]: Receiving data from client ... (in thread_manage_clients() at client.c:2310)
DEBUG1 - 21:31:07.360270298 [8383/8530]: Processing client command 49 (in process_client_msg() at client.c:714)
DEBUG2 - 21:31:07.360298084 [8383/8530]: Trying to find session by name life (in session_find_by_name() at session.c:1000)
DEBUG3 - 21:31:07.360320765 [8383/8530]: Created hashtable size 4 at 0x7f89e00120e0 of type 1 (in lttng_ht_new() at hashtable.c:135)
DEBUG3 - 21:31:07.360327638 [8383/8530]: Created hashtable size 4 at 0x7f89e0012620 of type 1 (in lttng_ht_new() at hashtable.c:135)
DEBUG1 - 21:31:07.360330585 [8383/8530]: Allocating ltt_sessions_ht_by_id (in ltt_sessions_ht_alloc() at session.c:304)
DEBUG3 - 21:31:07.360334964 [8383/8530]: Created hashtable size 4 at 0x7f89e0012b60 of type 2 (in lttng_ht_new() at hashtable.c:135)
DEBUG1 - 21:31:07.360338528 [8383/8530]: Tracing session life created with ID 0 by uid = 90709, gid = 64000 (in session_create() at session.c:1207)
DEBUG2 - 21:31:07.360344803 [8383/8530]: Setting trace directory path from URI to /home/ematkho/src/arraise/trace (in add_uri_to_consumer() at cmd.c:904)
DEBUG1 - 21:31:07.360358346 [8383/8530]: Sending response (size: 8242, retcode: Success (10)) (in thread_manage_clients() at client.c:2375)
DEBUG1 - 21:31:07.360370160 [8383/8530]: Clean command context structure (in clean_command_ctx() at client.c:650)
DEBUG1 - 21:31:07.360384711 [8383/8530]: Accepting client command ... (in thread_manage_clients() at client.c:2223)
DEBUG1 - 21:31:07.360453884 [8383/8530]: Wait for client response (in thread_manage_clients() at client.c:2265)
DEBUG1 - 21:31:07.360473211 [8383/8530]: Receiving data from client ... (in thread_manage_clients() at client.c:2310)
DEBUG1 - 21:31:07.360479411 [8383/8530]: Nothing recv() from client... continuing (in thread_manage_clients() at client.c:2314)
DEBUG1 - 21:31:07.360487700 [8383/8530]: Clean command context structure (in clean_command_ctx() at client.c:650)
DEBUG1 - 21:31:07.360490546 [8383/8530]: Accepting client command ... (in thread_manage_clients() at client.c:2223)
DEBUG1 - 21:31:07.360493858 [8383/8530]: Wait for client response (in thread_manage_clients() at client.c:2265)
DEBUG1 - 21:31:07.360500448 [8383/8530]: Receiving data from client ... (in thread_manage_clients() at client.c:2310)
DEBUG1 - 21:31:07.360508501 [8383/8530]: Processing client command 13 (in process_client_msg() at client.c:714)
DEBUG1 - 21:31:07.360515151 [8383/8530]: Counting number of available session for UID 90709 GID 64000 (in lttng_sessions_count() at client.c:513)
DEBUG1 - 21:31:07.360519122 [8383/8530]: Getting all available session for UID 90709 GID 64000 (in cmd_list_lttng_sessions() at cmd.c:3733)
DEBUG1 - 21:31:07.360524289 [8383/8530]: Sending response (size: 4412, retcode: Success (10)) (in thread_manage_clients() at client.c:2375)
DEBUG1 - 21:31:07.360538267 [8383/8530]: Clean command context structure (in clean_command_ctx() at client.c:650)
DEBUG1 - 21:31:07.360545782 [8383/8530]: Accepting client command ... (in thread_manage_clients() at client.c:2223)
DEBUG1 - 21:31:07.364678687 [8383/8530]: Wait for client response (in thread_manage_clients() at client.c:2265)
DEBUG1 - 21:31:07.364720504 [8383/8530]: Receiving data from client ... (in thread_manage_clients() at client.c:2310)
DEBUG1 - 21:31:07.364727904 [8383/8530]: Nothing recv() from client... continuing (in thread_manage_clients() at client.c:2314)
DEBUG1 - 21:31:07.364739179 [8383/8530]: Clean command context structure (in clean_command_ctx() at client.c:650)
DEBUG1 - 21:31:07.364743778 [8383/8530]: Accepting client command ... (in thread_manage_clients() at client.c:2223)
DEBUG1 - 21:31:07.364749611 [8383/8530]: Wait for client response (in thread_manage_clients() at client.c:2265)
DEBUG1 - 21:31:07.364758409 [8383/8530]: Receiving data from client ... (in thread_manage_clients() at client.c:2310)
DEBUG1 - 21:31:07.364772206 [8383/8530]: Processing client command 6 (in process_client_msg() at client.c:714)
DEBUG1 - 21:31:07.364780393 [8383/8530]: Getting session life by name (in process_client_msg() at client.c:811)
DEBUG2 - 21:31:07.364785391 [8383/8530]: Trying to find session by name life (in session_find_by_name() at session.c:1000)
DEBUG1 - 21:31:07.364790433 [8383/8530]: Creating UST session (in create_ust_session() at client.c:427)
DEBUG3 - 21:31:07.364804783 [8383/8530]: Created hashtable size 4 at 0x7f89e0005ed0 of type 0 (in lttng_ht_new() at hashtable.c:135)
DEBUG3 - 21:31:07.364812128 [8383/8530]: Created hashtable size 4 at 0x7f89e0006410 of type 2 (in lttng_ht_new() at hashtable.c:135)
DEBUG3 - 21:31:07.364829977 [8383/8530]: Created hashtable size 4 at 0x7f89e0007940 of type 1 (in lttng_ht_new() at hashtable.c:135)
DEBUG2 - 21:31:07.364835266 [8383/8530]: UST trace session create successful (in trace_ust_create_session() at trace-ust.c:323)
DEBUG3 - 21:31:07.364851724 [8383/8530]: Copying tracing session consumer output in UST session (in copy_session_consumer() at client.c:371)
DEBUG3 - 21:31:07.364865956 [8383/8530]: Created hashtable size 4 at 0x7f89e0007e80 of type 1 (in lttng_ht_new() at hashtable.c:135)
DEBUG3 - 21:31:07.364874922 [8383/8530]: Copy session consumer subdir ust (in copy_session_consumer() at client.c:393)
DEBUG3 - 21:31:07.364872689 [8383/8385]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:126)
DEBUG1 - 21:31:07.364882800 [8383/8530]: Spawning consumerd (in spawn_consumerd() at client.c:133)
DEBUG2 - 21:31:07.365305310 [8383/8530]: Consumer pid 8577 (in start_consumerd() at client.c:307)
DEBUG2 - 21:31:07.365325510 [8383/8530]: Spawning consumer control thread (in start_consumerd() at client.c:310)
DEBUG1 - 21:31:07.365401640 [8383/8530]: Waiting for consumer management thread to be ready (in wait_until_thread_is_ready() at manage-consumer.c:46)
DEBUG1 - 21:31:07.365396365 [8577/8577]: Using 64-bit UST consumer at: /usr/lib/x86_64-linux-gnu/lttng/libexec/lttng-consumerd (in spawn_consumerd() at client.c:211)
DEBUG3 - 21:31:07.365501104 [8383/8385]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)
DEBUG1 - 21:31:07.365573367 [8383/8578]: Launching "Consumer management" thread (in launch_thread() at thread.c:64)
DEBUG1 - 21:31:07.365589579 [8383/8578]: [thread] Manage consumer started (in thread_consumer_management() at manage-consumer.c:65)
DEBUG2 - 21:31:07.418931733 [8383/8578]: Receiving code from consumer err_sock (in thread_consumer_management() at manage-consumer.c:162)
DEBUG1 - 21:31:07.519496009 [8383/8578]: Consumer command socket ready (fd: 70) (in thread_consumer_management() at manage-consumer.c:204)
DEBUG1 - 21:31:07.519511401 [8383/8578]: Consumer metadata socket ready (fd: 71) (in thread_consumer_management() at manage-consumer.c:206)
DEBUG1 - 21:31:07.519530353 [8383/8578]: Sending consumer initialization command (in consumer_init() at consumer.c:1758)
DEBUG3 - 21:31:07.519592512 [8383/8578]: Sending SET_CHANNEL_MONITOR_PIPE command to consumer (in consumer_send_pipe() at consumer.c:1223)
DEBUG3 - 21:31:07.519636047 [8383/8578]: Sending channel monitor pipe 18 to consumer on socket 70 (in consumer_send_pipe() at consumer.c:1231)
DEBUG2 - 21:31:07.519664782 [8383/8578]: channel monitor pipe successfully sent (in consumer_send_pipe() at consumer.c:1237)
DEBUG1 - 21:31:07.519714849 [8383/8578]: Marking consumer management thread as ready (in mark_thread_as_ready() at manage-consumer.c:31)
DEBUG1 - 21:31:07.519732853 [8383/8530]: Consumer management thread is ready (in wait_until_thread_is_ready() at manage-consumer.c:48)
DEBUG3 - 21:31:07.519754210 [8383/8530]: Consumer socket created (fd: 70) and added to output (in consumer_create_socket() at consumer.c:351)
DEBUG1 - 21:31:07.519761549 [8383/8530]: Setting relayd for session life (in cmd_setup_relayd() at cmd.c:1188)
DEBUG1 - 21:31:07.519770708 [8383/8530]: Enable event command for event '*' (in _cmd_enable_event() at cmd.c:2094)
DEBUG2 - 21:31:07.519778154 [8383/8530]: Trace UST channel channel0 not found by name (in trace_ust_find_channel_by_name() at trace-ust.c:187)
DEBUG1 - 21:31:07.519787454 [8383/8530]: Enabling channel for session life (in cmd_enable_channel() at cmd.c:1568)
DEBUG2 - 21:31:07.519793160 [8383/8530]: Trace UST channel channel0 not found by name (in trace_ust_find_channel_by_name() at trace-ust.c:187)
DEBUG3 - 21:31:07.519803279 [8383/8530]: Created hashtable size 4 at 0x7f89e0008ba0 of type 0 (in lttng_ht_new() at hashtable.c:135)
DEBUG3 - 21:31:07.519816250 [8383/8530]: Created hashtable size 4 at 0x7f89e00090a0 of type 1 (in lttng_ht_new() at hashtable.c:135)
DEBUG2 - 21:31:07.519821968 [8383/8530]: Trace UST channel channel0 created (in trace_ust_create_channel() at trace-ust.c:401)
DEBUG2 - 21:31:07.519829158 [8383/8530]: Channel channel0 is being created for UST with buffer 1 and id 0 (in channel_ust_create() at channel.c:452)
DEBUG2 - 21:31:07.519838325 [8383/8530]: Channel channel0 created successfully (in channel_ust_create() at channel.c:481)
DEBUG2 - 21:31:07.519844467 [8383/8530]: Trace UST channel channel0 found by name (in trace_ust_find_channel_by_name() at trace-ust.c:182)
DEBUG2 - 21:31:07.519850379 [8383/8530]: Trace UST event * NOT found (in trace_ust_find_event() at trace-ust.c:225)
DEBUG2 - 21:31:07.519856568 [8383/8530]: Trace UST event *, loglevel (0,-1) created (in trace_ust_create_event() at trace-ust.c:524)
DEBUG1 - 21:31:07.519874343 [8383/8530]: Sending response (size: 20, retcode: Success (10)) (in thread_manage_clients() at client.c:2375)
DEBUG1 - 21:31:07.519898276 [8383/8530]: Clean command context structure (in clean_command_ctx() at client.c:650)
DEBUG1 - 21:31:07.519904255 [8383/8530]: Accepting client command ... (in thread_manage_clients() at client.c:2223)
DEBUG1 - 21:31:07.523584534 [8383/8530]: Wait for client response (in thread_manage_clients() at client.c:2265)
DEBUG1 - 21:31:07.523616284 [8383/8530]: Receiving data from client ... (in thread_manage_clients() at client.c:2310)
DEBUG1 - 21:31:07.523623830 [8383/8530]: Nothing recv() from client... continuing (in thread_manage_clients() at client.c:2314)
DEBUG1 - 21:31:07.523635210 [8383/8530]: Clean command context structure (in clean_command_ctx() at client.c:650)
DEBUG1 - 21:31:07.523641309 [8383/8530]: Accepting client command ... (in thread_manage_clients() at client.c:2223)
DEBUG1 - 21:31:07.523647754 [8383/8530]: Wait for client response (in thread_manage_clients() at client.c:2265)
DEBUG1 - 21:31:07.523660941 [8383/8530]: Receiving data from client ... (in thread_manage_clients() at client.c:2310)
DEBUG1 - 21:31:07.523677434 [8383/8530]: Processing client command 0 (in process_client_msg() at client.c:714)
DEBUG1 - 21:31:07.523686891 [8383/8530]: Getting session life by name (in process_client_msg() at client.c:811)
DEBUG2 - 21:31:07.523692475 [8383/8530]: Trying to find session by name life (in session_find_by_name() at session.c:1000)
DEBUG3 - 21:31:07.523700475 [8383/8530]: Consumer socket created (fd: 70) and added to output (in consumer_create_socket() at consumer.c:351)
DEBUG1 - 21:31:07.523705935 [8383/8530]: Setting relayd for session life (in cmd_setup_relayd() at cmd.c:1188)
DEBUG1 - 21:31:07.523715512 [8383/8530]: Context UST 5 added to channel channel0 (in add_uctx_to_channel() at context.c:176)
DEBUG1 - 21:31:07.523721926 [8383/8530]: Sending response (size: 20, retcode: Success (10)) (in thread_manage_clients() at client.c:2375)
DEBUG1 - 21:31:07.523737299 [8383/8530]: Clean command context structure (in clean_command_ctx() at client.c:650)
DEBUG1 - 21:31:07.523743366 [8383/8530]: Accepting client command ... (in thread_manage_clients() at client.c:2223)
DEBUG1 - 21:31:07.523818149 [8383/8530]: Wait for client response (in thread_manage_clients() at client.c:2265)
DEBUG1 - 21:31:07.523836259 [8383/8530]: Receiving data from client ... (in thread_manage_clients() at client.c:2310)
DEBUG1 - 21:31:07.523841112 [8383/8530]: Nothing recv() from client... continuing (in thread_manage_clients() at client.c:2314)
DEBUG1 - 21:31:07.523849424 [8383/8530]: Clean command context structure (in clean_command_ctx() at client.c:650)
DEBUG1 - 21:31:07.523852653 [8383/8530]: Accepting client command ... (in thread_manage_clients() at client.c:2223)
DEBUG1 - 21:31:07.523856562 [8383/8530]: Wait for client response (in thread_manage_clients() at client.c:2265)
DEBUG1 - 21:31:07.523864110 [8383/8530]: Receiving data from client ... (in thread_manage_clients() at client.c:2310)
DEBUG1 - 21:31:07.523873199 [8383/8530]: Processing client command 0 (in process_client_msg() at client.c:714)
DEBUG1 - 21:31:07.523877073 [8383/8530]: Getting session life by name (in process_client_msg() at client.c:811)
DEBUG2 - 21:31:07.523880307 [8383/8530]: Trying to find session by name life (in session_find_by_name() at session.c:1000)
DEBUG3 - 21:31:07.523884278 [8383/8530]: Consumer socket created (fd: 70) and added to output (in consumer_create_socket() at consumer.c:351)
DEBUG1 - 21:31:07.523887449 [8383/8530]: Setting relayd for session life (in cmd_setup_relayd() at cmd.c:1188)
DEBUG1 - 21:31:07.523892766 [8383/8530]: Context UST 5 added to channel channel0 (in add_uctx_to_channel() at context.c:176)
DEBUG1 - 21:31:07.523896526 [8383/8530]: Sending response (size: 20, retcode: Success (10)) (in thread_manage_clients() at client.c:2375)
DEBUG1 - 21:31:07.523906172 [8383/8530]: Clean command context structure (in clean_command_ctx() at client.c:650)
DEBUG1 - 21:31:07.523909366 [8383/8530]: Accepting client command ... (in thread_manage_clients() at client.c:2223)
DEBUG1 - 21:31:07.527323520 [8383/8530]: Wait for client response (in thread_manage_clients() at client.c:2265)
DEBUG1 - 21:31:07.527357200 [8383/8530]: Receiving data from client ... (in thread_manage_clients() at client.c:2310)
DEBUG1 - 21:31:07.527367100 [8383/8530]: Nothing recv() from client... continuing (in thread_manage_clients() at client.c:2314)
DEBUG1 - 21:31:07.527379265 [8383/8530]: Clean command context structure (in clean_command_ctx() at client.c:650)
DEBUG1 - 21:31:07.527383350 [8383/8530]: Accepting client command ... (in thread_manage_clients() at client.c:2223)
DEBUG1 - 21:31:07.527388093 [8383/8530]: Wait for client response (in thread_manage_clients() at client.c:2265)
DEBUG1 - 21:31:07.527397851 [8383/8530]: Receiving data from client ... (in thread_manage_clients() at client.c:2310)
DEBUG1 - 21:31:07.527409949 [8383/8530]: Processing client command 6 (in process_client_msg() at client.c:714)
DEBUG1 - 21:31:07.527417645 [8383/8530]: Getting session life by name (in process_client_msg() at client.c:811)
DEBUG2 - 21:31:07.527421769 [8383/8530]: Trying to find session by name life (in session_find_by_name() at session.c:1000)
DEBUG1 - 21:31:07.527426115 [8383/8530]: Creating kernel session (in create_kernel_session() at client.c:472)
DEBUG3 - 21:31:07.527458357 [8383/8530]: Created hashtable size 4 at 0x7f89e00208c0 of type 1 (in lttng_ht_new() at hashtable.c:135)
DEBUG1 - 21:31:07.527501415 [8383/8530]: Kernel session created (fd: 72) (in kernel_create_session() at kernel.c:125)
Warning: Could not set kernel session name for session 0 name: life
Warning: Could not set kernel session creation time for session 0 name: life
DEBUG3 - 21:31:07.527513932 [8383/8530]: Copying tracing session consumer output in kernel session (in copy_session_consumer() at client.c:351)
DEBUG3 - 21:31:07.527532302 [8383/8530]: Created hashtable size 4 at 0x7f89e0020e00 of type 1 (in lttng_ht_new() at hashtable.c:135)
DEBUG3 - 21:31:07.527534912 [8383/8385]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:126)
DEBUG3 - 21:31:07.527540026 [8383/8530]: Copy session consumer subdir kernel (in copy_session_consumer() at client.c:393)
DEBUG1 - 21:31:07.527577947 [8383/8530]: Spawning consumerd (in spawn_consumerd() at client.c:133)
DEBUG3 - 21:31:07.527583636 [8383/8385]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)
DEBUG2 - 21:31:07.527954888 [8383/8530]: Consumer pid 8590 (in start_consumerd() at client.c:307)
DEBUG2 - 21:31:07.527970544 [8383/8530]: Spawning consumer control thread (in start_consumerd() at client.c:310)
DEBUG1 - 21:31:07.528031920 [8383/8530]: Waiting for consumer management thread to be ready (in wait_until_thread_is_ready() at manage-consumer.c:46)
DEBUG1 - 21:31:07.528038098 [8383/8591]: Launching "Consumer management" thread (in launch_thread() at thread.c:64)
DEBUG1 - 21:31:07.528053175 [8383/8591]: [thread] Manage consumer started (in thread_consumer_management() at manage-consumer.c:65)
DEBUG3 - 21:31:07.528070457 [8590/8590]: Looking for a kernel consumer at these locations: (in spawn_consumerd() at client.c:155)
DEBUG3 - 21:31:07.528118925 [8590/8590]: 1) /usr/lib/x86_64-linux-gnu/lttng/libexec/lttng-consumerd (in spawn_consumerd() at client.c:156)
DEBUG3 - 21:31:07.528124840 [8590/8590]: 2) /usr/lib/x86_64-linux-gnu/lttng/libexec/lttng-consumerd (in spawn_consumerd() at client.c:157)
DEBUG3 - 21:31:07.528130245 [8590/8590]: 3) NULL (in spawn_consumerd() at client.c:158)
DEBUG3 - 21:31:07.528148798 [8590/8590]: Found location #1 (in spawn_consumerd() at client.c:160)
DEBUG1 - 21:31:07.528154162 [8590/8590]: Using kernel consumer at: /usr/lib/x86_64-linux-gnu/lttng/libexec/lttng-consumerd (in spawn_consumerd() at client.c:174)
DEBUG2 - 21:31:07.586131348 [8383/8591]: Receiving code from consumer err_sock (in thread_consumer_management() at manage-consumer.c:162)
DEBUG1 - 21:31:07.686513613 [8383/8591]: Consumer command socket ready (fd: 77) (in thread_consumer_management() at manage-consumer.c:204)
DEBUG1 - 21:31:07.686528602 [8383/8591]: Consumer metadata socket ready (fd: 78) (in thread_consumer_management() at manage-consumer.c:206)
DEBUG1 - 21:31:07.686549838 [8383/8591]: Sending consumer initialization command (in consumer_init() at consumer.c:1758)
DEBUG3 - 21:31:07.686581991 [8383/8591]: Sending SET_CHANNEL_MONITOR_PIPE command to consumer (in consumer_send_pipe() at consumer.c:1223)
DEBUG3 - 21:31:07.686599574 [8383/8591]: Sending channel monitor pipe 12 to consumer on socket 77 (in consumer_send_pipe() at consumer.c:1231)
DEBUG2 - 21:31:07.686634339 [8383/8591]: channel monitor pipe successfully sent (in consumer_send_pipe() at consumer.c:1237)
DEBUG1 - 21:31:07.686640507 [8383/8591]: Marking consumer management thread as ready (in mark_thread_as_ready() at manage-consumer.c:31)
DEBUG1 - 21:31:07.686647240 [8383/8530]: Consumer management thread is ready (in wait_until_thread_is_ready() at manage-consumer.c:48)
DEBUG3 - 21:31:07.686656209 [8383/8530]: Consumer socket created (fd: 77) and added to output (in consumer_create_socket() at consumer.c:351)
DEBUG1 - 21:31:07.686658898 [8383/8530]: Setting relayd for session life (in cmd_setup_relayd() at cmd.c:1188)
DEBUG1 - 21:31:07.686662931 [8383/8530]: Enable event command for event '*' (in _cmd_enable_event() at cmd.c:2094)
DEBUG1 - 21:31:07.686665311 [8383/8530]: Trying to find channel channel0 (in trace_kernel_get_channel_by_name() at trace-kernel.c:46)
DEBUG1 - 21:31:07.686669306 [8383/8530]: Enabling channel for session life (in cmd_enable_channel() at cmd.c:1568)
DEBUG1 - 21:31:07.686673620 [8383/8530]: Trying to find channel channel0 (in trace_kernel_get_channel_by_name() at trace-kernel.c:46)
DEBUG3 - 21:31:07.686676460 [8383/8530]: Kernel create channel with attr: 0, 1048576, 4, 0, 200000, 0, 0 (in kernel_create_channel() at kernel.c:180)
DEBUG1 - 21:31:07.688970313 [8383/8530]: Kernel channel channel0 created (fd: 79, key: 1) (in kernel_create_channel() at kernel.c:204)
DEBUG1 - 21:31:07.689007895 [8383/8530]: Kernel quiescent wait on 21 (in kernel_wait_quiescent() at kernel.c:1023)
DEBUG1 - 21:31:07.689019064 [8383/8536]: Thread kernel return from poll on 2 fds (in thread_kernel_management() at manage-kernel.c:234)
DEBUG1 - 21:31:07.689041850 [8383/8536]: Updating kernel poll set (in update_kernel_poll() at manage-kernel.c:37)
DEBUG1 - 21:31:07.707282157 [8383/8530]: Trying to find channel channel0 (in trace_kernel_get_channel_by_name() at trace-kernel.c:46)
DEBUG1 - 21:31:07.707297135 [8383/8530]: Found channel by name channel0 (in trace_kernel_get_channel_by_name() at trace-kernel.c:50)
DEBUG1 - 21:31:07.707320662 [8383/8530]: Event * created (fd: 80) (in kernel_create_event() at kernel.c:539)
DEBUG1 - 21:31:07.707326665 [8383/8530]: Event * created (fd: 81) (in kernel_create_event() at kernel.c:539)
DEBUG1 - 21:31:07.707328906 [8383/8530]: Kernel quiescent wait on 21 (in kernel_wait_quiescent() at kernel.c:1023)
DEBUG1 - 21:31:07.723303873 [8383/8530]: Sending response (size: 20, retcode: Success (10)) (in thread_manage_clients() at client.c:2375)
DEBUG1 - 21:31:07.723313577 [8383/8536]: Channel fd 79 added to kernel set (in update_kernel_poll() at manage-kernel.c:60)
DEBUG1 - 21:31:07.723333953 [8383/8536]: Thread kernel polling (in thread_kernel_management() at manage-kernel.c:227)
DEBUG1 - 21:31:07.723340300 [8383/8536]: Thread kernel return from poll on 3 fds (in thread_kernel_management() at manage-kernel.c:234)
DEBUG1 - 21:31:07.723342812 [8383/8536]: Updating kernel streams for channel fd 79 (in update_kernel_stream() at manage-kernel.c:88)
DEBUG1 - 21:31:07.723345481 [8383/8536]: Channel found, updating kernel streams (in update_kernel_stream() at manage-kernel.c:111)
DEBUG1 - 21:31:07.723350470 [8383/8530]: Clean command context structure (in clean_command_ctx() at client.c:650)
DEBUG1 - 21:31:07.723354340 [8383/8530]: Accepting client command ... (in thread_manage_clients() at client.c:2223)
DEBUG1 - 21:31:07.723357522 [8383/8536]: Kernel stream channel0_0 created (fd: 65, state: 0) (in kernel_open_channel_stream() at kernel.c:1139)
DEBUG1 - 21:31:07.723364073 [8383/8536]: Kernel stream channel0_1 created (fd: 82, state: 0) (in kernel_open_channel_stream() at kernel.c:1139)
DEBUG1 - 21:31:07.723368776 [8383/8536]: Kernel stream channel0_2 created (fd: 83, state: 0) (in kernel_open_channel_stream() at kernel.c:1139)
DEBUG1 - 21:31:07.723372195 [8383/8536]: Kernel stream channel0_3 created (fd: 84, state: 0) (in kernel_open_channel_stream() at kernel.c:1139)
DEBUG1 - 21:31:07.723374792 [8383/8536]: Thread kernel polling (in thread_kernel_management() at manage-kernel.c:227)
DEBUG1 - 21:31:07.726008390 [8383/8530]: Wait for client response (in thread_manage_clients() at client.c:2265)
DEBUG1 - 21:31:07.726030777 [8383/8530]: Receiving data from client ... (in thread_manage_clients() at client.c:2310)
DEBUG1 - 21:31:07.726034782 [8383/8530]: Nothing recv() from client... continuing (in thread_manage_clients() at client.c:2314)
DEBUG1 - 21:31:07.726041027 [8383/8530]: Clean command context structure (in clean_command_ctx() at client.c:650)
DEBUG1 - 21:31:07.726043362 [8383/8530]: Accepting client command ... (in thread_manage_clients() at client.c:2223)
DEBUG1 - 21:31:07.726045911 [8383/8530]: Wait for client response (in thread_manage_clients() at client.c:2265)
DEBUG1 - 21:31:07.726050688 [8383/8530]: Receiving data from client ... (in thread_manage_clients() at client.c:2310)
DEBUG1 - 21:31:07.726057490 [8383/8530]: Processing client command 16 (in process_client_msg() at client.c:714)
DEBUG1 - 21:31:07.726061956 [8383/8530]: Getting session life by name (in process_client_msg() at client.c:811)
DEBUG2 - 21:31:07.726064386 [8383/8530]: Trying to find session by name life (in session_find_by_name() at session.c:1000)
DEBUG1 - 21:31:07.726069132 [8383/8530]: Creating initial trace chunk of session "life" (in cmd_start_trace() at cmd.c:2687)
DEBUG1 - 21:31:07.726073479 [8383/8530]: Creating trace chunk: chunk_id = 0, creation time = 20200306-213107 (in lttng_trace_chunk_create() at trace-chunk.c:422)
DEBUG1 - 21:31:07.726077528 [8383/8530]: Chunk name set to "(none)" (in lttng_trace_chunk_create() at trace-chunk.c:452)
DEBUG1 - 21:31:07.726079670 [8383/8530]: Creating base output directory of session "life" at /home/ematkho/src/arraise/trace (in session_create_new_trace_chunk() at session.c:653)
DEBUG3 - 21:31:07.726082654 [8383/8530]: mkdirat() recursive fd = -100 (AT_FDCWD), path = /home/ematkho/src/arraise/trace, mode = 504, uid = 90709, gid = 64000 (in run_as_mkdirat_recursive() at runas.c:1428)
DEBUG1 - 21:31:07.726089030 [8383/8530]: Using run_as worker (in run_as() at runas.c:1383)
DEBUG3 - 21:31:07.726206933 [8383/8530]: mkdirat() recursive fd = 86, path = ust, mode = 504, uid = 90709, gid = 64000 (in run_as_mkdirat() at runas.c:1462)
DEBUG1 - 21:31:07.726215403 [8383/8530]: Using run_as worker (in run_as() at runas.c:1383)
DEBUG1 - 21:31:07.726296209 [8383/8530]: Sending consumer create trace chunk command: relayd_id = -1, session_id = 0, chunk_id = 0, creation_timestamp = 20200306T213107-0500 (in consumer_create_trace_chunk() at consumer.c:1914)
DEBUG1 - 21:31:07.726349099 [8383/8530]: Sending trace chunk domain directory fd to consumer (in consumer_create_trace_chunk() at consumer.c:1925)
DEBUG1 - 21:31:07.726404718 [8383/8530]: Creating trace chunk subdirectory "kernel/index" (in lttng_trace_chunk_create_subdirectory() at trace-chunk.c:1212)
DEBUG3 - 21:31:07.726409555 [8383/8530]: mkdirat() recursive fd = 86, path = kernel/index, mode = 504, uid = 90709, gid = 64000 (in run_as_mkdirat_recursive() at runas.c:1428)
DEBUG1 - 21:31:07.726413905 [8383/8530]: Using run_as worker (in run_as() at runas.c:1383)
DEBUG1 - 21:31:07.726444098 [8383/8530]: Adding new top-level directory "kernel/index" to trace chunk "(unnamed)" (in add_top_level_directory_unique() at trace-chunk.c:1186)
DEBUG3 - 21:31:07.726449119 [8383/8530]: mkdirat() recursive fd = 86, path = kernel, mode = 504, uid = 90709, gid = 64000 (in run_as_mkdirat() at runas.c:1462)
DEBUG1 - 21:31:07.726453057 [8383/8530]: Using run_as worker (in run_as() at runas.c:1383)
DEBUG1 - 21:31:07.726479696 [8383/8530]: Sending consumer create trace chunk command: relayd_id = -1, session_id = 0, chunk_id = 0, creation_timestamp = 20200306T213107-0500 (in consumer_create_trace_chunk() at consumer.c:1914)
DEBUG1 - 21:31:07.726506748 [8383/8530]: Sending trace chunk domain directory fd to consumer (in consumer_create_trace_chunk() at consumer.c:1925)
DEBUG1 - 21:31:07.726559184 [8383/8530]: Start kernel tracing session life (in cmd_start_trace() at cmd.c:2725)
DEBUG1 - 21:31:07.726859478 [8383/8530]: Kernel metadata opened (fd: 87) (in kernel_open_metadata() at kernel.c:982)
DEBUG1 - 21:31:07.726864776 [8383/8530]: Kernel metadata stream created (fd: 88) (in kernel_open_metadata_stream() at kernel.c:1163)
DEBUG1 - 21:31:07.726867779 [8383/8530]: Sending session stream to kernel consumer (in kernel_consumer_send_session() at kernel-consumer.c:432)
DEBUG1 - 21:31:07.726869856 [8383/8530]: Sending metadata 88 to kernel consumer (in kernel_consumer_add_metadata() at kernel-consumer.c:218)
DEBUG1 - 21:31:07.726909072 [8383/8530]: Sending streams of channel channel0 to kernel consumer (in kernel_consumer_send_channel_streams() at kernel-consumer.c:375)
DEBUG1 - 21:31:07.726912222 [8383/8530]: Kernel consumer adding channel channel0 to kernel consumer (in kernel_consumer_add_channel() at kernel-consumer.c:109)
DEBUG3 - 21:31:07.726916107 [8383/8530]: Kernel local consumer trace path relative to current trace chunk: "kernel" (in create_channel_path() at kernel-consumer.c:48)
DEBUG1 - 21:31:07.726918760 [8383/8530]: Creating trace chunk subdirectory "kernel/index" (in lttng_trace_chunk_create_subdirectory() at trace-chunk.c:1212)
DEBUG3 - 21:31:07.726921033 [8383/8530]: mkdirat() recursive fd = 86, path = kernel/index, mode = 504, uid = 90709, gid = 64000 (in run_as_mkdirat_recursive() at runas.c:1428)
DEBUG1 - 21:31:07.726926467 [8383/8530]: Using run_as worker (in run_as() at runas.c:1383)
DEBUG3 - 21:31:07.727022253 [8383/8530]: Session 0 found by id. (in session_find_by_id() at session.c:1038)
DEBUG1 - 21:31:07.727036005 [8383/8530]: Beginning of waiter wait period (in lttng_waiter_wait() at waiter.c:46)
DEBUG1 - 21:31:07.727042911 [8383/8527]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:545)
DEBUG1 - 21:31:07.727049196 [8383/8527]: [notification-thread] Handling fd (34) activity (1) (in thread_notification() at notification-thread.c:563)
DEBUG1 - 21:31:07.727053073 [8383/8527]: [notification-thread] Received add channel command (in handle_notification_thread_command() at notification-thread-events.c:2296)
DEBUG1 - 21:31:07.727055290 [8383/8527]: [notification-thread] Adding channel channel0 from session life, channel key = 1 in kernel domain (in handle_notification_thread_command_add_channel() at notification-thread-events.c:1552)
DEBUG1 - 21:31:07.727060750 [8383/8527]: [notification-thread] Found 0 triggers that apply to newly created session (in lttng_session_trigger_list_build() at notification-thread-events.c:1469)
DEBUG1 - 21:31:07.727067842 [8383/8527]: [notification-thread] Found 0 triggers that apply to newly added channel (in handle_notification_thread_command_add_channel() at notification-thread-events.c:1593)
DEBUG1 - 21:31:07.727072643 [8383/8527]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:543)
DEBUG1 - 21:31:07.727073969 [8383/8530]: End of waiter wait period (in lttng_waiter_wait() at waiter.c:89)
DEBUG1 - 21:31:07.727079664 [8383/8530]: Sending stream 84 of channel channel0 to kernel consumer (in kernel_consumer_add_stream() at kernel-consumer.c:289)
DEBUG1 - 21:31:07.727107657 [8383/8530]: Sending stream 83 of channel channel0 to kernel consumer (in kernel_consumer_add_stream() at kernel-consumer.c:289)
DEBUG1 - 21:31:07.727251714 [8383/8530]: Sending stream 82 of channel channel0 to kernel consumer (in kernel_consumer_add_stream() at kernel-consumer.c:289)
DEBUG1 - 21:31:07.727392509 [8383/8530]: Sending stream 65 of channel channel0 to kernel consumer (in kernel_consumer_add_stream() at kernel-consumer.c:289)
DEBUG1 - 21:31:07.727488315 [8383/8530]: Sending streams_sent (in kernel_consumer_streams_sent() at kernel-consumer.c:327)
DEBUG1 - 21:31:07.727577601 [8383/8530]: Kernel consumer FDs of metadata and channel streams sent (in kernel_consumer_send_session() at kernel-consumer.c:460)
DEBUG1 - 21:31:07.779858311 [8383/8530]: Kernel session started (in kernel_start_session() at kernel.c:1007)
DEBUG1 - 21:31:07.779881286 [8383/8530]: Kernel quiescent wait on 21 (in kernel_wait_quiescent() at kernel.c:1023)
DEBUG1 - 21:31:07.803302447 [8383/8530]: Starting all UST traces (in ust_app_start_trace_all() at ust-app.c:4853)
DEBUG1 - 21:31:07.803340349 [8383/8530]: Clearing stream quiescent state for all ust apps (in ust_app_clear_quiescent_session() at ust-app.c:4729)
DEBUG1 - 21:31:07.803351561 [8383/8530]: Sending response (size: 20, retcode: Success (10)) (in thread_manage_clients() at client.c:2375)
DEBUG1 - 21:31:07.803388250 [8383/8530]: Clean command context structure (in clean_command_ctx() at client.c:650)
DEBUG1 - 21:31:07.803394797 [8383/8530]: Accepting client command ... (in thread_manage_clients() at client.c:2223)
DEBUG1 - 21:31:07.810680101 [8383/8532]: UST registration received with pid:8601 ppid:8573 uid:90709 gid:64000 sock:85 name:pageFaultTest (version 8.1) (in thread_application_registration() at register.c:314)
DEBUG1 - 21:31:07.810720459 [8383/8532]: Futex n to 1 wake done (in futex_nto1_wake() at futex.c:112)
DEBUG1 - 21:31:07.810730691 [8383/8532]: Accepting application registration (in thread_application_registration() at register.c:205)
DEBUG1 - 21:31:07.810735193 [8383/8531]: Futex n to 1 wait done (in futex_nto1_wait() at futex.c:95)
DEBUG1 - 21:31:07.810760504 [8383/8531]: Futex n to 1 prepare done (in futex_nto1_prepare() at futex.c:67)
DEBUG1 - 21:31:07.810770663 [8383/8531]: Dispatching UST registration pid:8601 ppid:8573 uid:90709 gid:64000 sock:85 name:pageFaultTest (version 8.1) (in thread_dispatch_ust_registration() at dispatch.c:285)
DEBUG1 - 21:31:07.810788156 [8383/8532]: UST registration received with pid:8601 ppid:8573 uid:90709 gid:64000 sock:89 name:pageFaultTest (version 8.1) (in thread_application_registration() at register.c:314)
DEBUG1 - 21:31:07.810803403 [8383/8532]: Futex n to 1 wake done (in futex_nto1_wake() at futex.c:112)
DEBUG3 - 21:31:07.810806308 [8383/8531]: UST app creating application for socket 85 (in ust_app_create() at ust-app.c:3326)
DEBUG1 - 21:31:07.810814163 [8383/8532]: Accepting application registration (in thread_application_registration() at register.c:205)
DEBUG3 - 21:31:07.810823137 [8383/8531]: Created hashtable size 4 at 0x7f89c4000a50 of type 2 (in lttng_ht_new() at hashtable.c:135)
DEBUG3 - 21:31:07.810833859 [8383/8531]: Created hashtable size 4 at 0x7f89c4000f90 of type 1 (in lttng_ht_new() at hashtable.c:135)
DEBUG3 - 21:31:07.810840178 [8383/8531]: Created hashtable size 4 at 0x7f89c40014d0 of type 1 (in lttng_ht_new() at hashtable.c:135)
DEBUG1 - 21:31:07.810871749 [8383/8531]: Dispatching UST registration pid:8601 ppid:8573 uid:90709 gid:64000 sock:89 name:pageFaultTest (version 8.1) (in thread_dispatch_ust_registration() at dispatch.c:285)
DEBUG3 - 21:31:07.810878609 [8383/8531]: UST app notify socket 89 is set (in thread_dispatch_ust_registration() at dispatch.c:347)
DEBUG1 - 21:31:07.810891532 [8383/8531]: App registered with pid:8601 ppid:8573 uid:90709 gid:64000 sock:85 name:pageFaultTest notify_sock:89 (version 8.1) (in ust_app_add() at ust-app.c:3417)
DEBUG2 - 21:31:07.811075219 [8383/8531]: UST app global update for app sock 85 for session id 0 (in ust_app_global_update() at ust-app.c:5114)
DEBUG3 - 21:31:07.811082403 [8383/8534]: [ust-thread] Manage notify return from poll on 2 fds (in thread_application_notification() at notify-apps.c:81)
DEBUG2 - 21:31:07.811101842 [8383/8531]: UST app pid: 8601 session id 0 not found, creating it (in find_or_create_ust_app_session() at ust-app.c:2121)
DEBUG3 - 21:31:07.811141068 [8383/8534]: UST thread notify added sock 89 to pollset (in thread_application_notification() at notify-apps.c:134)
DEBUG3 - 21:31:07.811152119 [8383/8534]: [ust-thread] Manage notify polling (in thread_application_notification() at notify-apps.c:74)
DEBUG3 - 21:31:07.811158739 [8383/8531]: Created hashtable size 4 at 0x7f89c4004b20 of type 0 (in lttng_ht_new() at hashtable.c:135)
DEBUG2 - 21:31:07.811221208 [8383/8531]: Shadow copy of session handle -1 (in shadow_copy_session() at ust-app.c:1846)
DEBUG3 - 21:31:07.811240571 [8383/8531]: Buffer registry per UID find id: 0, ABI: 64, uid: 90709 (in buffer_reg_uid_find() at buffer-registry.c:194)
DEBUG3 - 21:31:07.811258424 [8383/8531]: Created hashtable size 4 at 0x7f89c4007100 of type 2 (in lttng_ht_new() at hashtable.c:135)
DEBUG3 - 21:31:07.811264784 [8383/8531]: Buffer registry per UID created id: 0, ABI: 64, uid: 90709, domain: 2 (in buffer_reg_uid_create() at buffer-registry.c:143)
DEBUG3 - 21:31:07.811280537 [8383/8531]: Created hashtable size 4 at 0x7f89c400a720 of type 0 (in lttng_ht_new() at hashtable.c:135)
DEBUG3 - 21:31:07.811289546 [8383/8531]: Created hashtable size 4 at 0x7f89c400ac60 of type 2 (in lttng_ht_new() at hashtable.c:135)
DEBUG3 - 21:31:07.811301002 [8383/8531]: Append to metadata: "/* CTF 1.8 */

" (in lttng_metadata_printf() at ust-metadata.c:166)
DEBUG3 - 21:31:07.811313326 [8383/8531]: Append to metadata: "typealias integer { size = 8; align = 8; signed = false; } := uint8_t;
typealias integer { size = 16; align = 8; signed = false; } := uint16_t;
typealias integer { size = 32; align = 8; signed = false; } := uint32_t;
typealias integer { size = 64; align = 8; signed = false; } := uint64_t;
typealias integer { size = 64; align = 8; signed = false; } := unsigned long;
typealias integer { size = 5; align = 1; signed = false; } := uint5_t;
typealias integer { size = 27; align = 1; signed = false; } := uint27_t;

trace {
major = 1;
minor = 8;
uuid = "70cb5d61-4bd6-44f6-b25a-5387247e8f69";
byte_order = le;
packet.header := struct {
uint32_t magic;
uint8_t uuid[16];
uint32_t stream_id;
uint64_t stream_instance_id;
};
};

" (in lttng_metadata_printf() at ust-metadata.c:166)
DEBUG3 - 21:31:07.811322327 [8383/8531]: Append to metadata: "env {
domain = "ust";
tracer_name = "lttng-ust";
tracer_major = 2;
tracer_minor = 12;
tracer_buffering_scheme = "uid";
tracer_buffering_id = 90709;
architecture_bit_width = 64;
" (in lttng_metadata_printf() at ust-metadata.c:166)
DEBUG3 - 21:31:07.811329017 [8383/8531]: Session 0 found by id. (in session_find_by_id() at session.c:1038)
DEBUG3 - 21:31:07.811335073 [8383/8531]: Append to metadata: " trace_name = "" (in lttng_metadata_printf() at ust-metadata.c:166)
DEBUG3 - 21:31:07.811340780 [8383/8531]: Append to metadata: "l" (in lttng_metadata_printf() at ust-metadata.c:166)
DEBUG3 - 21:31:07.811346099 [8383/8531]: Append to metadata: "i" (in lttng_metadata_printf() at ust-metadata.c:166)
DEBUG3 - 21:31:07.811351341 [8383/8531]: Append to metadata: "f" (in lttng_metadata_printf() at ust-metadata.c:166)
DEBUG3 - 21:31:07.811356511 [8383/8531]: Append to metadata: "e" (in lttng_metadata_printf() at ust-metadata.c:166)
DEBUG3 - 21:31:07.811361778 [8383/8531]: Append to metadata: "";
" (in lttng_metadata_printf() at ust-metadata.c:166)
DEBUG3 - 21:31:07.811369278 [8383/8531]: Append to metadata: " trace_creation_datetime = "20200306T213107-0500";
hostname = "elxag47zp12";
" (in lttng_metadata_printf() at ust-metadata.c:166)
DEBUG3 - 21:31:07.811375234 [8383/8531]: Append to metadata: "};

" (in lttng_metadata_printf() at ust-metadata.c:166)
DEBUG3 - 21:31:07.811381255 [8383/8531]: Append to metadata: "clock {
name = "monotonic";
" (in lttng_metadata_printf() at ust-metadata.c:166)
DEBUG3 - 21:31:07.811422393 [8383/8531]: Append to metadata: " uuid = "47a27068-d8b3-4923-a46a-d8f41de03aba";
" (in lttng_metadata_printf() at ust-metadata.c:166)
DEBUG3 - 21:31:07.811435801 [8383/8531]: Append to metadata: " description = "Monotonic Clock";
freq = 1000000000; /* Frequency, in Hz */
/* clock value offset from Epoch is: offset * (1/freq) */
offset = 1583547106759174825;
};

" (in lttng_metadata_printf() at ust-metadata.c:166)
DEBUG3 - 21:31:07.811444947 [8383/8531]: Append to metadata: "typealias integer {
size = 27; align = 1; signed = false;
map = clock.monotonic.value;
} := uint27_clock_monotonic_t;

typealias integer {
size = 32; align = 8; signed = false;
map = clock.monotonic.value;
} := uint32_clock_monotonic_t;

typealias integer {
size = 64; align = 8; signed = false;
map = clock.monotonic.value;
} := uint64_clock_monotonic_t;

" (in lttng_metadata_printf() at ust-metadata.c:166)
DEBUG3 - 21:31:07.811452059 [8383/8531]: Append to metadata: "struct packet_context {
uint64_clock_monotonic_t timestamp_begin;
uint64_clock_monotonic_t timestamp_end;
uint64_t content_size;
uint64_t packet_size;
uint64_t packet_seq_num;
unsigned long events_discarded;
uint32_t cpu_id;
};

" (in lttng_metadata_printf() at ust-metadata.c:166)
DEBUG3 - 21:31:07.811460581 [8383/8531]: Append to metadata: "struct event_header_compact {
enum : uint5_t { compact = 0 ... 30, extended = 31 } id;
variant <id> {
struct {
uint27_clock_monotonic_t timestamp;
} compact;
struct {
uint32_t id;
uint64_clock_monotonic_t timestamp;
} extended;
} v;
} align(8);

struct event_header_large {
enum : uint16_t { compact = 0 ... 65534, extended = 65535 } id;
variant <id> {
struct {
uint32_clock_monotonic_t timestamp;
} compact;
struct {
uint32_t id;
uint64_clock_monotonic_t timestamp;
} extended;
} v;
} align(8);

" (in lttng_metadata_printf() at ust-metadata.c:166)
DEBUG3 - 21:31:07.811467216 [8383/8531]: Buffer registry per UID adding to global registry with id: 0 (in buffer_reg_uid_add() at buffer-registry.c:165)
DEBUG3 - 21:31:07.811476047 [8383/8531]: UST app buffer registry per UID created successfully (in setup_buffer_reg_uid() at ust-app.c:2084)
DEBUG2 - 21:31:07.811658949 [8383/8531]: UST app session created successfully with handle 1 (in find_or_create_ust_app_session() at ust-app.c:2196)
DEBUG3 - 21:31:07.811675898 [8383/8531]: Created hashtable size 4 at 0x7f89c400b3d0 of type 1 (in lttng_ht_new() at hashtable.c:135)
DEBUG3 - 21:31:07.811682920 [8383/8531]: Created hashtable size 4 at 0x7f89c400b910 of type 0 (in lttng_ht_new() at hashtable.c:135)
DEBUG3 - 21:31:07.811688483 [8383/8531]: UST app channel channel0 allocated (in alloc_ust_app_channel() at ust-app.c:1064)
DEBUG2 - 21:31:07.811694020 [8383/8531]: UST app shadow copy of channel channel0 started (in shadow_copy_channel() at ust-app.c:1803)
DEBUG3 - 21:31:07.811699729 [8383/8531]: UST app shadow copy of channel channel0 done (in shadow_copy_channel() at ust-app.c:1829)
DEBUG1 - 21:31:07.811705344 [8383/8531]: UST app creating channel channel0 with per UID buffers (in create_channel_per_uid() at ust-app.c:2818)
DEBUG3 - 21:31:07.811710847 [8383/8531]: Buffer registry per UID find id: 0, ABI: 64, uid: 90709 (in buffer_reg_uid_find() at buffer-registry.c:194)
DEBUG2 - 21:31:07.811717459 [8383/8531]: UST app creating buffer registry channel for channel0 (in create_buffer_reg_channel() at ust-app.c:2657)
DEBUG3 - 21:31:07.811722804 [8383/8531]: Buffer registry channel create with key: 0 (in buffer_reg_channel_create() at buffer-registry.c:370)
DEBUG3 - 21:31:07.811734937 [8383/8531]: Created hashtable size 4 at 0x7f89c400cf90 of type 0 (in lttng_ht_new() at hashtable.c:135)
DEBUG3 - 21:31:07.811741582 [8383/8531]: Session 0 found by id. (in session_find_by_id() at session.c:1038)
DEBUG2 - 21:31:07.811749147 [8383/8531]: Asking UST consumer for channel (in ask_channel_creation() at ust-consumer.c:57)
DEBUG3 - 21:31:07.811767901 [8383/8531]: Consumer trace path relative to current trace chunk: "ust/uid/90709/64-bit" (in setup_channel_trace_path() at consumer.c:73)
DEBUG1 - 21:31:07.811775105 [8383/8531]: Creating trace chunk subdirectory "ust/uid/90709/64-bit/index" (in lttng_trace_chunk_create_subdirectory() at trace-chunk.c:1212)
DEBUG3 - 21:31:07.811781800 [8383/8531]: mkdirat() recursive fd = 86, path = ust/uid/90709/64-bit/index, mode = 504, uid = 90709, gid = 64000 (in run_as_mkdirat_recursive() at runas.c:1428)
DEBUG1 - 21:31:07.811798968 [8383/8531]: Using run_as worker (in run_as() at runas.c:1383)
DEBUG1 - 21:31:07.811927056 [8383/8531]: Adding new top-level directory "ust/uid/90709/64-bit/index" to trace chunk "(unnamed)" (in add_top_level_directory_unique() at trace-chunk.c:1186)
DEBUG3 - 21:31:07.811941920 [8383/8531]: UST registry channel finding key 0 (in ust_registry_channel_find() at ust-registry.c:810)
DEBUG2 - 21:31:07.824416710 [8383/8531]: UST ask channel 1 successfully done with 4 stream(s) (in ask_channel_creation() at ust-consumer.c:179)
DEBUG2 - 21:31:07.824509432 [8383/8531]: UST app stream 1 received successfully (in ust_consumer_get_channel() at ust-consumer.c:300)
DEBUG2 - 21:31:07.824532176 [8383/8531]: UST app stream 2 received successfully (in ust_consumer_get_channel() at ust-consumer.c:300)
DEBUG2 - 21:31:07.824546840 [8383/8531]: UST app stream 3 received successfully (in ust_consumer_get_channel() at ust-consumer.c:300)
DEBUG2 - 21:31:07.824558638 [8383/8531]: UST app stream 4 received successfully (in ust_consumer_get_channel() at ust-consumer.c:300)
DEBUG3 - 21:31:07.824566759 [8383/8531]: UST app consumer has no more stream available (in ust_consumer_get_channel() at ust-consumer.c:284)
DEBUG2 - 21:31:07.824571644 [8383/8531]: UST app setup buffer registry channel for channel0 (in setup_buffer_reg_channel() at ust-app.c:2707)
DEBUG2 - 21:31:07.824574477 [8383/8531]: UST app setup buffer registry stream (in setup_buffer_reg_streams() at ust-app.c:2612)
DEBUG3 - 21:31:07.824577174 [8383/8531]: Buffer registry creating stream (in buffer_reg_stream_create() at buffer-registry.c:400)
DEBUG3 - 21:31:07.824580552 [8383/8531]: Buffer registry creating stream (in buffer_reg_stream_create() at buffer-registry.c:400)
DEBUG3 - 21:31:07.824582989 [8383/8531]: Buffer registry creating stream (in buffer_reg_stream_create() at buffer-registry.c:400)
DEBUG3 - 21:31:07.824585408 [8383/8531]: Buffer registry creating stream (in buffer_reg_stream_create() at buffer-registry.c:400)
DEBUG3 - 21:31:07.824588349 [8383/8531]: UST registry channel finding key 0 (in ust_registry_channel_find() at ust-registry.c:810)
DEBUG1 - 21:31:07.824599359 [8383/8531]: Beginning of waiter wait period (in lttng_waiter_wait() at waiter.c:46)
DEBUG1 - 21:31:07.824605100 [8383/8527]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:545)
DEBUG1 - 21:31:07.824610389 [8383/8527]: [notification-thread] Handling fd (34) activity (1) (in thread_notification() at notification-thread.c:563)
DEBUG1 - 21:31:07.824618212 [8383/8527]: [notification-thread] Received add channel command (in handle_notification_thread_command() at notification-thread-events.c:2296)
DEBUG1 - 21:31:07.824621079 [8383/8527]: [notification-thread] Adding channel channel0 from session life, channel key = 1 in user space domain (in handle_notification_thread_command_add_channel() at notification-thread-events.c:1552)
DEBUG1 - 21:31:07.824624924 [8383/8527]: [notification-thread] Found session info of session "life" (uid = 90709, gid = 64000) (in find_or_create_session_info() at notification-thread-events.c:1495)
DEBUG1 - 21:31:07.824629630 [8383/8527]: [notification-thread] Found 0 triggers that apply to newly added channel (in handle_notification_thread_command_add_channel() at notification-thread-events.c:1593)
DEBUG1 - 21:31:07.824636908 [8383/8527]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:543)
DEBUG1 - 21:31:07.824640249 [8383/8531]: End of waiter wait period (in lttng_waiter_wait() at waiter.c:89)
DEBUG1 - 21:31:07.824644955 [8383/8531]: UST app sending buffer registry channel to ust sock 85 (in send_channel_uid_to_ust() at ust-app.c:2743)
DEBUG2 - 21:31:07.824652608 [8383/8531]: UST app send channel to sock 85 pid 8601 (name: channel0, key: 0) (in ust_consumer_send_channel_to_ust() at ust-consumer.c:406)
DEBUG2 - 21:31:07.824778885 [8383/8531]: UST consumer send stream to app 85 (in ust_consumer_send_stream_to_ust() at ust-consumer.c:369)
DEBUG2 - 21:31:07.824924352 [8383/8531]: UST consumer send stream to app 85 (in ust_consumer_send_stream_to_ust() at ust-consumer.c:369)
DEBUG2 - 21:31:07.825050882 [8383/8531]: UST consumer send stream to app 85 (in ust_consumer_send_stream_to_ust() at ust-consumer.c:369)
DEBUG2 - 21:31:07.825174205 [8383/8531]: UST consumer send stream to app 85 (in ust_consumer_send_stream_to_ust() at ust-consumer.c:369)
DEBUG2 - 21:31:07.825287174 [8383/8531]: UST app adding context to channel channel0 (in create_ust_app_channel_context() at ust-app.c:2305)
DEBUG3 - 21:31:07.825293221 [8383/8531]: UST app context 5 allocated (in alloc_ust_app_ctx() at ust-app.c:1161)
Error: UST app create channel context failed for app (pid: 8601) with ret -1024
DEBUG3 - 21:31:07.825332908 [8383/8531]: Buffer registry per UID find id: 0, ABI: 64, uid: 90709 (in buffer_reg_uid_find() at buffer-registry.c:194)
DEBUG3 - 21:31:07.825339898 [8383/8531]: UST app deleting channel channel0 (in delete_ust_app_channel() at ust-app.c:459)
DEBUG1 - 21:31:07.825596445 [8383/8531]: Starting tracing for ust app pid 8601 (in ust_app_start_trace() at ust-app.c:4323)
DEBUG1 - 21:31:07.825641555 [8383/8531]: Woken up but nothing in the UST command queue (in thread_dispatch_ust_registration() at dispatch.c:273)
DEBUG1 - 21:31:07.825646661 [8383/8531]: Futex n to 1 wait done (in futex_nto1_wait() at futex.c:95)
DEBUG1 - 21:31:07.825648693 [8383/8533]: Apps thread return from poll on 2 fds (in thread_application_management() at manage-apps.c:95)
DEBUG1 - 21:31:07.825650647 [8383/8531]: Futex n to 1 prepare done (in futex_nto1_prepare() at futex.c:67)
DEBUG1 - 21:31:07.825668800 [8383/8531]: Woken up but nothing in the UST command queue (in thread_dispatch_ust_registration() at dispatch.c:273)
DEBUG1 - 21:31:07.825669428 [8383/8533]: Apps with sock 85 added to poll set (in thread_application_management() at manage-apps.c:145)
DEBUG1 - 21:31:07.825677091 [8383/8533]: Apps thread polling (in thread_application_management() at manage-apps.c:88)
DEBUG3 - 21:31:07.835494602 [8383/8385]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:126)
DEBUG3 - 21:31:07.835550117 [8383/8385]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)
DEBUG3 - 21:31:07.835559894 [8383/8385]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:126)
DEBUG3 - 21:31:07.835583521 [8383/8385]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)
DEBUG3 - 21:31:07.835591786 [8383/8385]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:126)
DEBUG3 - 21:31:07.835616963 [8383/8385]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)
DEBUG3 - 21:31:08.163163743 [8383/8534]: [ust-thread] Manage notify return from poll on 3 fds (in thread_application_notification() at notify-apps.c:81)
DEBUG3 - 21:31:08.163216643 [8383/8534]: UST app receiving notify from sock 89 (in ust_app_recv_notify() at ust-app.c:5622)
DEBUG1 - 21:31:08.163165860 [8383/8533]: Apps thread return from poll on 3 fds (in thread_application_management() at manage-apps.c:95)
DEBUG3 - 21:31:08.163226744 [8383/8534]: UST app recv notify failed. Application died (in ust_app_recv_notify() at ust-app.c:5629)
DEBUG1 - 21:31:08.163238572 [8383/8534]: UST app notify socket unregister 89 (in ust_app_notify_sock_unregister() at ust-app.c:5779)
DEBUG1 - 21:31:08.163240206 [8383/8533]: PID 8601 unregistering with sock 85 (in ust_app_unregister() at ust-app.c:3471)
DEBUG1 - 21:31:08.163247743 [8383/8533]: Apps thread polling (in thread_application_management() at manage-apps.c:88)
DEBUG3 - 21:31:08.163252003 [8383/8534]: [ust-thread] Manage notify polling (in thread_application_notification() at notify-apps.c:74)
DEBUG1 - 21:31:08.165743399 [8383/8530]: Wait for client response (in thread_manage_clients() at client.c:2265)
DEBUG1 - 21:31:08.165771564 [8383/8530]: Receiving data from client ... (in thread_manage_clients() at client.c:2310)
DEBUG1 - 21:31:08.165776929 [8383/8530]: Nothing recv() from client... continuing (in thread_manage_clients() at client.c:2314)
DEBUG1 - 21:31:08.165786091 [8383/8530]: Clean command context structure (in clean_command_ctx() at client.c:650)
DEBUG1 - 21:31:08.165789239 [8383/8530]: Accepting client command ... (in thread_manage_clients() at client.c:2223)
DEBUG1 - 21:31:08.165793585 [8383/8530]: Wait for client response (in thread_manage_clients() at client.c:2265)
DEBUG1 - 21:31:08.165801738 [8383/8530]: Receiving data from client ... (in thread_manage_clients() at client.c:2310)
DEBUG1 - 21:31:08.165811714 [8383/8530]: Processing client command 17 (in process_client_msg() at client.c:714)
DEBUG1 - 21:31:08.165815835 [8383/8530]: Getting session life by name (in process_client_msg() at client.c:811)
DEBUG2 - 21:31:08.165819244 [8383/8530]: Trying to find session by name life (in session_find_by_name() at session.c:1000)
DEBUG1 - 21:31:08.165822929 [8383/8530]: Begin stop session "life" (id 0) (in cmd_stop_trace() at cmd.c:2788)
DEBUG1 - 21:31:08.165826091 [8383/8530]: Stopping kernel tracing (in stop_kernel_session() at cmd.c:1340)
DEBUG1 - 21:31:08.169081292 [8383/8530]: Kernel session stopped (in kernel_stop_session() at kernel.c:1088)
DEBUG1 - 21:31:08.169087761 [8383/8530]: Kernel quiescent wait on 21 (in kernel_wait_quiescent() at kernel.c:1023)
DEBUG3 - 21:31:08.173330820 [8383/8587]: Call RCU deleting app PID 8601 (in delete_ust_app_rcu() at ust-app.c:959)
DEBUG1 - 21:31:08.187229380 [8383/8530]: Kernel flushing metadata buffer on fd 88 (in kernel_metadata_flush_buffer() at kernel.c:1039)
DEBUG1 - 21:31:08.187240948 [8383/8530]: Flush buffer for channel channel0 (in kernel_flush_buffer() at kernel.c:1059)
DEBUG1 - 21:31:08.187244791 [8383/8530]: Flushing channel stream 84 (in kernel_flush_buffer() at kernel.c:1062)
DEBUG1 - 21:31:08.187249445 [8383/8530]: Flushing channel stream 83 (in kernel_flush_buffer() at kernel.c:1062)
DEBUG1 - 21:31:08.187256278 [8383/8530]: Flushing channel stream 82 (in kernel_flush_buffer() at kernel.c:1062)
DEBUG1 - 21:31:08.187262402 [8383/8530]: Flushing channel stream 65 (in kernel_flush_buffer() at kernel.c:1062)
DEBUG1 - 21:31:08.187268853 [8383/8530]: Stopping all UST traces (in ust_app_stop_trace_all() at ust-app.c:4890)
DEBUG1 - 21:31:08.187272634 [8383/8530]: Flushing session buffers for all ust apps (in ust_app_flush_session() at ust-app.c:4584)
DEBUG2 - 21:31:08.187277910 [8383/8530]: Consumer flush channel key 1 (in consumer_flush_channel() at consumer.c:1321)
DEBUG1 - 21:31:08.187355576 [8383/8530]: Completed stop session "life" (id 0) (in cmd_stop_trace() at cmd.c:2813)
DEBUG1 - 21:31:08.187367275 [8383/8530]: Sending response (size: 20, retcode: Success (10)) (in thread_manage_clients() at client.c:2375)
DEBUG1 - 21:31:08.187384659 [8383/8530]: Clean command context structure (in clean_command_ctx() at client.c:650)
DEBUG2 - 21:31:08.187387626 [8383/8587]: UST app pid 8601 deleted (in delete_ust_app() at ust-app.c:943)
DEBUG3 - 21:31:08.187407683 [8383/8385]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:126)
DEBUG3 - 21:31:08.187482060 [8383/8385]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)
DEBUG3 - 21:31:08.187491806 [8383/8385]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:126)
DEBUG3 - 21:31:08.187523036 [8383/8385]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)
DEBUG3 - 21:31:08.187529475 [8383/8385]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:126)
DEBUG3 - 21:31:08.187562337 [8383/8385]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)
DEBUG1 - 21:31:08.187390343 [8383/8530]: Accepting client command ... (in thread_manage_clients() at client.c:2223)
DEBUG1 - 21:31:08.187632669 [8383/8530]: Wait for client response (in thread_manage_clients() at client.c:2265)
DEBUG1 - 21:31:08.187654161 [8383/8530]: Receiving data from client ... (in thread_manage_clients() at client.c:2310)
DEBUG1 - 21:31:08.187662469 [8383/8530]: Nothing recv() from client... continuing (in thread_manage_clients() at client.c:2314)
DEBUG1 - 21:31:08.187675671 [8383/8530]: Clean command context structure (in clean_command_ctx() at client.c:650)
DEBUG1 - 21:31:08.187681240 [8383/8530]: Accepting client command ... (in thread_manage_clients() at client.c:2223)
DEBUG1 - 21:31:08.187687750 [8383/8530]: Wait for client response (in thread_manage_clients() at client.c:2265)
DEBUG1 - 21:31:08.187700389 [8383/8530]: Receiving data from client ... (in thread_manage_clients() at client.c:2310)
DEBUG1 - 21:31:08.187714739 [8383/8530]: Processing client command 24 (in process_client_msg() at client.c:714)
DEBUG1 - 21:31:08.187720535 [8383/8530]: Getting session life by name (in process_client_msg() at client.c:811)
DEBUG2 - 21:31:08.187725641 [8383/8530]: Trying to find session by name life (in session_find_by_name() at session.c:1000)
DEBUG1 - 21:31:08.187731698 [8383/8530]: Data pending for session life (in cmd_data_pending() at cmd.c:3793)
DEBUG3 - 21:31:08.187737085 [8383/8530]: Consumer data pending for id 0 (in consumer_is_data_pending() at consumer.c:1265)
DEBUG1 - 21:31:08.187828245 [8383/8530]: Consumer data is pending for session id 0 (in consumer_is_data_pending() at consumer.c:1301)
DEBUG1 - 21:31:08.187840884 [8383/8530]: Sending response (size: 21, retcode: Success (10)) (in thread_manage_clients() at client.c:2375)
DEBUG1 - 21:31:08.187858677 [8383/8530]: Clean command context structure (in clean_command_ctx() at client.c:650)
DEBUG1 - 21:31:08.187864564 [8383/8530]: Accepting client command ... (in thread_manage_clients() at client.c:2223)
DEBUG1 - 21:31:08.388176506 [8383/8530]: Wait for client response (in thread_manage_clients() at client.c:2265)
DEBUG1 - 21:31:08.388225587 [8383/8530]: Receiving data from client ... (in thread_manage_clients() at client.c:2310)
DEBUG1 - 21:31:08.388237837 [8383/8530]: Nothing recv() from client... continuing (in thread_manage_clients() at client.c:2314)
DEBUG1 - 21:31:08.388259091 [8383/8530]: Clean command context structure (in clean_command_ctx() at client.c:650)
DEBUG1 - 21:31:08.388267989 [8383/8530]: Accepting client command ... (in thread_manage_clients() at client.c:2223)
DEBUG1 - 21:31:08.388278635 [8383/8530]: Wait for client response (in thread_manage_clients() at client.c:2265)
DEBUG1 - 21:31:08.388299686 [8383/8530]: Receiving data from client ... (in thread_manage_clients() at client.c:2310)
DEBUG1 - 21:31:08.388323370 [8383/8530]: Processing client command 24 (in process_client_msg() at client.c:714)
DEBUG1 - 21:31:08.388333979 [8383/8530]: Getting session life by name (in process_client_msg() at client.c:811)
DEBUG2 - 21:31:08.388342735 [8383/8530]: Trying to find session by name life (in session_find_by_name() at session.c:1000)
DEBUG1 - 21:31:08.388353662 [8383/8530]: Data pending for session life (in cmd_data_pending() at cmd.c:3793)
DEBUG3 - 21:31:08.388362832 [8383/8530]: Consumer data pending for id 0 (in consumer_is_data_pending() at consumer.c:1265)
DEBUG1 - 21:31:08.388463012 [8383/8530]: Consumer data is NOT pending for session id 0 (in consumer_is_data_pending() at consumer.c:1301)
DEBUG3 - 21:31:08.388481965 [8383/8530]: Consumer data pending for id 0 (in consumer_is_data_pending() at consumer.c:1265)
DEBUG1 - 21:31:08.388595568 [8383/8530]: Consumer data is NOT pending for session id 0 (in consumer_is_data_pending() at consumer.c:1301)
DEBUG1 - 21:31:08.388617049 [8383/8530]: Sending response (size: 21, retcode: Success (10)) (in thread_manage_clients() at client.c:2375)
DEBUG1 - 21:31:08.388648108 [8383/8530]: Clean command context structure (in clean_command_ctx() at client.c:650)
DEBUG1 - 21:31:08.388657730 [8383/8530]: Accepting client command ... (in thread_manage_clients() at client.c:2223)
DEBUG1 - 21:31:08.388795531 [8383/8530]: Wait for client response (in thread_manage_clients() at client.c:2265)
DEBUG1 - 21:31:08.388828163 [8383/8530]: Receiving data from client ... (in thread_manage_clients() at client.c:2310)
DEBUG1 - 21:31:08.388840111 [8383/8530]: Nothing recv() from client... continuing (in thread_manage_clients() at client.c:2314)
DEBUG1 - 21:31:08.388859420 [8383/8530]: Clean command context structure (in clean_command_ctx() at client.c:650)
DEBUG1 - 21:31:08.388868141 [8383/8530]: Accepting client command ... (in thread_manage_clients() at client.c:2223)
DEBUG1 - 21:31:08.388879078 [8383/8530]: Wait for client response (in thread_manage_clients() at client.c:2265)
DEBUG1 - 21:31:08.388900020 [8383/8530]: Receiving data from client ... (in thread_manage_clients() at client.c:2310)
DEBUG1 - 21:31:08.388922480 [8383/8530]: Processing client command 13 (in process_client_msg() at client.c:714)
DEBUG1 - 21:31:08.388932565 [8383/8530]: Counting number of available session for UID 90709 GID 64000 (in lttng_sessions_count() at client.c:513)
DEBUG1 - 21:31:08.388967977 [8383/8530]: Getting all available session for UID 90709 GID 64000 (in cmd_list_lttng_sessions() at cmd.c:3733)
DEBUG1 - 21:31:08.388994468 [8383/8530]: Sending response (size: 4412, retcode: Success (10)) (in thread_manage_clients() at client.c:2375)
DEBUG1 - 21:31:08.389022188 [8383/8530]: Clean command context structure (in clean_command_ctx() at client.c:650)
DEBUG1 - 21:31:08.389031037 [8383/8530]: Accepting client command ... (in thread_manage_clients() at client.c:2223)
DEBUG1 - 21:31:08.389170843 [8383/8530]: Wait for client response (in thread_manage_clients() at client.c:2265)
DEBUG1 - 21:31:08.389193803 [8383/8530]: Receiving data from client ... (in thread_manage_clients() at client.c:2310)
DEBUG1 - 21:31:08.389205071 [8383/8530]: Nothing recv() from client... continuing (in thread_manage_clients() at client.c:2314)
DEBUG1 - 21:31:08.389221579 [8383/8530]: Clean command context structure (in clean_command_ctx() at client.c:650)
DEBUG1 - 21:31:08.389229287 [8383/8530]: Accepting client command ... (in thread_manage_clients() at client.c:2223)
DEBUG1 - 21:31:08.389239679 [8383/8530]: Wait for client response (in thread_manage_clients() at client.c:2265)
DEBUG1 - 21:31:08.389258461 [8383/8530]: Receiving data from client ... (in thread_manage_clients() at client.c:2310)
DEBUG1 - 21:31:08.389278419 [8383/8530]: Processing client command 11 (in process_client_msg() at client.c:714)
DEBUG1 - 21:31:08.389287788 [8383/8530]: Getting session life by name (in process_client_msg() at client.c:811)
DEBUG2 - 21:31:08.389295803 [8383/8530]: Trying to find session by name life (in session_find_by_name() at session.c:1000)
DEBUG3 - 21:31:08.389305247 [8383/8530]: Listing domains found kernel domain (in cmd_list_domains() at cmd.c:3528)
DEBUG3 - 21:31:08.389312987 [8383/8530]: Listing domains found UST global domain (in cmd_list_domains() at cmd.c:3533)
DEBUG1 - 21:31:08.389325183 [8383/8530]: Sending response (size: 636, retcode: Success (10)) (in thread_manage_clients() at client.c:2375)
DEBUG1 - 21:31:08.389348824 [8383/8530]: Clean command context structure (in clean_command_ctx() at client.c:650)
DEBUG1 - 21:31:08.389357434 [8383/8530]: Accepting client command ... (in thread_manage_clients() at client.c:2223)
DEBUG1 - 21:31:08.389464834 [8383/8530]: Wait for client response (in thread_manage_clients() at client.c:2265)
DEBUG1 - 21:31:08.389487280 [8383/8530]: Receiving data from client ... (in thread_manage_clients() at client.c:2310)
DEBUG1 - 21:31:08.389498568 [8383/8530]: Nothing recv() from client... continuing (in thread_manage_clients() at client.c:2314)
DEBUG1 - 21:31:08.389515436 [8383/8530]: Clean command context structure (in clean_command_ctx() at client.c:650)
DEBUG1 - 21:31:08.389523593 [8383/8530]: Accepting client command ... (in thread_manage_clients() at client.c:2223)
DEBUG1 - 21:31:08.389533670 [8383/8530]: Wait for client response (in thread_manage_clients() at client.c:2265)
DEBUG1 - 21:31:08.389553053 [8383/8530]: Receiving data from client ... (in thread_manage_clients() at client.c:2310)
DEBUG1 - 21:31:08.389574939 [8383/8530]: Processing client command 10 (in process_client_msg() at client.c:714)
DEBUG1 - 21:31:08.389583080 [8383/8530]: Getting session life by name (in process_client_msg() at client.c:811)
DEBUG2 - 21:31:08.389591521 [8383/8530]: Trying to find session by name life (in session_find_by_name() at session.c:1000)
DEBUG3 - 21:31:08.389602023 [8383/8530]: Consumer socket created (fd: 77) and added to output (in consumer_create_socket() at consumer.c:351)
DEBUG1 - 21:31:08.389611541 [8383/8530]: Setting relayd for session life (in cmd_setup_relayd() at cmd.c:1188)
DEBUG3 - 21:31:08.389620054 [8383/8530]: Number of kernel channels 1 (in cmd_list_channels() at cmd.c:3603)
DEBUG1 - 21:31:08.389629315 [8383/8530]: Listing channels for session life (in list_lttng_channels() at cmd.c:291)
DEBUG3 - 21:31:08.389637066 [8383/8530]: Consumer discarded events id 0 (in consumer_get_discarded_events() at consumer.c:1570)
DEBUG1 - 21:31:08.389693573 [8383/8530]: Consumer discarded 0 events in session id 0 (in consumer_get_discarded_events() at consumer.c:1607)
DEBUG3 - 21:31:08.389703422 [8383/8530]: Consumer lost packets id 0 (in consumer_get_lost_packets() at consumer.c:1627)
DEBUG1 - 21:31:08.389745883 [8383/8530]: Consumer lost 0 packets in session id 0 (in consumer_get_lost_packets() at consumer.c:1664)
DEBUG1 - 21:31:08.389757932 [8383/8530]: Sending response (size: 676, retcode: Success (10)) (in thread_manage_clients() at client.c:2375)
DEBUG1 - 21:31:08.389780892 [8383/8530]: Clean command context structure (in clean_command_ctx() at client.c:650)
DEBUG1 - 21:31:08.389789076 [8383/8530]: Accepting client command ... (in thread_manage_clients() at client.c:2223)
DEBUG1 - 21:31:08.389871904 [8383/8530]: Wait for client response (in thread_manage_clients() at client.c:2265)
DEBUG1 - 21:31:08.389894241 [8383/8530]: Receiving data from client ... (in thread_manage_clients() at client.c:2310)
DEBUG1 - 21:31:08.389905425 [8383/8530]: Nothing recv() from client... continuing (in thread_manage_clients() at client.c:2314)
DEBUG1 - 21:31:08.389921333 [8383/8530]: Clean command context structure (in clean_command_ctx() at client.c:650)
DEBUG1 - 21:31:08.389929389 [8383/8530]: Accepting client command ... (in thread_manage_clients() at client.c:2223)
DEBUG1 - 21:31:08.389938937 [8383/8530]: Wait for client response (in thread_manage_clients() at client.c:2265)
DEBUG1 - 21:31:08.389959044 [8383/8530]: Receiving data from client ... (in thread_manage_clients() at client.c:2310)
DEBUG1 - 21:31:08.389980849 [8383/8530]: Processing client command 10 (in process_client_msg() at client.c:714)
DEBUG1 - 21:31:08.389989624 [8383/8530]: Getting session life by name (in process_client_msg() at client.c:811)
DEBUG2 - 21:31:08.389997865 [8383/8530]: Trying to find session by name life (in session_find_by_name() at session.c:1000)
DEBUG3 - 21:31:08.390012520 [8383/8530]: Consumer socket created (fd: 70) and added to output (in consumer_create_socket() at consumer.c:351)
DEBUG1 - 21:31:08.390021431 [8383/8530]: Setting relayd for session life (in cmd_setup_relayd() at cmd.c:1188)
DEBUG3 - 21:31:08.390030829 [8383/8530]: Number of UST global channels 1 (in cmd_list_channels() at cmd.c:3616)
DEBUG1 - 21:31:08.390039655 [8383/8530]: Listing channels for session life (in list_lttng_channels() at cmd.c:291)
DEBUG3 - 21:31:08.390049608 [8383/8530]: Consumer discarded events id 0 (in consumer_get_discarded_events() at consumer.c:1570)
DEBUG1 - 21:31:08.390108224 [8383/8530]: Consumer discarded 0 events in session id 0 (in consumer_get_discarded_events() at consumer.c:1607)
DEBUG1 - 21:31:08.390120644 [8383/8530]: Sending response (size: 676, retcode: Success (10)) (in thread_manage_clients() at client.c:2375)
DEBUG1 - 21:31:08.390144013 [8383/8530]: Clean command context structure (in clean_command_ctx() at client.c:650)
DEBUG1 - 21:31:08.390153234 [8383/8530]: Accepting client command ... (in thread_manage_clients() at client.c:2223)
DEBUG1 - 21:31:08.395345959 [8383/8530]: Wait for client response (in thread_manage_clients() at client.c:2265)
DEBUG1 - 21:31:08.395377161 [8383/8530]: Receiving data from client ... (in thread_manage_clients() at client.c:2310)
DEBUG1 - 21:31:08.395384677 [8383/8530]: Nothing recv() from client... continuing (in thread_manage_clients() at client.c:2314)
DEBUG1 - 21:31:08.395395719 [8383/8530]: Clean command context structure (in clean_command_ctx() at client.c:650)
DEBUG1 - 21:31:08.395399785 [8383/8530]: Accepting client command ... (in thread_manage_clients() at client.c:2223)
DEBUG1 - 21:31:08.395404962 [8383/8530]: Wait for client response (in thread_manage_clients() at client.c:2265)
DEBUG1 - 21:31:08.395414796 [8383/8530]: Receiving data from client ... (in thread_manage_clients() at client.c:2310)
DEBUG1 - 21:31:08.395426756 [8383/8530]: Processing client command 13 (in process_client_msg() at client.c:714)
DEBUG1 - 21:31:08.395432190 [8383/8530]: Counting number of available session for UID 90709 GID 64000 (in lttng_sessions_count() at client.c:513)
DEBUG1 - 21:31:08.395438174 [8383/8530]: Getting all available session for UID 90709 GID 64000 (in cmd_list_lttng_sessions() at cmd.c:3733)
DEBUG1 - 21:31:08.395445277 [8383/8530]: Sending response (size: 4412, retcode: Success (10)) (in thread_manage_clients() at client.c:2375)
DEBUG1 - 21:31:08.395458422 [8383/8530]: Clean command context structure (in clean_command_ctx() at client.c:650)
DEBUG1 - 21:31:08.395462446 [8383/8530]: Accepting client command ... (in thread_manage_clients() at client.c:2223)
DEBUG1 - 21:31:08.395602765 [8383/8530]: Wait for client response (in thread_manage_clients() at client.c:2265)
DEBUG1 - 21:31:08.395627287 [8383/8530]: Receiving data from client ... (in thread_manage_clients() at client.c:2310)
DEBUG1 - 21:31:08.395633897 [8383/8530]: Nothing recv() from client... continuing (in thread_manage_clients() at client.c:2314)
DEBUG1 - 21:31:08.395644338 [8383/8530]: Clean command context structure (in clean_command_ctx() at client.c:650)
DEBUG1 - 21:31:08.395649876 [8383/8530]: Accepting client command ... (in thread_manage_clients() at client.c:2223)
DEBUG1 - 21:31:08.395655181 [8383/8530]: Wait for client response (in thread_manage_clients() at client.c:2265)
DEBUG1 - 21:31:08.395663982 [8383/8530]: Receiving data from client ... (in thread_manage_clients() at client.c:2310)
DEBUG1 - 21:31:08.395674663 [8383/8530]: Processing client command 17 (in process_client_msg() at client.c:714)
DEBUG1 - 21:31:08.395679498 [8383/8530]: Getting session life by name (in process_client_msg() at client.c:811)
DEBUG2 - 21:31:08.395683338 [8383/8530]: Trying to find session by name life (in session_find_by_name() at session.c:1000)
DEBUG1 - 21:31:08.395688378 [8383/8530]: Begin stop session "life" (id 0) (in cmd_stop_trace() at cmd.c:2788)
DEBUG1 - 21:31:08.395693141 [8383/8530]: Sending response (size: 20, retcode: Tracing has already been stopped (81)) (in thread_manage_clients() at client.c:2375)
DEBUG1 - 21:31:08.395705170 [8383/8530]: Clean command context structure (in clean_command_ctx() at client.c:650)
DEBUG1 - 21:31:08.395708722 [8383/8530]: Accepting client command ... (in thread_manage_clients() at client.c:2223)
DEBUG1 - 21:31:08.395798324 [8383/8530]: Wait for client response (in thread_manage_clients() at client.c:2265)
DEBUG1 - 21:31:08.395821811 [8383/8530]: Receiving data from client ... (in thread_manage_clients() at client.c:2310)
DEBUG1 - 21:31:08.395828316 [8383/8530]: Nothing recv() from client... continuing (in thread_manage_clients() at client.c:2314)
DEBUG1 - 21:31:08.395838673 [8383/8530]: Clean command context structure (in clean_command_ctx() at client.c:650)
DEBUG1 - 21:31:08.395844393 [8383/8530]: Accepting client command ... (in thread_manage_clients() at client.c:2223)
DEBUG1 - 21:31:08.395849346 [8383/8530]: Wait for client response (in thread_manage_clients() at client.c:2265)
DEBUG1 - 21:31:08.395858047 [8383/8530]: Receiving data from client ... (in thread_manage_clients() at client.c:2310)
DEBUG1 - 21:31:08.395868669 [8383/8530]: Processing client command 24 (in process_client_msg() at client.c:714)
DEBUG1 - 21:31:08.395873065 [8383/8530]: Getting session life by name (in process_client_msg() at client.c:811)
DEBUG2 - 21:31:08.395876823 [8383/8530]: Trying to find session by name life (in session_find_by_name() at session.c:1000)
DEBUG1 - 21:31:08.395880858 [8383/8530]: Data pending for session life (in cmd_data_pending() at cmd.c:3793)
DEBUG3 - 21:31:08.395884621 [8383/8530]: Consumer data pending for id 0 (in consumer_is_data_pending() at consumer.c:1265)
DEBUG1 - 21:31:08.395943056 [8383/8530]: Consumer data is NOT pending for session id 0 (in consumer_is_data_pending() at consumer.c:1301)
DEBUG3 - 21:31:08.395951933 [8383/8530]: Consumer data pending for id 0 (in consumer_is_data_pending() at consumer.c:1265)
DEBUG1 - 21:31:08.395988987 [8383/8530]: Consumer data is NOT pending for session id 0 (in consumer_is_data_pending() at consumer.c:1301)
DEBUG1 - 21:31:08.395997948 [8383/8530]: Sending response (size: 21, retcode: Success (10)) (in thread_manage_clients() at client.c:2375)
DEBUG1 - 21:31:08.396010230 [8383/8530]: Clean command context structure (in clean_command_ctx() at client.c:650)
DEBUG1 - 21:31:08.396014003 [8383/8530]: Accepting client command ... (in thread_manage_clients() at client.c:2223)
DEBUG1 - 21:31:08.396081441 [8383/8530]: Wait for client response (in thread_manage_clients() at client.c:2265)
DEBUG1 - 21:31:08.396094509 [8383/8530]: Receiving data from client ... (in thread_manage_clients() at client.c:2310)
DEBUG1 - 21:31:08.396099673 [8383/8530]: Nothing recv() from client... continuing (in thread_manage_clients() at client.c:2314)
DEBUG1 - 21:31:08.396106465 [8383/8530]: Clean command context structure (in clean_command_ctx() at client.c:650)
DEBUG1 - 21:31:08.396109596 [8383/8530]: Accepting client command ... (in thread_manage_clients() at client.c:2223)
DEBUG1 - 21:31:08.396113826 [8383/8530]: Wait for client response (in thread_manage_clients() at client.c:2265)
DEBUG1 - 21:31:08.396122252 [8383/8530]: Receiving data from client ... (in thread_manage_clients() at client.c:2310)
DEBUG1 - 21:31:08.396151877 [8383/8530]: Processing client command 9 (in process_client_msg() at client.c:714)
DEBUG1 - 21:31:08.396157364 [8383/8530]: Getting session life by name (in process_client_msg() at client.c:811)
DEBUG2 - 21:31:08.396160814 [8383/8530]: Trying to find session by name life (in session_find_by_name() at session.c:1000)
DEBUG1 - 21:31:08.396164985 [8383/8530]: Begin destroy session life (id 0) (in cmd_destroy_session() at cmd.c:3299)
DEBUG1 - 21:31:08.396172504 [8383/8530]: Rotate kernel session life started (session 0) (in kernel_rotate_session() at kernel.c:1630)
DEBUG1 - 21:31:08.396176654 [8383/8530]: Rotate kernel channel 1, session life (in kernel_rotate_session() at kernel.c:1645)
DEBUG1 - 21:31:08.396180150 [8383/8530]: Consumer rotate channel key 1 (in consumer_rotate_channel() at consumer.c:1687)
DEBUG1 - 21:31:08.396241245 [8383/8530]: Consumer rotate channel key 2 (in consumer_rotate_channel() at consumer.c:1687)
DEBUG1 - 21:31:08.396276157 [8383/8530]: Setting trace chunk close command to "no operation" (in lttng_trace_chunk_set_close_command() at trace-chunk.c:1784)
DEBUG1 - 21:31:08.396285487 [8383/8530]: lttng_trace_chunk_rename_path from to (in lttng_trace_chunk_rename_path_no_lock() at trace-chunk.c:740)
DEBUG1 - 21:31:08.396297064 [8383/8530]: Sending consumer close trace chunk command: relayd_id = -1, session_id = 0, chunk_id = 0, close command = "none" (in consumer_close_trace_chunk() at consumer.c:2012)
DEBUG1 - 21:31:08.396343601 [8383/8530]: Sending consumer close trace chunk command: relayd_id = -1, session_id = 0, chunk_id = 0, close command = "none" (in consumer_close_trace_chunk() at consumer.c:2012)
DEBUG1 - 21:31:08.396385610 [8383/8530]: Enabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_start() at timer.c:213)
DEBUG1 - 21:31:08.396406682 [8383/8530]: Cmd rotate session life, archive_id 0 sent (in cmd_rotate_session() at cmd.c:5079)
DEBUG1 - 21:31:08.396414528 [8383/8530]: Clean command context structure (in clean_command_ctx() at client.c:650)
DEBUG1 - 21:31:08.396418118 [8383/8530]: Accepting client command ... (in thread_manage_clients() at client.c:2223)
DEBUG1 - 21:31:08.727355026 [8383/8527]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:545)
DEBUG1 - 21:31:08.727401168 [8383/8527]: [notification-thread] Handling fd (11) activity (1) (in thread_notification() at notification-thread.c:563)
DEBUG1 - 21:31:08.727434941 [8383/8527]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session life (highest usage = 0, lowest usage = 0, total consumed = 6344704) (in handle_notification_thread_channel_sample() at notification-thread-events.c:3261)
DEBUG1 - 21:31:08.727454807 [8383/8527]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:543)
DEBUG1 - 21:31:08.824534863 [8383/8527]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:545)
DEBUG1 - 21:31:08.824575311 [8383/8527]: [notification-thread] Handling fd (17) activity (1) (in thread_notification() at notification-thread.c:563)
DEBUG1 - 21:31:08.824599798 [8383/8527]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session life (highest usage = 0, lowest usage = 0, total consumed = 16384) (in handle_notification_thread_channel_sample() at notification-thread-events.c:3261)
DEBUG1 - 21:31:08.824619453 [8383/8527]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:543)
DEBUG1 - 21:31:08.896710706 [8383/8529]: [rotation-thread] Poll wait returned (1) (in thread_rotation() at rotation-thread.c:798)
DEBUG1 - 21:31:08.896766300 [8383/8529]: [rotation-thread] Handling fd (15) activity (1) (in thread_rotation() at rotation-thread.c:817)
DEBUG1 - 21:31:08.896782948 [8383/8529]: [rotation-thread] Checking for pending rotation on session "life", trace archive 0 (in check_session_rotation_pending() at rotation-thread.c:443)
DEBUG1 - 21:31:08.896794324 [8383/8529]: Disabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_stop() at timer.c:245)
DEBUG1 - 21:31:08.896888056 [8383/8529]: Sending consumer trace chunk exists command: relayd_id = -1, session_id = 0, chunk_id = 0 (in consumer_trace_chunk_exists() at consumer.c:2105)
DEBUG1 - 21:31:08.897037651 [8383/8529]: Consumer ret code -126 (in consumer_recv_status_reply() at consumer.c:200)
DEBUG1 - 21:31:08.897063546 [8383/8529]: Consumer reply to TRACE_CHUNK_EXISTS command: trace chunk exists locally (in consumer_trace_chunk_exists() at consumer.c:2128)
DEBUG1 - 21:31:08.897075664 [8383/8529]: [rotation-thread] Rotation of trace archive 0 is still pending for session life (in check_session_rotation_pending() at rotation-thread.c:506)
DEBUG1 - 21:31:08.897086203 [8383/8529]: Enabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_start() at timer.c:213)
DEBUG1 - 21:31:08.897130842 [8383/8529]: [rotation-thread] Entering poll wait (in thread_rotation() at rotation-thread.c:796)
DEBUG1 - 21:31:09.397313295 [8383/8529]: [rotation-thread] Poll wait returned (1) (in thread_rotation() at rotation-thread.c:798)
DEBUG1 - 21:31:09.397354057 [8383/8529]: [rotation-thread] Handling fd (15) activity (1) (in thread_rotation() at rotation-thread.c:817)
DEBUG1 - 21:31:09.397368923 [8383/8529]: [rotation-thread] Checking for pending rotation on session "life", trace archive 0 (in check_session_rotation_pending() at rotation-thread.c:443)
DEBUG1 - 21:31:09.397382466 [8383/8529]: Disabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_stop() at timer.c:245)
DEBUG1 - 21:31:09.397446218 [8383/8529]: Sending consumer trace chunk exists command: relayd_id = -1, session_id = 0, chunk_id = 0 (in consumer_trace_chunk_exists() at consumer.c:2105)
DEBUG1 - 21:31:09.397568336 [8383/8529]: Consumer ret code -126 (in consumer_recv_status_reply() at consumer.c:200)
DEBUG1 - 21:31:09.397594921 [8383/8529]: Consumer reply to TRACE_CHUNK_EXISTS command: trace chunk exists locally (in consumer_trace_chunk_exists() at consumer.c:2128)
DEBUG1 - 21:31:09.397607959 [8383/8529]: [rotation-thread] Rotation of trace archive 0 is still pending for session life (in check_session_rotation_pending() at rotation-thread.c:506)
DEBUG1 - 21:31:09.397620344 [8383/8529]: Enabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_start() at timer.c:213)
DEBUG1 - 21:31:09.397659229 [8383/8529]: [rotation-thread] Entering poll wait (in thread_rotation() at rotation-thread.c:796)
DEBUG1 - 21:31:09.727423456 [8383/8527]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:545)
DEBUG1 - 21:31:09.727474318 [8383/8527]: [notification-thread] Handling fd (11) activity (1) (in thread_notification() at notification-thread.c:563)
DEBUG1 - 21:31:09.727518104 [8383/8527]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session life (highest usage = 0, lowest usage = 0, total consumed = 6344704) (in handle_notification_thread_channel_sample() at notification-thread-events.c:3261)
DEBUG1 - 21:31:09.727541679 [8383/8527]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:543)
DEBUG1 - 21:31:09.824589489 [8383/8527]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:545)
DEBUG1 - 21:31:09.824630592 [8383/8527]: [notification-thread] Handling fd (17) activity (1) (in thread_notification() at notification-thread.c:563)
DEBUG1 - 21:31:09.824670015 [8383/8527]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session life (highest usage = 0, lowest usage = 0, total consumed = 16384) (in handle_notification_thread_channel_sample() at notification-thread-events.c:3261)
DEBUG1 - 21:31:09.824699676 [8383/8527]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:543)
DEBUG1 - 21:31:09.897850412 [8383/8529]: [rotation-thread] Poll wait returned (1) (in thread_rotation() at rotation-thread.c:798)
DEBUG1 - 21:31:09.897878135 [8383/8529]: [rotation-thread] Handling fd (15) activity (1) (in thread_rotation() at rotation-thread.c:817)
DEBUG1 - 21:31:09.897889054 [8383/8529]: [rotation-thread] Checking for pending rotation on session "life", trace archive 0 (in check_session_rotation_pending() at rotation-thread.c:443)
DEBUG1 - 21:31:09.897896880 [8383/8529]: Disabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_stop() at timer.c:245)
DEBUG1 - 21:31:09.897964468 [8383/8529]: Sending consumer trace chunk exists command: relayd_id = -1, session_id = 0, chunk_id = 0 (in consumer_trace_chunk_exists() at consumer.c:2105)
DEBUG1 - 21:31:09.898101769 [8383/8529]: Consumer ret code -126 (in consumer_recv_status_reply() at consumer.c:200)
DEBUG1 - 21:31:09.898119594 [8383/8529]: Consumer reply to TRACE_CHUNK_EXISTS command: trace chunk exists locally (in consumer_trace_chunk_exists() at consumer.c:2128)
DEBUG1 - 21:31:09.898129876 [8383/8529]: [rotation-thread] Rotation of trace archive 0 is still pending for session life (in check_session_rotation_pending() at rotation-thread.c:506)
DEBUG1 - 21:31:09.898138576 [8383/8529]: Enabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_start() at timer.c:213)
DEBUG1 - 21:31:09.898164757 [8383/8529]: [rotation-thread] Entering poll wait (in thread_rotation() at rotation-thread.c:796)
DEBUG1 - 21:31:10.398353572 [8383/8529]: [rotation-thread] Poll wait returned (1) (in thread_rotation() at rotation-thread.c:798)
DEBUG1 - 21:31:10.398403523 [8383/8529]: [rotation-thread] Handling fd (15) activity (1) (in thread_rotation() at rotation-thread.c:817)
DEBUG1 - 21:31:10.398448527 [8383/8529]: [rotation-thread] Checking for pending rotation on session "life", trace archive 0 (in check_session_rotation_pending() at rotation-thread.c:443)
DEBUG1 - 21:31:10.398480701 [8383/8529]: Disabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_stop() at timer.c:245)
DEBUG1 - 21:31:10.398604016 [8383/8529]: Sending consumer trace chunk exists command: relayd_id = -1, session_id = 0, chunk_id = 0 (in consumer_trace_chunk_exists() at consumer.c:2105)
DEBUG1 - 21:31:10.398796184 [8383/8529]: Consumer ret code -126 (in consumer_recv_status_reply() at consumer.c:200)
DEBUG1 - 21:31:10.398817784 [8383/8529]: Consumer reply to TRACE_CHUNK_EXISTS command: trace chunk exists locally (in consumer_trace_chunk_exists() at consumer.c:2128)
DEBUG1 - 21:31:10.398835285 [8383/8529]: [rotation-thread] Rotation of trace archive 0 is still pending for session life (in check_session_rotation_pending() at rotation-thread.c:506)
DEBUG1 - 21:31:10.398851422 [8383/8529]: Enabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_start() at timer.c:213)
DEBUG1 - 21:31:10.398902635 [8383/8529]: [rotation-thread] Entering poll wait (in thread_rotation() at rotation-thread.c:796)
DEBUG1 - 21:31:10.727351947 [8383/8527]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:545)
DEBUG1 - 21:31:10.727398048 [8383/8527]: [notification-thread] Handling fd (11) activity (1) (in thread_notification() at notification-thread.c:563)
DEBUG1 - 21:31:10.727447061 [8383/8527]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session life (highest usage = 0, lowest usage = 0, total consumed = 6344704) (in handle_notification_thread_channel_sample() at notification-thread-events.c:3261)
DEBUG1 - 21:31:10.727481997 [8383/8527]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:543)
DEBUG1 - 21:31:10.824601604 [8383/8527]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:545)
DEBUG1 - 21:31:10.824655614 [8383/8527]: [notification-thread] Handling fd (17) activity (1) (in thread_notification() at notification-thread.c:563)
DEBUG1 - 21:31:10.824703826 [8383/8527]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session life (highest usage = 0, lowest usage = 0, total consumed = 16384) (in handle_notification_thread_channel_sample() at notification-thread-events.c:3261)
DEBUG1 - 21:31:10.824739062 [8383/8527]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:543)
DEBUG1 - 21:31:10.899122218 [8383/8529]: [rotation-thread] Poll wait returned (1) (in thread_rotation() at rotation-thread.c:798)
DEBUG1 - 21:31:10.899251041 [8383/8529]: [rotation-thread] Handling fd (15) activity (1) (in thread_rotation() at rotation-thread.c:817)
DEBUG1 - 21:31:10.899277406 [8383/8529]: [rotation-thread] Checking for pending rotation on session "life", trace archive 0 (in check_session_rotation_pending() at rotation-thread.c:443)
DEBUG1 - 21:31:10.899293033 [8383/8529]: Disabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_stop() at timer.c:245)
DEBUG1 - 21:31:10.899414017 [8383/8529]: Sending consumer trace chunk exists command: relayd_id = -1, session_id = 0, chunk_id = 0 (in consumer_trace_chunk_exists() at consumer.c:2105)
DEBUG1 - 21:31:10.899619802 [8383/8529]: Consumer ret code -126 (in consumer_recv_status_reply() at consumer.c:200)
DEBUG1 - 21:31:10.899652939 [8383/8529]: Consumer reply to TRACE_CHUNK_EXISTS command: trace chunk exists locally (in consumer_trace_chunk_exists() at consumer.c:2128)
DEBUG1 - 21:31:10.899671963 [8383/8529]: [rotation-thread] Rotation of trace archive 0 is still pending for session life (in check_session_rotation_pending() at rotation-thread.c:506)
DEBUG1 - 21:31:10.899687138 [8383/8529]: Enabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_start() at timer.c:213)
DEBUG1 - 21:31:10.899736411 [8383/8529]: [rotation-thread] Entering poll wait (in thread_rotation() at rotation-thread.c:796)
DEBUG1 - 21:31:11.399937052 [8383/8529]: [rotation-thread] Poll wait returned (1) (in thread_rotation() at rotation-thread.c:798)
DEBUG1 - 21:31:11.399970726 [8383/8529]: [rotation-thread] Handling fd (15) activity (1) (in thread_rotation() at rotation-thread.c:817)
DEBUG1 - 21:31:11.399994224 [8383/8529]: [rotation-thread] Checking for pending rotation on session "life", trace archive 0 (in check_session_rotation_pending() at rotation-thread.c:443)
DEBUG1 - 21:31:11.400008794 [8383/8529]: Disabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_stop() at timer.c:245)
DEBUG1 - 21:31:11.400102960 [8383/8529]: Sending consumer trace chunk exists command: relayd_id = -1, session_id = 0, chunk_id = 0 (in consumer_trace_chunk_exists() at consumer.c:2105)
DEBUG1 - 21:31:11.400253299 [8383/8529]: Consumer ret code -126 (in consumer_recv_status_reply() at consumer.c:200)
DEBUG1 - 21:31:11.400279291 [8383/8529]: Consumer reply to TRACE_CHUNK_EXISTS command: trace chunk exists locally (in consumer_trace_chunk_exists() at consumer.c:2128)
DEBUG1 - 21:31:11.400295428 [8383/8529]: [rotation-thread] Rotation of trace archive 0 is still pending for session life (in check_session_rotation_pending() at rotation-thread.c:506)
DEBUG1 - 21:31:11.400307560 [8383/8529]: Enabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_start() at timer.c:213)
DEBUG1 - 21:31:11.400345015 [8383/8529]: [rotation-thread] Entering poll wait (in thread_rotation() at rotation-thread.c:796)
DEBUG1 - 21:31:11.727362688 [8383/8527]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:545)
DEBUG1 - 21:31:11.727400876 [8383/8527]: [notification-thread] Handling fd (11) activity (1) (in thread_notification() at notification-thread.c:563)
DEBUG1 - 21:31:11.727432038 [8383/8527]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session life (highest usage = 0, lowest usage = 0, total consumed = 6344704) (in handle_notification_thread_channel_sample() at notification-thread-events.c:3261)
DEBUG1 - 21:31:11.727452881 [8383/8527]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:543)
DEBUG1 - 21:31:11.824602628 [8383/8527]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:545)
DEBUG1 - 21:31:11.824654513 [8383/8527]: [notification-thread] Handling fd (17) activity (1) (in thread_notification() at notification-thread.c:563)
DEBUG1 - 21:31:11.824704614 [8383/8527]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session life (highest usage = 0, lowest usage = 0, total consumed = 16384) (in handle_notification_thread_channel_sample() at notification-thread-events.c:3261)
DEBUG1 - 21:31:11.824738778 [8383/8527]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:543)
DEBUG1 - 21:31:11.900559088 [8383/8529]: [rotation-thread] Poll wait returned (1) (in thread_rotation() at rotation-thread.c:798)
DEBUG1 - 21:31:11.900604307 [8383/8529]: [rotation-thread] Handling fd (15) activity (1) (in thread_rotation() at rotation-thread.c:817)
DEBUG1 - 21:31:11.900621747 [8383/8529]: [rotation-thread] Checking for pending rotation on session "life", trace archive 0 (in check_session_rotation_pending() at rotation-thread.c:443)
DEBUG1 - 21:31:11.900636151 [8383/8529]: Disabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_stop() at timer.c:245)
DEBUG1 - 21:31:11.900719984 [8383/8529]: Sending consumer trace chunk exists command: relayd_id = -1, session_id = 0, chunk_id = 0 (in consumer_trace_chunk_exists() at consumer.c:2105)
DEBUG1 - 21:31:11.900869915 [8383/8529]: Consumer ret code -126 (in consumer_recv_status_reply() at consumer.c:200)
DEBUG1 - 21:31:11.900899243 [8383/8529]: Consumer reply to TRACE_CHUNK_EXISTS command: trace chunk exists locally (in consumer_trace_chunk_exists() at consumer.c:2128)
DEBUG1 - 21:31:11.900911802 [8383/8529]: [rotation-thread] Rotation of trace archive 0 is still pending for session life (in check_session_rotation_pending() at rotation-thread.c:506)
DEBUG1 - 21:31:11.900922672 [8383/8529]: Enabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_start() at timer.c:213)
DEBUG1 - 21:31:11.900959713 [8383/8529]: [rotation-thread] Entering poll wait (in thread_rotation() at rotation-thread.c:796)
DEBUG1 - 21:31:12.401162682 [8383/8529]: [rotation-thread] Poll wait returned (1) (in thread_rotation() at rotation-thread.c:798)
DEBUG1 - 21:31:12.401209661 [8383/8529]: [rotation-thread] Handling fd (15) activity (1) (in thread_rotation() at rotation-thread.c:817)
DEBUG1 - 21:31:12.401227798 [8383/8529]: [rotation-thread] Checking for pending rotation on session "life", trace archive 0 (in check_session_rotation_pending() at rotation-thread.c:443)
DEBUG1 - 21:31:12.401245423 [8383/8529]: Disabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_stop() at timer.c:245)
DEBUG1 - 21:31:12.401331547 [8383/8529]: Sending consumer trace chunk exists command: relayd_id = -1, session_id = 0, chunk_id = 0 (in consumer_trace_chunk_exists() at consumer.c:2105)
DEBUG1 - 21:31:12.401544484 [8383/8529]: Consumer ret code -126 (in consumer_recv_status_reply() at consumer.c:200)
DEBUG1 - 21:31:12.401576834 [8383/8529]: Consumer reply to TRACE_CHUNK_EXISTS command: trace chunk exists locally (in consumer_trace_chunk_exists() at consumer.c:2128)
DEBUG1 - 21:31:12.401593708 [8383/8529]: [rotation-thread] Rotation of trace archive 0 is still pending for session life (in check_session_rotation_pending() at rotation-thread.c:506)
DEBUG1 - 21:31:12.401609574 [8383/8529]: Enabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_start() at timer.c:213)
DEBUG1 - 21:31:12.401656889 [8383/8529]: [rotation-thread] Entering poll wait (in thread_rotation() at rotation-thread.c:796)
DEBUG1 - 21:31:12.727164299 [8383/8527]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:545)
DEBUG1 - 21:31:12.727231222 [8383/8527]: [notification-thread] Handling fd (11) activity (1) (in thread_notification() at notification-thread.c:563)
DEBUG1 - 21:31:12.727255281 [8383/8527]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session life (highest usage = 0, lowest usage = 0, total consumed = 6344704) (in handle_notification_thread_channel_sample() at notification-thread-events.c:3261)
DEBUG1 - 21:31:12.727270909 [8383/8527]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:543)
DEBUG1 - 21:31:12.824521462 [8383/8527]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:545)
DEBUG1 - 21:31:12.824565574 [8383/8527]: [notification-thread] Handling fd (17) activity (1) (in thread_notification() at notification-thread.c:563)
DEBUG1 - 21:31:12.824644020 [8383/8527]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session life (highest usage = 0, lowest usage = 0, total consumed = 16384) (in handle_notification_thread_channel_sample() at notification-thread-events.c:3261)
DEBUG1 - 21:31:12.824664026 [8383/8527]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:543)
DEBUG1 - 21:31:12.901866989 [8383/8529]: [rotation-thread] Poll wait returned (1) (in thread_rotation() at rotation-thread.c:798)
DEBUG1 - 21:31:12.901918609 [8383/8529]: [rotation-thread] Handling fd (15) activity (1) (in thread_rotation() at rotation-thread.c:817)
DEBUG1 - 21:31:12.901944273 [8383/8529]: [rotation-thread] Checking for pending rotation on session "life", trace archive 0 (in check_session_rotation_pending() at rotation-thread.c:443)
DEBUG1 - 21:31:12.901968699 [8383/8529]: Disabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_stop() at timer.c:245)
DEBUG1 - 21:31:12.902122825 [8383/8529]: Sending consumer trace chunk exists command: relayd_id = -1, session_id = 0, chunk_id = 0 (in consumer_trace_chunk_exists() at consumer.c:2105)
DEBUG1 - 21:31:12.902321679 [8383/8529]: Consumer ret code -126 (in consumer_recv_status_reply() at consumer.c:200)
DEBUG1 - 21:31:12.902354510 [8383/8529]: Consumer reply to TRACE_CHUNK_EXISTS command: trace chunk exists locally (in consumer_trace_chunk_exists() at consumer.c:2128)
DEBUG1 - 21:31:12.902373489 [8383/8529]: [rotation-thread] Rotation of trace archive 0 is still pending for session life (in check_session_rotation_pending() at rotation-thread.c:506)
DEBUG1 - 21:31:12.902389321 [8383/8529]: Enabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_start() at timer.c:213)
DEBUG1 - 21:31:12.902440208 [8383/8529]: [rotation-thread] Entering poll wait (in thread_rotation() at rotation-thread.c:796)
DEBUG1 - 21:31:13.402508740 [8383/8529]: [rotation-thread] Poll wait returned (1) (in thread_rotation() at rotation-thread.c:798)
DEBUG1 - 21:31:13.402531235 [8383/8529]: [rotation-thread] Handling fd (15) activity (1) (in thread_rotation() at rotation-thread.c:817)
DEBUG1 - 21:31:13.402544220 [8383/8529]: [rotation-thread] Checking for pending rotation on session "life", trace archive 0 (in check_session_rotation_pending() at rotation-thread.c:443)
DEBUG1 - 21:31:13.402547285 [8383/8529]: Disabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_stop() at timer.c:245)
DEBUG1 - 21:31:13.402568227 [8383/8529]: Sending consumer trace chunk exists command: relayd_id = -1, session_id = 0, chunk_id = 0 (in consumer_trace_chunk_exists() at consumer.c:2105)
DEBUG1 - 21:31:13.402621060 [8383/8529]: Consumer ret code -126 (in consumer_recv_status_reply() at consumer.c:200)
DEBUG1 - 21:31:13.402625862 [8383/8529]: Consumer reply to TRACE_CHUNK_EXISTS command: trace chunk exists locally (in consumer_trace_chunk_exists() at consumer.c:2128)
DEBUG1 - 21:31:13.402637917 [8383/8529]: [rotation-thread] Rotation of trace archive 0 is still pending for session life (in check_session_rotation_pending() at rotation-thread.c:506)
DEBUG1 - 21:31:13.402640492 [8383/8529]: Enabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_start() at timer.c:213)
DEBUG1 - 21:31:13.402651609 [8383/8529]: [rotation-thread] Entering poll wait (in thread_rotation() at rotation-thread.c:796)
DEBUG1 - 21:31:13.727357504 [8383/8527]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:545)
DEBUG1 - 21:31:13.727401074 [8383/8527]: [notification-thread] Handling fd (11) activity (1) (in thread_notification() at notification-thread.c:563)
DEBUG1 - 21:31:13.727432878 [8383/8527]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session life (highest usage = 0, lowest usage = 0, total consumed = 6344704) (in handle_notification_thread_channel_sample() at notification-thread-events.c:3261)
DEBUG1 - 21:31:13.727452162 [8383/8527]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:543)
DEBUG1 - 21:31:13.824626045 [8383/8527]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:545)
DEBUG1 - 21:31:13.824688830 [8383/8527]: [notification-thread] Handling fd (17) activity (1) (in thread_notification() at notification-thread.c:563)
DEBUG1 - 21:31:13.824752201 [8383/8527]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session life (highest usage = 0, lowest usage = 0, total consumed = 16384) (in handle_notification_thread_channel_sample() at notification-thread-events.c:3261)
DEBUG1 - 21:31:13.824797947 [8383/8527]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:543)
DEBUG1 - 21:31:13.902868649 [8383/8529]: [rotation-thread] Poll wait returned (1) (in thread_rotation() at rotation-thread.c:798)
DEBUG1 - 21:31:13.902913688 [8383/8529]: [rotation-thread] Handling fd (15) activity (1) (in thread_rotation() at rotation-thread.c:817)
DEBUG1 - 21:31:13.902931925 [8383/8529]: [rotation-thread] Checking for pending rotation on session "life", trace archive 0 (in check_session_rotation_pending() at rotation-thread.c:443)
DEBUG1 - 21:31:13.902967232 [8383/8529]: Disabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_stop() at timer.c:245)
DEBUG1 - 21:31:13.903044620 [8383/8529]: Sending consumer trace chunk exists command: relayd_id = -1, session_id = 0, chunk_id = 0 (in consumer_trace_chunk_exists() at consumer.c:2105)
DEBUG1 - 21:31:13.903262148 [8383/8529]: Consumer ret code -126 (in consumer_recv_status_reply() at consumer.c:200)
DEBUG1 - 21:31:13.903287030 [8383/8529]: Consumer reply to TRACE_CHUNK_EXISTS command: trace chunk exists locally (in consumer_trace_chunk_exists() at consumer.c:2128)
DEBUG1 - 21:31:13.903298872 [8383/8529]: [rotation-thread] Rotation of trace archive 0 is still pending for session life (in check_session_rotation_pending() at rotation-thread.c:506)
DEBUG1 - 21:31:13.903310063 [8383/8529]: Enabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_start() at timer.c:213)
DEBUG1 - 21:31:13.903347665 [8383/8529]: [rotation-thread] Entering poll wait (in thread_rotation() at rotation-thread.c:796)
DEBUG1 - 21:31:14.403551401 [8383/8529]: [rotation-thread] Poll wait returned (1) (in thread_rotation() at rotation-thread.c:798)
DEBUG1 - 21:31:14.403599292 [8383/8529]: [rotation-thread] Handling fd (15) activity (1) (in thread_rotation() at rotation-thread.c:817)
DEBUG1 - 21:31:14.403617278 [8383/8529]: [rotation-thread] Checking for pending rotation on session "life", trace archive 0 (in check_session_rotation_pending() at rotation-thread.c:443)
DEBUG1 - 21:31:14.403634152 [8383/8529]: Disabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_stop() at timer.c:245)
DEBUG1 - 21:31:14.403716748 [8383/8529]: Sending consumer trace chunk exists command: relayd_id = -1, session_id = 0, chunk_id = 0 (in consumer_trace_chunk_exists() at consumer.c:2105)
DEBUG1 - 21:31:14.403864865 [8383/8529]: Consumer ret code -126 (in consumer_recv_status_reply() at consumer.c:200)
DEBUG1 - 21:31:14.403889452 [8383/8529]: Consumer reply to TRACE_CHUNK_EXISTS command: trace chunk exists locally (in consumer_trace_chunk_exists() at consumer.c:2128)
DEBUG1 - 21:31:14.403901174 [8383/8529]: [rotation-thread] Rotation of trace archive 0 is still pending for session life (in check_session_rotation_pending() at rotation-thread.c:506)
DEBUG1 - 21:31:14.403912044 [8383/8529]: Enabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_start() at timer.c:213)
DEBUG1 - 21:31:14.403948839 [8383/8529]: [rotation-thread] Entering poll wait (in thread_rotation() at rotation-thread.c:796)
DEBUG1 - 21:31:14.727357445 [8383/8527]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:545)
DEBUG1 - 21:31:14.727396530 [8383/8527]: [notification-thread] Handling fd (11) activity (1) (in thread_notification() at notification-thread.c:563)
DEBUG1 - 21:31:14.727421097 [8383/8527]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session life (highest usage = 0, lowest usage = 0, total consumed = 6344704) (in handle_notification_thread_channel_sample() at notification-thread-events.c:3261)
DEBUG1 - 21:31:14.727435836 [8383/8527]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:543)
DEBUG1 - 21:31:14.824604923 [8383/8527]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:545)
DEBUG1 - 21:31:14.824651124 [8383/8527]: [notification-thread] Handling fd (17) activity (1) (in thread_notification() at notification-thread.c:563)
DEBUG1 - 21:31:14.824685148 [8383/8527]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session life (highest usage = 0, lowest usage = 0, total consumed = 16384) (in handle_notification_thread_channel_sample() at notification-thread-events.c:3261)
DEBUG1 - 21:31:14.824708522 [8383/8527]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:543)
DEBUG1 - 21:31:14.904167811 [8383/8529]: [rotation-thread] Poll wait returned (1) (in thread_rotation() at rotation-thread.c:798)
DEBUG1 - 21:31:14.904216999 [8383/8529]: [rotation-thread] Handling fd (15) activity (1) (in thread_rotation() at rotation-thread.c:817)
DEBUG1 - 21:31:14.904235552 [8383/8529]: [rotation-thread] Checking for pending rotation on session "life", trace archive 0 (in check_session_rotation_pending() at rotation-thread.c:443)
DEBUG1 - 21:31:14.904254205 [8383/8529]: Disabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_stop() at timer.c:245)
DEBUG1 - 21:31:14.904336275 [8383/8529]: Sending consumer trace chunk exists command: relayd_id = -1, session_id = 0, chunk_id = 0 (in consumer_trace_chunk_exists() at consumer.c:2105)
DEBUG1 - 21:31:14.904478919 [8383/8529]: Consumer ret code -126 (in consumer_recv_status_reply() at consumer.c:200)
DEBUG1 - 21:31:14.904501902 [8383/8529]: Consumer reply to TRACE_CHUNK_EXISTS command: trace chunk exists locally (in consumer_trace_chunk_exists() at consumer.c:2128)
DEBUG1 - 21:31:14.904513669 [8383/8529]: [rotation-thread] Rotation of trace archive 0 is still pending for session life (in check_session_rotation_pending() at rotation-thread.c:506)
DEBUG1 - 21:31:14.904524389 [8383/8529]: Enabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_start() at timer.c:213)
DEBUG1 - 21:31:14.904561029 [8383/8529]: [rotation-thread] Entering poll wait (in thread_rotation() at rotation-thread.c:796)
DEBUG1 - 21:31:14.943065664 [8384/8384]: run_as worker received signal SIGINT (in worker_sighandler() at runas.c:1147)
DEBUG1 - 21:31:14.943072590 [8383/8383]: SIGINT caught (in sighandler() at main.c:1105)
DEBUG1 - 21:31:14.943114211 [8383/8383]: Terminating all threads (in stop_threads() at main.c:163)
DEBUG1 - 21:31:14.943235486 [8383/8383]: Shutting down "Client management" thread (in _lttng_thread_shutdown() at thread.c:152)
DEBUG1 - 21:31:14.943331418 [8383/8530]: Clean command context structure (in clean_command_ctx() at client.c:650)
DEBUG1 - 21:31:14.943408651 [8383/8530]: Client thread dying (in thread_manage_clients() at client.c:2422)
DEBUG1 - 21:31:14.943435398 [8383/8530]: Thread "Client management" has returned (in launch_thread() at thread.c:66)
DEBUG1 - 21:31:14.943586326 [8383/8383]: Initiating destruction of all sessions (in destroy_all_sessions_and_wait() at main.c:1224)
DEBUG1 - 21:31:14.943617669 [8383/8383]: Waiting for the destruction of all sessions to complete (in destroy_all_sessions_and_wait() at main.c:1252)
DEBUG1 - 21:31:15.404700812 [8383/8529]: [rotation-thread] Poll wait returned (1) (in thread_rotation() at rotation-thread.c:798)
DEBUG1 - 21:31:15.404725482 [8383/8529]: [rotation-thread] Handling fd (15) activity (1) (in thread_rotation() at rotation-thread.c:817)
DEBUG1 - 21:31:15.404735966 [8383/8529]: [rotation-thread] Checking for pending rotation on session "life", trace archive 0 (in check_session_rotation_pending() at rotation-thread.c:443)
DEBUG1 - 21:31:15.404742118 [8383/8529]: Disabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_stop() at timer.c:245)
DEBUG1 - 21:31:15.404785811 [8383/8529]: Sending consumer trace chunk exists command: relayd_id = -1, session_id = 0, chunk_id = 0 (in consumer_trace_chunk_exists() at consumer.c:2105)
DEBUG1 - 21:31:15.404871304 [8383/8529]: Consumer ret code -126 (in consumer_recv_status_reply() at consumer.c:200)
DEBUG1 - 21:31:15.404886757 [8383/8529]: Consumer reply to TRACE_CHUNK_EXISTS command: trace chunk exists locally (in consumer_trace_chunk_exists() at consumer.c:2128)
DEBUG1 - 21:31:15.404893545 [8383/8529]: [rotation-thread] Rotation of trace archive 0 is still pending for session life (in check_session_rotation_pending() at rotation-thread.c:506)
DEBUG1 - 21:31:15.404899423 [8383/8529]: Enabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_start() at timer.c:213)
DEBUG1 - 21:31:15.404920154 [8383/8529]: [rotation-thread] Entering poll wait (in thread_rotation() at rotation-thread.c:796)
DEBUG1 - 21:31:15.727339685 [8383/8527]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:545)
DEBUG1 - 21:31:15.727382224 [8383/8527]: [notification-thread] Handling fd (11) activity (1) (in thread_notification() at notification-thread.c:563)
DEBUG1 - 21:31:15.727414583 [8383/8527]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session life (highest usage = 0, lowest usage = 0, total consumed = 6344704) (in handle_notification_thread_channel_sample() at notification-thread-events.c:3261)
DEBUG1 - 21:31:15.727434063 [8383/8527]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:543)
DEBUG1 - 21:31:15.824600569 [8383/8527]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:545)
DEBUG1 - 21:31:15.824645237 [8383/8527]: [notification-thread] Handling fd (17) activity (1) (in thread_notification() at notification-thread.c:563)
DEBUG1 - 21:31:15.824679617 [8383/8527]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session life (highest usage = 0, lowest usage = 0, total consumed = 16384) (in handle_notification_thread_channel_sample() at notification-thread-events.c:3261)
DEBUG1 - 21:31:15.824702870 [8383/8527]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:543)
DEBUG1 - 21:31:15.905120462 [8383/8529]: [rotation-thread] Poll wait returned (1) (in thread_rotation() at rotation-thread.c:798)
DEBUG1 - 21:31:15.905170753 [8383/8529]: [rotation-thread] Handling fd (15) activity (1) (in thread_rotation() at rotation-thread.c:817)
DEBUG1 - 21:31:15.905201659 [8383/8529]: [rotation-thread] Checking for pending rotation on session "life", trace archive 0 (in check_session_rotation_pending() at rotation-thread.c:443)
DEBUG1 - 21:31:15.905222397 [8383/8529]: Disabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_stop() at timer.c:245)
DEBUG1 - 21:31:15.905375561 [8383/8529]: Sending consumer trace chunk exists command: relayd_id = -1, session_id = 0, chunk_id = 0 (in consumer_trace_chunk_exists() at consumer.c:2105)
DEBUG1 - 21:31:15.905602320 [8383/8529]: Consumer ret code -126 (in consumer_recv_status_reply() at consumer.c:200)
DEBUG1 - 21:31:15.905626385 [8383/8529]: Consumer reply to TRACE_CHUNK_EXISTS command: trace chunk exists locally (in consumer_trace_chunk_exists() at consumer.c:2128)
DEBUG1 - 21:31:15.905643841 [8383/8529]: [rotation-thread] Rotation of trace archive 0 is still pending for session life (in check_session_rotation_pending() at rotation-thread.c:506)
DEBUG1 - 21:31:15.905659346 [8383/8529]: Enabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_start() at timer.c:213)
DEBUG1 - 21:31:15.905708871 [8383/8529]: [rotation-thread] Entering poll wait (in thread_rotation() at rotation-thread.c:796)
DEBUG1 - 21:31:16.405882775 [8383/8529]: [rotation-thread] Poll wait returned (1) (in thread_rotation() at rotation-thread.c:798)
DEBUG1 - 21:31:16.405925283 [8383/8529]: [rotation-thread] Handling fd (15) activity (1) (in thread_rotation() at rotation-thread.c:817)
DEBUG1 - 21:31:16.405940074 [8383/8529]: [rotation-thread] Checking for pending rotation on session "life", trace archive 0 (in check_session_rotation_pending() at rotation-thread.c:443)
DEBUG1 - 21:31:16.405951096 [8383/8529]: Disabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_stop() at timer.c:245)
DEBUG1 - 21:31:16.406012294 [8383/8529]: Sending consumer trace chunk exists command: relayd_id = -1, session_id = 0, chunk_id = 0 (in consumer_trace_chunk_exists() at consumer.c:2105)
DEBUG1 - 21:31:16.406128900 [8383/8529]: Consumer ret code -126 (in consumer_recv_status_reply() at consumer.c:200)
DEBUG1 - 21:31:16.406149775 [8383/8529]: Consumer reply to TRACE_CHUNK_EXISTS command: trace chunk exists locally (in consumer_trace_chunk_exists() at consumer.c:2128)
DEBUG1 - 21:31:16.406163379 [8383/8529]: [rotation-thread] Rotation of trace archive 0 is still pending for session life (in check_session_rotation_pending() at rotation-thread.c:506)
DEBUG1 - 21:31:16.406174244 [8383/8529]: Enabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_start() at timer.c:213)
DEBUG1 - 21:31:16.406207013 [8383/8529]: [rotation-thread] Entering poll wait (in thread_rotation() at rotation-thread.c:796)
DEBUG1 - 21:31:16.727327464 [8383/8527]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:545)
DEBUG1 - 21:31:16.727366178 [8383/8527]: [notification-thread] Handling fd (11) activity (1) (in thread_notification() at notification-thread.c:563)
DEBUG1 - 21:31:16.727391231 [8383/8527]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session life (highest usage = 0, lowest usage = 0, total consumed = 6344704) (in handle_notification_thread_channel_sample() at notification-thread-events.c:3261)
DEBUG1 - 21:31:16.727406140 [8383/8527]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:543)
DEBUG1 - 21:31:16.824598886 [8383/8527]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:545)
DEBUG1 - 21:31:16.824646156 [8383/8527]: [notification-thread] Handling fd (17) activity (1) (in thread_notification() at notification-thread.c:563)
DEBUG1 - 21:31:16.824679528 [8383/8527]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session life (highest usage = 0, lowest usage = 0, total consumed = 16384) (in handle_notification_thread_channel_sample() at notification-thread-events.c:3261)
DEBUG1 - 21:31:16.824702932 [8383/8527]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:543)
DEBUG1 - 21:31:16.906404473 [8383/8529]: [rotation-thread] Poll wait returned (1) (in thread_rotation() at rotation-thread.c:798)
DEBUG1 - 21:31:16.906451267 [8383/8529]: [rotation-thread] Handling fd (15) activity (1) (in thread_rotation() at rotation-thread.c:817)
DEBUG1 - 21:31:16.906469739 [8383/8529]: [rotation-thread] Checking for pending rotation on session "life", trace archive 0 (in check_session_rotation_pending() at rotation-thread.c:443)
DEBUG1 - 21:31:16.906487395 [8383/8529]: Disabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_stop() at timer.c:245)
DEBUG1 - 21:31:16.906568497 [8383/8529]: Sending consumer trace chunk exists command: relayd_id = -1, session_id = 0, chunk_id = 0 (in consumer_trace_chunk_exists() at consumer.c:2105)
DEBUG1 - 21:31:16.906704561 [8383/8529]: Consumer ret code -126 (in consumer_recv_status_reply() at consumer.c:200)
DEBUG1 - 21:31:16.906728522 [8383/8529]: Consumer reply to TRACE_CHUNK_EXISTS command: trace chunk exists locally (in consumer_trace_chunk_exists() at consumer.c:2128)
DEBUG1 - 21:31:16.906740194 [8383/8529]: [rotation-thread] Rotation of trace archive 0 is still pending for session life (in check_session_rotation_pending() at rotation-thread.c:506)
DEBUG1 - 21:31:16.906750778 [8383/8529]: Enabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_start() at timer.c:213)
DEBUG1 - 21:31:16.906787919 [8383/8529]: [rotation-thread] Entering poll wait (in thread_rotation() at rotation-thread.c:796)
DEBUG1 - 21:31:17.406899272 [8383/8529]: [rotation-thread] Poll wait returned (1) (in thread_rotation() at rotation-thread.c:798)
DEBUG1 - 21:31:17.406919048 [8383/8529]: [rotation-thread] Handling fd (15) activity (1) (in thread_rotation() at rotation-thread.c:817)
DEBUG1 - 21:31:17.406924904 [8383/8529]: [rotation-thread] Checking for pending rotation on session "life", trace archive 0 (in check_session_rotation_pending() at rotation-thread.c:443)
DEBUG1 - 21:31:17.406929283 [8383/8529]: Disabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_stop() at timer.c:245)
DEBUG1 - 21:31:17.406961287 [8383/8529]: Sending consumer trace chunk exists command: relayd_id = -1, session_id = 0, chunk_id = 0 (in consumer_trace_chunk_exists() at consumer.c:2105)
DEBUG1 - 21:31:17.407023838 [8383/8529]: Consumer ret code -126 (in consumer_recv_status_reply() at consumer.c:200)
DEBUG1 - 21:31:17.407033950 [8383/8529]: Consumer reply to TRACE_CHUNK_EXISTS command: trace chunk exists locally (in consumer_trace_chunk_exists() at consumer.c:2128)
DEBUG1 - 21:31:17.407038752 [8383/8529]: [rotation-thread] Rotation of trace archive 0 is still pending for session life (in check_session_rotation_pending() at rotation-thread.c:506)
DEBUG1 - 21:31:17.407044053 [8383/8529]: Enabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_start() at timer.c:213)
DEBUG1 - 21:31:17.407062091 [8383/8529]: [rotation-thread] Entering poll wait (in thread_rotation() at rotation-thread.c:796)
DEBUG1 - 21:31:17.727361353 [8383/8527]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:545)
DEBUG1 - 21:31:17.727410206 [8383/8527]: [notification-thread] Handling fd (11) activity (1) (in thread_notification() at notification-thread.c:563)
DEBUG1 - 21:31:17.727442891 [8383/8527]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session life (highest usage = 0, lowest usage = 0, total consumed = 6344704) (in handle_notification_thread_channel_sample() at notification-thread-events.c:3261)
DEBUG1 - 21:31:17.727464617 [8383/8527]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:543)
DEBUG1 - 21:31:17.824486583 [8383/8527]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:545)
DEBUG1 - 21:31:17.824521925 [8383/8527]: [notification-thread] Handling fd (17) activity (1) (in thread_notification() at notification-thread.c:563)
DEBUG1 - 21:31:17.824551914 [8383/8527]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session life (highest usage = 0, lowest usage = 0, total consumed = 16384) (in handle_notification_thread_channel_sample() at notification-thread-events.c:3261)
DEBUG1 - 21:31:17.824572427 [8383/8527]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:543)
DEBUG1 - 21:31:17.907294788 [8383/8529]: [rotation-thread] Poll wait returned (1) (in thread_rotation() at rotation-thread.c:798)
DEBUG1 - 21:31:17.907324256 [8383/8529]: [rotation-thread] Handling fd (15) activity (1) (in thread_rotation() at rotation-thread.c:817)
DEBUG1 - 21:31:17.907337299 [8383/8529]: [rotation-thread] Checking for pending rotation on session "life", trace archive 0 (in check_session_rotation_pending() at rotation-thread.c:443)
DEBUG1 - 21:31:17.907347145 [8383/8529]: Disabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_stop() at timer.c:245)
DEBUG1 - 21:31:17.907425109 [8383/8529]: Sending consumer trace chunk exists command: relayd_id = -1, session_id = 0, chunk_id = 0 (in consumer_trace_chunk_exists() at consumer.c:2105)
DEBUG1 - 21:31:17.907570265 [8383/8529]: Consumer ret code -126 (in consumer_recv_status_reply() at consumer.c:200)
DEBUG1 - 21:31:17.907588611 [8383/8529]: Consumer reply to TRACE_CHUNK_EXISTS command: trace chunk exists locally (in consumer_trace_chunk_exists() at consumer.c:2128)
DEBUG1 - 21:31:17.907602139 [8383/8529]: [rotation-thread] Rotation of trace archive 0 is still pending for session life (in check_session_rotation_pending() at rotation-thread.c:506)
DEBUG1 - 21:31:17.907613950 [8383/8529]: Enabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_start() at timer.c:213)
DEBUG1 - 21:31:17.907646770 [8383/8529]: [rotation-thread] Entering poll wait (in thread_rotation() at rotation-thread.c:796)
DEBUG1 - 21:31:18.407827792 [8383/8529]: [rotation-thread] Poll wait returned (1) (in thread_rotation() at rotation-thread.c:798)
DEBUG1 - 21:31:18.407885646 [8383/8529]: [rotation-thread] Handling fd (15) activity (1) (in thread_rotation() at rotation-thread.c:817)
DEBUG1 - 21:31:18.407905181 [8383/8529]: [rotation-thread] Checking for pending rotation on session "life", trace archive 0 (in check_session_rotation_pending() at rotation-thread.c:443)
DEBUG1 - 21:31:18.407919349 [8383/8529]: Disabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_stop() at timer.c:245)
DEBUG1 - 21:31:18.408008795 [8383/8529]: Sending consumer trace chunk exists command: relayd_id = -1, session_id = 0, chunk_id = 0 (in consumer_trace_chunk_exists() at consumer.c:2105)
DEBUG1 - 21:31:18.408199185 [8383/8529]: Consumer ret code -126 (in consumer_recv_status_reply() at consumer.c:200)
DEBUG1 - 21:31:18.408232517 [8383/8529]: Consumer reply to TRACE_CHUNK_EXISTS command: trace chunk exists locally (in consumer_trace_chunk_exists() at consumer.c:2128)
DEBUG1 - 21:31:18.408250208 [8383/8529]: [rotation-thread] Rotation of trace archive 0 is still pending for session life (in check_session_rotation_pending() at rotation-thread.c:506)
DEBUG1 - 21:31:18.408265493 [8383/8529]: Enabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_start() at timer.c:213)
DEBUG1 - 21:31:18.408312918 [8383/8529]: [rotation-thread] Entering poll wait (in thread_rotation() at rotation-thread.c:796)
DEBUG1 - 21:31:18.727361906 [8383/8527]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:545)
DEBUG1 - 21:31:18.727403151 [8383/8527]: [notification-thread] Handling fd (11) activity (1) (in thread_notification() at notification-thread.c:563)
DEBUG1 - 21:31:18.727427803 [8383/8527]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session life (highest usage = 0, lowest usage = 0, total consumed = 6344704) (in handle_notification_thread_channel_sample() at notification-thread-events.c:3261)
DEBUG1 - 21:31:18.727442412 [8383/8527]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:543)
DEBUG1 - 21:31:18.824576853 [8383/8527]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:545)
DEBUG1 - 21:31:18.824624498 [8383/8527]: [notification-thread] Handling fd (17) activity (1) (in thread_notification() at notification-thread.c:563)
DEBUG1 - 21:31:18.824655345 [8383/8527]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session life (highest usage = 0, lowest usage = 0, total consumed = 16384) (in handle_notification_thread_channel_sample() at notification-thread-events.c:3261)
DEBUG1 - 21:31:18.824675937 [8383/8527]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:543)
DEBUG1 - 21:31:18.908503950 [8383/8529]: [rotation-thread] Poll wait returned (1) (in thread_rotation() at rotation-thread.c:798)
DEBUG1 - 21:31:18.908556140 [8383/8529]: [rotation-thread] Handling fd (15) activity (1) (in thread_rotation() at rotation-thread.c:817)
DEBUG1 - 21:31:18.908585077 [8383/8529]: [rotation-thread] Checking for pending rotation on session "life", trace archive 0 (in check_session_rotation_pending() at rotation-thread.c:443)
DEBUG1 - 21:31:18.908609067 [8383/8529]: Disabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_stop() at timer.c:245)
DEBUG1 - 21:31:18.908763960 [8383/8529]: Sending consumer trace chunk exists command: relayd_id = -1, session_id = 0, chunk_id = 0 (in consumer_trace_chunk_exists() at consumer.c:2105)
DEBUG1 - 21:31:18.908974717 [8383/8529]: Consumer ret code -126 (in consumer_recv_status_reply() at consumer.c:200)
DEBUG1 - 21:31:18.909008304 [8383/8529]: Consumer reply to TRACE_CHUNK_EXISTS command: trace chunk exists locally (in consumer_trace_chunk_exists() at consumer.c:2128)
DEBUG1 - 21:31:18.909027328 [8383/8529]: [rotation-thread] Rotation of trace archive 0 is still pending for session life (in check_session_rotation_pending() at rotation-thread.c:506)
DEBUG1 - 21:31:18.909042789 [8383/8529]: Enabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_start() at timer.c:213)
DEBUG1 - 21:31:18.909093411 [8383/8529]: [rotation-thread] Entering poll wait (in thread_rotation() at rotation-thread.c:796)
DEBUG1 - 21:31:19.409292546 [8383/8529]: [rotation-thread] Poll wait returned (1) (in thread_rotation() at rotation-thread.c:798)
DEBUG1 - 21:31:19.409337580 [8383/8529]: [rotation-thread] Handling fd (15) activity (1) (in thread_rotation() at rotation-thread.c:817)
DEBUG1 - 21:31:19.409355507 [8383/8529]: [rotation-thread] Checking for pending rotation on session "life", trace archive 0 (in check_session_rotation_pending() at rotation-thread.c:443)
DEBUG1 - 21:31:19.409370366 [8383/8529]: Disabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_stop() at timer.c:245)
DEBUG1 - 21:31:19.409453694 [8383/8529]: Sending consumer trace chunk exists command: relayd_id = -1, session_id = 0, chunk_id = 0 (in consumer_trace_chunk_exists() at consumer.c:2105)
DEBUG1 - 21:31:19.409593086 [8383/8529]: Consumer ret code -126 (in consumer_recv_status_reply() at consumer.c:200)
DEBUG1 - 21:31:19.409616745 [8383/8529]: Consumer reply to TRACE_CHUNK_EXISTS command: trace chunk exists locally (in consumer_trace_chunk_exists() at consumer.c:2128)
DEBUG1 - 21:31:19.409628618 [8383/8529]: [rotation-thread] Rotation of trace archive 0 is still pending for session life (in check_session_rotation_pending() at rotation-thread.c:506)
DEBUG1 - 21:31:19.409639352 [8383/8529]: Enabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_start() at timer.c:213)
DEBUG1 - 21:31:19.409675832 [8383/8529]: [rotation-thread] Entering poll wait (in thread_rotation() at rotation-thread.c:796)
DEBUG1 - 21:31:19.727375504 [8383/8527]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:545)
DEBUG1 - 21:31:19.727415927 [8383/8527]: [notification-thread] Handling fd (11) activity (1) (in thread_notification() at notification-thread.c:563)
DEBUG1 - 21:31:19.727440819 [8383/8527]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session life (highest usage = 0, lowest usage = 0, total consumed = 6344704) (in handle_notification_thread_channel_sample() at notification-thread-events.c:3261)
DEBUG1 - 21:31:19.727456441 [8383/8527]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:543)
DEBUG1 - 21:31:19.824540070 [8383/8527]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:545)
DEBUG1 - 21:31:19.824585445 [8383/8527]: [notification-thread] Handling fd (17) activity (1) (in thread_notification() at notification-thread.c:563)
DEBUG1 - 21:31:19.824614171 [8383/8527]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session life (highest usage = 0, lowest usage = 0, total consumed = 16384) (in handle_notification_thread_channel_sample() at notification-thread-events.c:3261)
DEBUG1 - 21:31:19.824631671 [8383/8527]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:543)
DEBUG1 - 21:31:19.909820065 [8383/8529]: [rotation-thread] Poll wait returned (1) (in thread_rotation() at rotation-thread.c:798)
DEBUG1 - 21:31:19.909852430 [8383/8529]: [rotation-thread] Handling fd (15) activity (1) (in thread_rotation() at rotation-thread.c:817)
DEBUG1 - 21:31:19.909863215 [8383/8529]: [rotation-thread] Checking for pending rotation on session "life", trace archive 0 (in check_session_rotation_pending() at rotation-thread.c:443)
DEBUG1 - 21:31:19.909871865 [8383/8529]: Disabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_stop() at timer.c:245)
DEBUG1 - 21:31:19.909925359 [8383/8529]: Sending consumer trace chunk exists command: relayd_id = -1, session_id = 0, chunk_id = 0 (in consumer_trace_chunk_exists() at consumer.c:2105)
DEBUG1 - 21:31:19.910024077 [8383/8529]: Consumer ret code -126 (in consumer_recv_status_reply() at consumer.c:200)
DEBUG1 - 21:31:19.910040929 [8383/8529]: Consumer reply to TRACE_CHUNK_EXISTS command: trace chunk exists locally (in consumer_trace_chunk_exists() at consumer.c:2128)
DEBUG1 - 21:31:19.910049525 [8383/8529]: [rotation-thread] Rotation of trace archive 0 is still pending for session life (in check_session_rotation_pending() at rotation-thread.c:506)
DEBUG1 - 21:31:19.910057193 [8383/8529]: Enabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_start() at timer.c:213)
DEBUG1 - 21:31:19.910083728 [8383/8529]: [rotation-thread] Entering poll wait (in thread_rotation() at rotation-thread.c:796)
DEBUG1 - 21:31:20.410290543 [8383/8529]: [rotation-thread] Poll wait returned (1) (in thread_rotation() at rotation-thread.c:798)
DEBUG1 - 21:31:20.410338163 [8383/8529]: [rotation-thread] Handling fd (15) activity (1) (in thread_rotation() at rotation-thread.c:817)
DEBUG1 - 21:31:20.410357307 [8383/8529]: [rotation-thread] Checking for pending rotation on session "life", trace archive 0 (in check_session_rotation_pending() at rotation-thread.c:443)
DEBUG1 - 21:31:20.410375594 [8383/8529]: Disabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_stop() at timer.c:245)
DEBUG1 - 21:31:20.410460826 [8383/8529]: Sending consumer trace chunk exists command: relayd_id = -1, session_id = 0, chunk_id = 0 (in consumer_trace_chunk_exists() at consumer.c:2105)
DEBUG1 - 21:31:20.410609259 [8383/8529]: Consumer ret code -126 (in consumer_recv_status_reply() at consumer.c:200)
DEBUG1 - 21:31:20.410634567 [8383/8529]: Consumer reply to TRACE_CHUNK_EXISTS command: trace chunk exists locally (in consumer_trace_chunk_exists() at consumer.c:2128)
DEBUG1 - 21:31:20.410646364 [8383/8529]: [rotation-thread] Rotation of trace archive 0 is still pending for session life (in check_session_rotation_pending() at rotation-thread.c:506)
DEBUG1 - 21:31:20.410656949 [8383/8529]: Enabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_start() at timer.c:213)
DEBUG1 - 21:31:20.410693884 [8383/8529]: [rotation-thread] Entering poll wait (in thread_rotation() at rotation-thread.c:796)
DEBUG1 - 21:31:20.727373535 [8383/8527]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:545)
DEBUG1 - 21:31:20.727414981 [8383/8527]: [notification-thread] Handling fd (11) activity (1) (in thread_notification() at notification-thread.c:563)
DEBUG1 - 21:31:20.727439758 [8383/8527]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session life (highest usage = 0, lowest usage = 0, total consumed = 6344704) (in handle_notification_thread_channel_sample() at notification-thread-events.c:3261)
DEBUG1 - 21:31:20.727455074 [8383/8527]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:543)
DEBUG1 - 21:31:20.824579387 [8383/8527]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:545)
DEBUG1 - 21:31:20.824627017 [8383/8527]: [notification-thread] Handling fd (17) activity (1) (in thread_notification() at notification-thread.c:563)
DEBUG1 - 21:31:20.824657813 [8383/8527]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session life (highest usage = 0, lowest usage = 0, total consumed = 16384) (in handle_notification_thread_channel_sample() at notification-thread-events.c:3261)
DEBUG1 - 21:31:20.824678371 [8383/8527]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:543)
DEBUG1 - 21:31:20.910886389 [8383/8529]: [rotation-thread] Poll wait returned (1) (in thread_rotation() at rotation-thread.c:798)
DEBUG1 - 21:31:20.910934089 [8383/8529]: [rotation-thread] Handling fd (15) activity (1) (in thread_rotation() at rotation-thread.c:817)
DEBUG1 - 21:31:20.910953219 [8383/8529]: [rotation-thread] Checking for pending rotation on session "life", trace archive 0 (in check_session_rotation_pending() at rotation-thread.c:443)
DEBUG1 - 21:31:20.910968935 [8383/8529]: Disabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_stop() at timer.c:245)
DEBUG1 - 21:31:20.911052453 [8383/8529]: Sending consumer trace chunk exists command: relayd_id = -1, session_id = 0, chunk_id = 0 (in consumer_trace_chunk_exists() at consumer.c:2105)
DEBUG1 - 21:31:20.911272877 [8383/8529]: Consumer ret code -126 (in consumer_recv_status_reply() at consumer.c:200)
DEBUG1 - 21:31:20.911296937 [8383/8529]: Consumer reply to TRACE_CHUNK_EXISTS command: trace chunk exists locally (in consumer_trace_chunk_exists() at consumer.c:2128)
DEBUG1 - 21:31:20.911308735 [8383/8529]: [rotation-thread] Rotation of trace archive 0 is still pending for session life (in check_session_rotation_pending() at rotation-thread.c:506)
DEBUG1 - 21:31:20.911319665 [8383/8529]: Enabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_start() at timer.c:213)
DEBUG1 - 21:31:20.911356375 [8383/8529]: [rotation-thread] Entering poll wait (in thread_rotation() at rotation-thread.c:796)
DEBUG1 - 21:31:21.411488729 [8383/8529]: [rotation-thread] Poll wait returned (1) (in thread_rotation() at rotation-thread.c:798)
DEBUG1 - 21:31:21.411512392 [8383/8529]: [rotation-thread] Handling fd (15) activity (1) (in thread_rotation() at rotation-thread.c:817)
DEBUG1 - 21:31:21.411519877 [8383/8529]: [rotation-thread] Checking for pending rotation on session "life", trace archive 0 (in check_session_rotation_pending() at rotation-thread.c:443)
DEBUG1 - 21:31:21.411525087 [8383/8529]: Disabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_stop() at timer.c:245)
DEBUG1 - 21:31:21.411561647 [8383/8529]: Sending consumer trace chunk exists command: relayd_id = -1, session_id = 0, chunk_id = 0 (in consumer_trace_chunk_exists() at consumer.c:2105)
DEBUG1 - 21:31:21.411626844 [8383/8529]: Consumer ret code -126 (in consumer_recv_status_reply() at consumer.c:200)
DEBUG1 - 21:31:21.411637362 [8383/8529]: Consumer reply to TRACE_CHUNK_EXISTS command: trace chunk exists locally (in consumer_trace_chunk_exists() at consumer.c:2128)
DEBUG1 - 21:31:21.411642592 [8383/8529]: [rotation-thread] Rotation of trace archive 0 is still pending for session life (in check_session_rotation_pending() at rotation-thread.c:506)
DEBUG1 - 21:31:21.411647341 [8383/8529]: Enabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_start() at timer.c:213)
DEBUG1 - 21:31:21.411663695 [8383/8529]: [rotation-thread] Entering poll wait (in thread_rotation() at rotation-thread.c:796)
DEBUG1 - 21:31:21.727336757 [8383/8527]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:545)
DEBUG1 - 21:31:21.727378062 [8383/8527]: [notification-thread] Handling fd (11) activity (1) (in thread_notification() at notification-thread.c:563)
DEBUG1 - 21:31:21.727402925 [8383/8527]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session life (highest usage = 0, lowest usage = 0, total consumed = 6344704) (in handle_notification_thread_channel_sample() at notification-thread-events.c:3261)
DEBUG1 - 21:31:21.727418486 [8383/8527]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:543)
DEBUG1 - 21:31:21.824574365 [8383/8527]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:545)
DEBUG1 - 21:31:21.824615705 [8383/8527]: [notification-thread] Handling fd (17) activity (1) (in thread_notification() at notification-thread.c:563)
DEBUG1 - 21:31:21.824642848 [8383/8527]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session life (highest usage = 0, lowest usage = 0, total consumed = 16384) (in handle_notification_thread_channel_sample() at notification-thread-events.c:3261)
DEBUG1 - 21:31:21.824660439 [8383/8527]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:543)
DEBUG1 - 21:31:21.911821179 [8383/8529]: [rotation-thread] Poll wait returned (1) (in thread_rotation() at rotation-thread.c:798)
DEBUG1 - 21:31:21.911850897 [8383/8529]: [rotation-thread] Handling fd (15) activity (1) (in thread_rotation() at rotation-thread.c:817)
DEBUG1 - 21:31:21.911861585 [8383/8529]: [rotation-thread] Checking for pending rotation on session "life", trace archive 0 (in check_session_rotation_pending() at rotation-thread.c:443)
DEBUG1 - 21:31:21.911871032 [8383/8529]: Disabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_stop() at timer.c:245)
DEBUG1 - 21:31:21.911919270 [8383/8529]: Sending consumer trace chunk exists command: relayd_id = -1, session_id = 0, chunk_id = 0 (in consumer_trace_chunk_exists() at consumer.c:2105)
DEBUG1 - 21:31:21.912004552 [8383/8529]: Consumer ret code -126 (in consumer_recv_status_reply() at consumer.c:200)
DEBUG1 - 21:31:21.912017978 [8383/8529]: Consumer reply to TRACE_CHUNK_EXISTS command: trace chunk exists locally (in consumer_trace_chunk_exists() at consumer.c:2128)
DEBUG1 - 21:31:21.912024667 [8383/8529]: [rotation-thread] Rotation of trace archive 0 is still pending for session life (in check_session_rotation_pending() at rotation-thread.c:506)
DEBUG1 - 21:31:21.912030753 [8383/8529]: Enabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_start() at timer.c:213)
DEBUG1 - 21:31:21.912052302 [8383/8529]: [rotation-thread] Entering poll wait (in thread_rotation() at rotation-thread.c:796)
DEBUG1 - 21:31:22.412230425 [8383/8529]: [rotation-thread] Poll wait returned (1) (in thread_rotation() at rotation-thread.c:798)
DEBUG1 - 21:31:22.412293852 [8383/8529]: [rotation-thread] Handling fd (15) activity (1) (in thread_rotation() at rotation-thread.c:817)
DEBUG1 - 21:31:22.412314199 [8383/8529]: [rotation-thread] Checking for pending rotation on session "life", trace archive 0 (in check_session_rotation_pending() at rotation-thread.c:443)
DEBUG1 - 21:31:22.412327945 [8383/8529]: Disabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_stop() at timer.c:245)
DEBUG1 - 21:31:22.412403149 [8383/8529]: Sending consumer trace chunk exists command: relayd_id = -1, session_id = 0, chunk_id = 0 (in consumer_trace_chunk_exists() at consumer.c:2105)
DEBUG1 - 21:31:22.412556218 [8383/8529]: Consumer ret code -126 (in consumer_recv_status_reply() at consumer.c:200)
DEBUG1 - 21:31:22.412581436 [8383/8529]: Consumer reply to TRACE_CHUNK_EXISTS command: trace chunk exists locally (in consumer_trace_chunk_exists() at consumer.c:2128)
DEBUG1 - 21:31:22.412596591 [8383/8529]: [rotation-thread] Rotation of trace archive 0 is still pending for session life (in check_session_rotation_pending() at rotation-thread.c:506)
DEBUG1 - 21:31:22.412610984 [8383/8529]: Enabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_start() at timer.c:213)
DEBUG1 - 21:31:22.412658348 [8383/8529]: [rotation-thread] Entering poll wait (in thread_rotation() at rotation-thread.c:796)
DEBUG1 - 21:31:22.711556521 [8384/8384]: run_as worker received signal SIGINT (in worker_sighandler() at runas.c:1147)
DEBUG1 - 21:31:22.711577590 [8383/8383]: SIGINT caught (in sighandler() at main.c:1105)
DEBUG1 - 21:31:22.711593822 [8383/8383]: Terminating all threads (in stop_threads() at main.c:163)
DEBUG1 - 21:31:22.727238379 [8383/8527]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:545)
DEBUG1 - 21:31:22.727294750 [8383/8527]: [notification-thread] Handling fd (11) activity (1) (in thread_notification() at notification-thread.c:563)
DEBUG1 - 21:31:22.727314689 [8383/8527]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session life (highest usage = 0, lowest usage = 0, total consumed = 6344704) (in handle_notification_thread_channel_sample() at notification-thread-events.c:3261)
DEBUG1 - 21:31:22.727324882 [8383/8527]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:543)
DEBUG1 - 21:31:22.824498965 [8383/8527]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:545)
DEBUG1 - 21:31:22.824539353 [8383/8527]: [notification-thread] Handling fd (17) activity (1) (in thread_notification() at notification-thread.c:563)
DEBUG1 - 21:31:22.824566664 [8383/8527]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session life (highest usage = 0, lowest usage = 0, total consumed = 16384) (in handle_notification_thread_channel_sample() at notification-thread-events.c:3261)
DEBUG1 - 21:31:22.824585766 [8383/8527]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:543)
DEBUG1 - 21:31:22.912855456 [8383/8529]: [rotation-thread] Poll wait returned (1) (in thread_rotation() at rotation-thread.c:798)
DEBUG1 - 21:31:22.912897135 [8383/8529]: [rotation-thread] Handling fd (15) activity (1) (in thread_rotation() at rotation-thread.c:817)
DEBUG1 - 21:31:22.912913225 [8383/8529]: [rotation-thread] Checking for pending rotation on session "life", trace archive 0 (in check_session_rotation_pending() at rotation-thread.c:443)
DEBUG1 - 21:31:22.912927908 [8383/8529]: Disabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_stop() at timer.c:245)
DEBUG1 - 21:31:22.913001589 [8383/8529]: Sending consumer trace chunk exists command: relayd_id = -1, session_id = 0, chunk_id = 0 (in consumer_trace_chunk_exists() at consumer.c:2105)
PERROR - 21:31:22.913028340 [8383/8529]: sendmsg: Broken pipe (in lttcomm_send_unix_sock() at unix.c:282)
DEBUG1 - 21:31:22.913037681 [8383/8529]: Error when sending data to consumer on sock 70 (in consumer_socket_send() at consumer.c:114)
Error: Consumer returned an error from TRACE_CHUNK_EXISTS command
Error: Error occurred while checking rotation status on consumer daemon
DEBUG1 - 21:31:22.913064482 [8383/8529]: [rotation-thread] Rotation of trace archive 0 of session "life" is complete on all consumers (in check_session_rotation_pending_on_consumers() at rotation-thread.c:404)
DEBUG1 - 21:31:22.913086750 [8383/8529]: Tearing down kernel session (in kernel_destroy_session() at kernel.c:1350)
DEBUG1 - 21:31:22.913095664 [8383/8529]: [trace] Closing session fd 72 (in trace_kernel_destroy_session() at trace-kernel.c:709)
DEBUG1 - 21:31:22.913106779 [8383/8529]: [trace] Closing metadata stream fd 88 (in trace_kernel_destroy_session() at trace-kernel.c:719)
DEBUG1 - 21:31:22.913116993 [8383/8529]: [trace] Closing metadata fd 87 (in trace_kernel_destroy_metadata() at trace-kernel.c:682)
DEBUG1 - 21:31:22.913137931 [8383/8529]: [trace] Closing channel fd 79 (in trace_kernel_destroy_channel() at trace-kernel.c:636)
DEBUG1 - 21:31:22.913148885 [8383/8529]: [trace] Closing stream fd 84 (in trace_kernel_destroy_stream() at trace-kernel.c:564)
DEBUG1 - 21:31:22.913161897 [8383/8529]: [trace] Closing stream fd 83 (in trace_kernel_destroy_stream() at trace-kernel.c:564)
DEBUG1 - 21:31:22.913171711 [8383/8529]: [trace] Closing stream fd 82 (in trace_kernel_destroy_stream() at trace-kernel.c:564)
DEBUG1 - 21:31:22.913181556 [8383/8529]: [trace] Closing stream fd 65 (in trace_kernel_destroy_stream() at trace-kernel.c:564)
DEBUG1 - 21:31:22.913191160 [8383/8529]: [trace] Closing event fd 81 (in trace_kernel_destroy_event() at trace-kernel.c:590)
DEBUG1 - 21:31:22.913203736 [8383/8529]: [trace] Closing event fd 80 (in trace_kernel_destroy_event() at trace-kernel.c:590)
DEBUG1 - 21:31:22.943783060 [8383/8529]: Beginning of waiter wait period (in lttng_waiter_wait() at waiter.c:46)
DEBUG1 - 21:31:22.943795993 [8383/8527]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:545)
DEBUG1 - 21:31:22.943900337 [8383/8527]: [notification-thread] Handling fd (34) activity (1) (in thread_notification() at notification-thread.c:563)
DEBUG1 - 21:31:22.943926443 [8383/8527]: [notification-thread] Received remove channel command (in handle_notification_thread_command() at notification-thread-events.c:2309)
DEBUG1 - 21:31:22.943939533 [8383/8527]: [notification-thread] Removing channel key = 1 in kernel domain (in handle_notification_thread_command_remove_channel() at notification-thread-events.c:1653)
DEBUG1 - 21:31:22.944005956 [8383/8527]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:543)
DEBUG1 - 21:31:22.944027080 [8383/8529]: End of waiter wait period (in lttng_waiter_wait() at waiter.c:89)
DEBUG1 - 21:31:22.944048745 [8383/8529]: Destroy all UST traces (in ust_app_destroy_trace_all() at ust-app.c:4924)
DEBUG2 - 21:31:22.944063344 [8383/8529]: Trace UST destroy session 0 (in trace_ust_destroy_session() at trace-ust.c:1332)
DEBUG3 - 21:31:22.944128219 [8383/8529]: Buffer registry per UID destroy with id: 0, ABI: 64, uid: 90709 (in buffer_reg_uid_destroy() at buffer-registry.c:668)
DEBUG3 - 21:31:22.944128549 [8383/8385]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:126)
DEBUG3 - 21:31:22.944248101 [8383/8385]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)
DEBUG3 - 21:31:22.944274612 [8383/8385]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:126)
DEBUG3 - 21:31:22.944349470 [8383/8385]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)
DEBUG3 - 21:31:22.944374938 [8383/8385]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:126)
DEBUG1 - 21:31:22.944382661 [8383/8529]: Destroying session life (id 0) (in session_release() at session.c:885)
DEBUG1 - 21:31:22.944427725 [8383/8529]: Empty ltt_sessions_ht_by_id, destroying it (in del_session_ht() at session.c:391)
DEBUG1 - 21:31:22.944443893 [8383/8529]: No implicit rotation performed during the destruction of session "life", sending reply (in cmd_destroy_session_reply() at cmd.c:3230)
PERROR - 21:31:22.944468961 [8383/8529]: sendmsg: Broken pipe (in lttcomm_send_unix_sock() at unix.c:282)
Error: Failed to send result of the destruction of session "life" to client
DEBUG1 - 21:31:22.944547472 [8383/8536]: Thread kernel return from poll on 3 fds (in thread_kernel_management() at manage-kernel.c:234)
DEBUG1 - 21:31:22.944594706 [8383/8536]: Updating kernel poll set (in update_kernel_poll() at manage-kernel.c:37)
DEBUG3 - 21:31:22.944720005 [8383/8385]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)
DEBUG3 - 21:31:22.944766302 [8383/8385]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:126)
DEBUG3 - 21:31:22.944841240 [8383/8385]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)
DEBUG3 - 21:31:22.944867456 [8383/8385]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:126)
DEBUG3 - 21:31:22.944919250 [8383/8385]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)
DEBUG3 - 21:31:22.944939227 [8383/8385]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:126)
DEBUG3 - 21:31:22.944988656 [8383/8385]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)
DEBUG3 - 21:31:22.945007494 [8383/8385]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:126)
DEBUG1 - 21:31:22.945022865 [8383/8383]: Destruction of all sessions completed (in destroy_all_sessions_and_wait() at main.c:1254)
DEBUG1 - 21:31:22.945052223 [8383/8536]: Thread kernel polling (in thread_kernel_management() at manage-kernel.c:227)
DEBUG3 - 21:31:22.945052588 [8383/8385]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)
DEBUG1 - 21:31:22.945058688 [8383/8383]: Shutting down "UST application registration" thread (in _lttng_thread_shutdown() at thread.c:152)
DEBUG3 - 21:31:22.945107215 [8383/8385]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:126)
DEBUG1 - 21:31:22.945166852 [8383/8532]: Notifying applications of session daemon state: 0 (in notify_ust_apps() at register.c:90)
DEBUG3 - 21:31:22.945178214 [8383/8385]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)
DEBUG3 - 21:31:22.945196235 [8383/8385]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:126)
DEBUG3 - 21:31:22.945239736 [8383/8385]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)
DEBUG1 - 21:31:22.945260243 [8383/8532]: Got the wait shm fd 41 (in get_wait_shm() at shm.c:138)
DEBUG1 - 21:31:22.945323168 [8383/8532]: Futex wait update active 0 (in futex_wait_update() at futex.c:55)
DEBUG1 - 21:31:22.945031525 [8383/8529]: [rotation-thread] Entering poll wait (in thread_rotation() at rotation-thread.c:796)
DEBUG1 - 21:31:22.945407182 [8383/8532]: UST Registration thread cleanup complete (in thread_application_registration() at register.c:362)
DEBUG1 - 21:31:22.945420714 [8383/8532]: Thread "UST application registration" has returned (in launch_thread() at thread.c:66)
DEBUG1 - 21:31:22.945509664 [8383/8383]: Shutting down "Consumer management" thread (in _lttng_thread_shutdown() at thread.c:152)
DEBUG1 - 21:31:22.945641123 [8383/8591]: consumer thread cleanup completed (in thread_consumer_management() at manage-consumer.c:410)
DEBUG1 - 21:31:22.945663038 [8383/8591]: Thread "Consumer management" has returned (in launch_thread() at thread.c:66)
DEBUG1 - 21:31:22.945744697 [8383/8383]: Shutting down "Consumer management" thread (in _lttng_thread_shutdown() at thread.c:152)
DEBUG1 - 21:31:22.945861271 [8383/8578]: consumer thread cleanup completed (in thread_consumer_management() at manage-consumer.c:410)
DEBUG1 - 21:31:22.945894703 [8383/8578]: Thread "Consumer management" has returned (in launch_thread() at thread.c:66)
DEBUG1 - 21:31:22.945975891 [8383/8383]: Shutting down "Kernel management" thread (in _lttng_thread_shutdown() at thread.c:152)
DEBUG1 - 21:31:22.946014535 [8383/8536]: Thread kernel return from poll on 2 fds (in thread_kernel_management() at manage-kernel.c:234)
DEBUG1 - 21:31:22.946049420 [8383/8536]: Kernel thread dying (in thread_kernel_management() at manage-kernel.c:309)
DEBUG1 - 21:31:22.946062215 [8383/8536]: Thread "Kernel management" has returned (in launch_thread() at thread.c:66)
DEBUG1 - 21:31:22.946170991 [8383/8383]: Shutting down "Agent management" thread (in _lttng_thread_shutdown() at thread.c:152)
DEBUG3 - 21:31:22.946217654 [8383/8535]: [agent-thread] Manage agent return from poll on 2 fds (in thread_agent_management() at agent-thread.c:379)
DEBUG3 - 21:31:22.946245167 [8383/8535]: [agent-thread] 1 fd ready (in thread_agent_management() at agent-thread.c:390)
DEBUG3 - 21:31:22.946259085 [8383/8535]: [agent-thread] Destroy TCP socket on port 5345 (in destroy_tcp_socket() at agent-thread.c:184)
DEBUG1 - 21:31:22.946283541 [8383/8535]: [agent-thread] Cleaning up and stopping. (in thread_agent_management() at agent-thread.c:462)
DEBUG1 - 21:31:22.946293895 [8383/8535]: Thread "Agent management" has returned (in launch_thread() at thread.c:66)
DEBUG1 - 21:31:22.946380340 [8383/8383]: Shutting down "Application notification" thread (in _lttng_thread_shutdown() at thread.c:152)
DEBUG3 - 21:31:22.946425494 [8383/8534]: [ust-thread] Manage notify return from poll on 2 fds (in thread_application_notification() at notify-apps.c:81)
DEBUG1 - 21:31:22.946464664 [8383/8534]: Application notify communication apps thread cleanup complete (in thread_application_notification() at notify-apps.c:183)
DEBUG1 - 21:31:22.946481127 [8383/8534]: Thread "Application notification" has returned (in launch_thread() at thread.c:66)
DEBUG1 - 21:31:22.946565663 [8383/8383]: Shutting down "UST application management" thread (in _lttng_thread_shutdown() at thread.c:152)
DEBUG1 - 21:31:22.946603746 [8383/8533]: Apps thread return from poll on 2 fds (in thread_application_management() at manage-apps.c:95)
DEBUG1 - 21:31:22.946637854 [8383/8533]: Application communication apps thread cleanup complete (in thread_application_management() at manage-apps.c:194)
DEBUG1 - 21:31:22.946652458 [8383/8533]: Thread "UST application management" has returned (in launch_thread() at thread.c:66)
DEBUG1 - 21:31:22.946728313 [8383/8383]: Shutting down "UST registration dispatch" thread (in _lttng_thread_shutdown() at thread.c:152)
DEBUG1 - 21:31:22.946749743 [8383/8383]: Futex n to 1 wake done (in futex_nto1_wake() at futex.c:112)
DEBUG1 - 21:31:22.946760152 [8383/8531]: Futex n to 1 wait done (in futex_nto1_wait() at futex.c:95)
DEBUG1 - 21:31:22.946778274 [8383/8531]: Futex n to 1 prepare done (in futex_nto1_prepare() at futex.c:67)
DEBUG1 - 21:31:22.946788592 [8383/8531]: Dispatch thread dying (in thread_dispatch_ust_registration() at dispatch.c:478)
DEBUG1 - 21:31:22.946798195 [8383/8531]: Thread "UST registration dispatch" has returned (in launch_thread() at thread.c:66)
DEBUG1 - 21:31:22.946877954 [8383/8383]: Shutting down "Rotation" thread (in _lttng_thread_shutdown() at thread.c:152)
DEBUG1 - 21:31:22.946924331 [8383/8529]: [rotation-thread] Poll wait returned (1) (in thread_rotation() at rotation-thread.c:798)
DEBUG1 - 21:31:22.946944548 [8383/8529]: [rotation-thread] Handling fd (38) activity (1) (in thread_rotation() at rotation-thread.c:817)
DEBUG1 - 21:31:22.946960038 [8383/8529]: [rotation-thread] Quit pipe activity (in thread_rotation() at rotation-thread.c:856)
DEBUG1 - 21:31:22.946972387 [8383/8529]: [rotation-thread] Exit (in thread_rotation() at rotation-thread.c:864)
DEBUG1 - 21:31:22.947026582 [8383/8529]: Thread "Rotation" has returned (in launch_thread() at thread.c:66)
DEBUG1 - 21:31:22.947030291 [8383/8527]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:545)
DEBUG1 - 21:31:22.947071486 [8383/8527]: [notification-thread] Handling fd (47) activity (8209) (in thread_notification() at notification-thread.c:563)
DEBUG1 - 21:31:22.947087493 [8383/8527]: [notification-thread] Closing client connection (socket fd = 47) (in handle_notification_thread_client_disconnect() at notification-thread-events.c:2487)
DEBUG1 - 21:31:22.947117933 [8383/8527]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:543)
DEBUG1 - 21:31:22.947138736 [8383/8383]: Shutting down "Timer" thread (in _lttng_thread_shutdown() at thread.c:152)
DEBUG1 - 21:31:22.947243508 [8383/8528]: [timer-thread] Exit (in thread_timer() at timer.c:402)
DEBUG1 - 21:31:22.947278840 [8383/8528]: Thread "Timer" has returned (in launch_thread() at thread.c:66)
DEBUG1 - 21:31:22.947395474 [8383/8383]: Shutting down "Health management" thread (in _lttng_thread_shutdown() at thread.c:152)
DEBUG1 - 21:31:22.947466047 [8383/8526]: Health check thread dying (in thread_manage_health() at health.c:231)
DEBUG1 - 21:31:22.947545746 [8383/8526]: Thread "Health management" has returned (in launch_thread() at thread.c:66)
DEBUG2 - 21:31:22.954105269 [8383/8587]: Trace destroy UST event * (in trace_ust_destroy_event() at trace-ust.c:1175)
DEBUG2 - 21:31:22.954129273 [8383/8587]: Trace destroy UST channel channel0 (in _trace_ust_destroy_channel() at trace-ust.c:1240)
DEBUG3 - 21:31:22.954141910 [8383/8587]: Buffer registry session destroy (in buffer_reg_session_destroy() at buffer-registry.c:587)
DEBUG3 - 21:31:22.954155794 [8383/8587]: Buffer registry channel destroy with key 0 (in buffer_reg_channel_destroy() at buffer-registry.c:542)
DEBUG3 - 21:31:22.954166519 [8383/8587]: Buffer registry stream destroy with handle -1 (in buffer_reg_stream_destroy() at buffer-registry.c:490)
DEBUG3 - 21:31:22.954183514 [8383/8587]: Buffer registry stream destroy with handle -1 (in buffer_reg_stream_destroy() at buffer-registry.c:490)
DEBUG3 - 21:31:22.954197646 [8383/8587]: Buffer registry stream destroy with handle -1 (in buffer_reg_stream_destroy() at buffer-registry.c:490)
DEBUG3 - 21:31:22.954211855 [8383/8587]: Buffer registry stream destroy with handle -1 (in buffer_reg_stream_destroy() at buffer-registry.c:490)
DEBUG1 - 21:31:22.954267760 [8383/8587]: Beginning of waiter wait period (in lttng_waiter_wait() at waiter.c:46)
DEBUG1 - 21:31:22.954363272 [8383/8527]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:545)
DEBUG1 - 21:31:22.954375646 [8383/8527]: [notification-thread] Handling fd (34) activity (1) (in thread_notification() at notification-thread.c:563)
DEBUG3 - 21:31:22.954380344 [8383/8385]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:126)
DEBUG1 - 21:31:22.954389217 [8383/8527]: [notification-thread] Received remove channel command (in handle_notification_thread_command() at notification-thread-events.c:2309)
DEBUG1 - 21:31:22.954396794 [8383/8527]: [notification-thread] Removing channel key = 1 in user space domain (in handle_notification_thread_command_remove_channel() at notification-thread-events.c:1653)
DEBUG3 - 21:31:22.954479330 [8383/8385]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)
DEBUG1 - 21:31:22.954518608 [8383/8527]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:543)
DEBUG1 - 21:31:22.954522236 [8383/8587]: End of waiter wait period (in lttng_waiter_wait() at waiter.c:89)
DEBUG3 - 21:31:22.954583872 [8383/8385]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:126)
DEBUG1 - 21:31:22.954601880 [8383/8383]: Cleanup sessiond (in sessiond_cleanup() at main.c:268)
DEBUG3 - 21:31:22.954642768 [8383/8385]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)
DEBUG3 - 21:31:22.954654229 [8383/8385]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:126)
DEBUG1 - 21:31:22.954667179 [8383/8383]: Removing sessiond and consumerd content of directory /var/run/lttng (in sessiond_cleanup() at main.c:285)
DEBUG1 - 21:31:22.954676242 [8383/8383]: Removing /var/run/lttng/lttng-sessiond.pid (in sessiond_cleanup() at main.c:288)
DEBUG1 - 21:31:22.954688115 [8383/8383]: Removing /var/run/lttng/agent.port (in sessiond_cleanup() at main.c:291)
DEBUG3 - 21:31:22.954698990 [8383/8385]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)
DEBUG1 - 21:31:22.954704236 [8383/8383]: Removing /var/run/lttng/kconsumerd/error (in sessiond_cleanup() at main.c:295)
DEBUG1 - 21:31:22.954729170 [8383/8383]: Removing directory /var/run/lttng/kconsumerd (in sessiond_cleanup() at main.c:298)
DEBUG1 - 21:31:22.954739664 [8383/8383]: Removing /var/run/lttng/ustconsumerd32/error (in sessiond_cleanup() at main.c:302)
DEBUG1 - 21:31:22.954748028 [8383/8383]: Removing directory /var/run/lttng/ustconsumerd32 (in sessiond_cleanup() at main.c:305)
DEBUG1 - 21:31:22.954755638 [8383/8383]: Removing /var/run/lttng/ustconsumerd64/error (in sessiond_cleanup() at main.c:309)
DEBUG1 - 21:31:22.954763599 [8383/8383]: Removing directory /var/run/lttng/ustconsumerd64 (in sessiond_cleanup() at main.c:312)
DEBUG1 - 21:31:22.954771067 [8383/8383]: Cleaning up all agent apps (in sessiond_cleanup() at main.c:317)
DEBUG1 - 21:31:22.954794410 [8383/8383]: Closing all UST sockets (in sessiond_cleanup() at main.c:319)
DEBUG2 - 21:31:22.954800435 [8383/8383]: UST app cleaning registered apps hash table (in ust_app_clean_list() at ust-app.c:3849)
DEBUG3 - 21:31:22.954815068 [8383/8385]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:126)
DEBUG3 - 21:31:22.954815206 [8383/8383]: Buffer registry destroy all registry (in buffer_reg_destroy_registries() at buffer-registry.c:743)
DEBUG3 - 21:31:22.954850871 [8383/8385]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)
DEBUG1 - 21:31:22.954862317 [8383/8383]: Waiting for complete teardown of consumerd (PID: 8590) (in wait_consumer() at main.c:249)
DEBUG3 - 21:31:22.954862525 [8383/8385]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:126)
DEBUG3 - 21:31:22.954900550 [8383/8385]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)
DEBUG3 - 21:31:22.954906987 [8383/8385]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:126)
DEBUG3 - 21:31:22.954928210 [8383/8385]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)
DEBUG3 - 21:31:22.954934328 [8383/8385]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:126)
DEBUG3 - 21:31:22.954953655 [8383/8385]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)
DEBUG3 - 21:31:22.954959694 [8383/8385]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:126)
DEBUG3 - 21:31:22.954979194 [8383/8385]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)
DEBUG3 - 21:31:22.964666147 [8383/8385]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:126)
DEBUG3 - 21:31:22.964735768 [8383/8385]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)
DEBUG1 - 21:31:22.975514323 [8383/8383]: Waiting for complete teardown of consumerd (PID: 8577) (in wait_consumer() at main.c:249)
DEBUG1 - 21:31:22.976495478 [8384/8384]: run_as worker received signal SIGINT (in worker_sighandler() at runas.c:1147)
DEBUG1 - 21:31:22.976503043 [8383/8383]: SIGINT caught (in sighandler() at main.c:1105)
DEBUG1 - 21:31:22.976512555 [8383/8383]: Terminating all threads (in stop_threads() at main.c:163)
PERROR - 21:31:22.976521371 [8383/8383]: write poll pipe: Bad file descriptor (in notify_thread_pipe() at utils.c:35)
Error: write error on thread quit pipe
PERROR - 21:31:22.976529470 [8383/8383]: consumerd waitpid pid: 8577: Interrupted system call (in wait_consumer() at main.c:252)
DEBUG2 - 21:31:22.976534803 [8383/8383]: Closing kernel fd (in cleanup_kernel_tracer() at kernel.c:1784)
DEBUG1 - 21:31:22.976540117 [8383/8383]: Unloading kernel modules (in cleanup_kernel_tracer() at kernel.c:1792)
DEBUG1 - 21:31:22.987808070 [8383/8527]: [notification-thread] Poll wait returned (3) (in thread_notification() at notification-thread.c:545)
DEBUG1 - 21:31:22.987841715 [8383/8527]: [notification-thread] Handling fd (17) activity (16) (in thread_notification() at notification-thread.c:563)
DEBUG1 - 21:31:22.987853380 [8383/8527]: [notification-thread] Handling fd (13) activity (16) (in thread_notification() at notification-thread.c:563)
DEBUG1 - 21:31:22.987860281 [8383/8527]: [notification-thread] Handling fd (11) activity (16) (in thread_notification() at notification-thread.c:563)
DEBUG1 - 21:31:22.987867877 [8383/8527]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:543)
DEBUG1 - 21:31:23.000153156 [8383/8383]: Modprobe removal successful lttng-probe-writeback (in modprobe_remove_lttng() at modprobe.c:373)
DEBUG1 - 21:31:23.024068565 [8383/8383]: Modprobe removal successful lttng-probe-workqueue (in modprobe_remove_lttng() at modprobe.c:373)
DEBUG1 - 21:31:23.064466366 [8383/8383]: Modprobe removal successful lttng-probe-v4l2 (in modprobe_remove_lttng() at modprobe.c:373)
DEBUG1 - 21:31:23.092339214 [8383/8383]: Modprobe removal successful lttng-probe-vmscan (in modprobe_remove_lttng() at modprobe.c:373)
DEBUG1 - 21:31:23.124212932 [8383/8383]: Modprobe removal successful lttng-probe-udp (in modprobe_remove_lttng() at modprobe.c:373)
DEBUG1 - 21:31:23.152233190 [8383/8383]: Modprobe removal successful lttng-probe-timer (in modprobe_remove_lttng() at modprobe.c:373)
DEBUG1 - 21:31:23.172128690 [8383/8383]: Modprobe removal successful lttng-probe-sunrpc (in modprobe_remove_lttng() at modprobe.c:373)
DEBUG1 - 21:31:23.196157323 [8383/8383]: Modprobe removal successful lttng-probe-statedump (in modprobe_remove_lttng() at modprobe.c:373)
DEBUG1 - 21:31:23.228349772 [8383/8383]: Modprobe removal successful lttng-probe-sock (in modprobe_remove_lttng() at modprobe.c:373)
DEBUG1 - 21:31:23.247914536 [8383/8383]: Modprobe removal successful lttng-probe-skb (in modprobe_remove_lttng() at modprobe.c:373)
DEBUG1 - 21:31:23.268076322 [8383/8383]: Modprobe removal successful lttng-probe-signal (in modprobe_remove_lttng() at modprobe.c:373)
DEBUG1 - 21:31:23.296219921 [8383/8383]: Modprobe removal successful lttng-probe-scsi (in modprobe_remove_lttng() at modprobe.c:373)
DEBUG1 - 21:31:23.320177558 [8383/8383]: Modprobe removal successful lttng-probe-sched (in modprobe_remove_lttng() at modprobe.c:373)
DEBUG1 - 21:31:23.339598832 [8383/8383]: Modprobe removal successful lttng-probe-regulator (in modprobe_remove_lttng() at modprobe.c:373)
DEBUG1 - 21:31:23.355940116 [8383/8383]: Modprobe removal successful lttng-probe-rcu (in modprobe_remove_lttng() at modprobe.c:373)
DEBUG1 - 21:31:23.392370739 [8383/8383]: Modprobe removal successful lttng-probe-random (in modprobe_remove_lttng() at modprobe.c:373)
DEBUG1 - 21:31:23.428103921 [8383/8383]: Modprobe removal successful lttng-probe-printk (in modprobe_remove_lttng() at modprobe.c:373)
DEBUG1 - 21:31:23.460364019 [8383/8383]: Modprobe removal successful lttng-probe-power (in modprobe_remove_lttng() at modprobe.c:373)
DEBUG1 - 21:31:23.484048763 [8383/8383]: Modprobe removal successful lttng-probe-net (in modprobe_remove_lttng() at modprobe.c:373)
DEBUG1 - 21:31:23.520321941 [8383/8383]: Modprobe removal successful lttng-probe-napi (in modprobe_remove_lttng() at modprobe.c:373)
DEBUG1 - 21:31:23.560161737 [8383/8383]: Modprobe removal successful lttng-probe-module (in modprobe_remove_lttng() at modprobe.c:373)
DEBUG1 - 21:31:23.584462209 [8383/8383]: Modprobe removal successful lttng-probe-kvm (in modprobe_remove_lttng() at modprobe.c:373)
DEBUG1 - 21:31:23.604115214 [8383/8383]: Modprobe removal successful lttng-probe-kmem (in modprobe_remove_lttng() at modprobe.c:373)
DEBUG1 - 21:31:23.640207357 [8383/8383]: Modprobe removal successful lttng-probe-jbd2 (in modprobe_remove_lttng() at modprobe.c:373)
DEBUG1 - 21:31:23.668181311 [8383/8383]: Modprobe removal successful lttng-probe-irq (in modprobe_remove_lttng() at modprobe.c:373)
DEBUG1 - 21:31:23.700215569 [8383/8383]: Modprobe removal successful lttng-probe-i2c (in modprobe_remove_lttng() at modprobe.c:373)
DEBUG1 - 21:31:23.724053285 [8383/8383]: Modprobe removal successful lttng-probe-gpio (in modprobe_remove_lttng() at modprobe.c:373)
DEBUG1 - 21:31:23.756410122 [8383/8383]: Modprobe removal successful lttng-probe-compaction (in modprobe_remove_lttng() at modprobe.c:373)
DEBUG1 - 21:31:23.784098387 [8383/8383]: Modprobe removal successful lttng-probe-block (in modprobe_remove_lttng() at modprobe.c:373)
DEBUG1 - 21:31:23.812281497 [8383/8383]: Modprobe removal successful lttng-probe-asoc (in modprobe_remove_lttng() at modprobe.c:373)
DEBUG1 - 21:31:23.852174592 [8383/8383]: Modprobe removal successful lttng-ring-buffer-metadata-mmap-client (in modprobe_remove_lttng() at modprobe.c:373)
DEBUG1 - 21:31:23.879880891 [8383/8383]: Modprobe removal successful lttng-ring-buffer-client-mmap-overwrite (in modprobe_remove_lttng() at modprobe.c:373)
DEBUG1 - 21:31:23.912210507 [8383/8383]: Modprobe removal successful lttng-ring-buffer-client-mmap-discard (in modprobe_remove_lttng() at modprobe.c:373)
DEBUG1 - 21:31:23.948198483 [8383/8383]: Modprobe removal successful lttng-ring-buffer-metadata-client (in modprobe_remove_lttng() at modprobe.c:373)
DEBUG1 - 21:31:23.980406777 [8383/8383]: Modprobe removal successful lttng-ring-buffer-client-overwrite (in modprobe_remove_lttng() at modprobe.c:373)
DEBUG1 - 21:31:24.171993519 [8383/8383]: Modprobe removal successful lttng-ring-buffer-client-discard (in modprobe_remove_lttng() at modprobe.c:373)
DEBUG1 - 21:31:24.172082892 [8383/8383]: Shutting down "Notification" thread (in _lttng_thread_shutdown() at thread.c:152)
DEBUG1 - 21:31:24.172103125 [8383/8383]: Beginning of waiter wait period (in lttng_waiter_wait() at waiter.c:46)
DEBUG1 - 21:31:24.172129907 [8383/8527]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:545)
DEBUG1 - 21:31:24.172164320 [8383/8527]: [notification-thread] Handling fd (34) activity (1) (in thread_notification() at notification-thread.c:563)
DEBUG1 - 21:31:24.172183170 [8383/8527]: [notification-thread] Received quit command (in handle_notification_thread_command() at notification-thread-events.c:2331)
DEBUG1 - 21:31:24.172200965 [8383/8527]: [notification-thread] Closing all client connections (in handle_notification_thread_client_disconnect_all() at notification-thread-events.c:2517)
DEBUG1 - 21:31:24.172230570 [8383/8383]: End of waiter wait period (in lttng_waiter_wait() at waiter.c:89)
DEBUG1 - 21:31:24.172472308 [8383/8527]: [notification-thread] Destroying notification channel socket (in notification_channel_socket_destroy() at notification-thread.c:192)
DEBUG1 - 21:31:24.172545280 [8383/8527]: Thread "Notification" has returned (in launch_thread() at thread.c:66)
DEBUG1 - 21:31:24.182854657 [8383/8383]: Shutting down "HT cleanup" thread (in _lttng_thread_shutdown() at thread.c:152)
DEBUG3 - 21:31:24.182954989 [8383/8385]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:126)
DEBUG1 - 21:31:24.183000213 [8383/8385]: [ht-cleanup] quit. (in thread_ht_cleanup() at ht-cleanup.c:206)
DEBUG1 - 21:31:24.183030010 [8383/8385]: [ht-cleanup] Thread terminates. (in thread_ht_cleanup() at ht-cleanup.c:217)
DEBUG1 - 21:31:24.183042162 [8383/8385]: Thread "HT cleanup" has returned (in launch_thread() at thread.c:66)
DEBUG1 - 21:31:24.183320417 [8383/8383]: Cleaning up options (in sessiond_cleanup_options() at main.c:345)
DEBUG1 - 21:31:24.183360018 [8383/8383]: Destroying run_as worker (in run_as_destroy_worker_no_lock() at runas.c:1313)
DEBUG1 - 21:31:24.183370014 [8383/8383]: Closing run_as worker socket (in run_as_destroy_worker_no_lock() at runas.c:1318)
DEBUG1 - 21:31:24.183429181 [8384/8384]: run_as worker exiting (ret = 0) (in run_as_create_worker_no_lock() at runas.c:1263)
DEBUG1 - 21:31:24.184271954 [8383/8383]: lttng-runas terminated with status code 0 (in run_as_destroy_worker_no_lock() at runas.c:1340)
(5-5/7)