* [lttng-dev] Using lttng 2.11 and UST doesn't appear to work - getting empty trace files
@ 2023-04-24 13:48 Brian Hutchinson via lttng-dev
0 siblings, 0 replies; 4+ messages in thread
From: Brian Hutchinson via lttng-dev @ 2023-04-24 13:48 UTC (permalink / raw)
To: lttng-dev
[-- Attachment #1.1: Type: text/plain, Size: 3504 bytes --]
Hi,
I'm on an embedded platform, i.MX8 using Lttng 2.11 with 5.6.69 kernel.
Tracing kernel events with lttng works fine but userspace (tracef and trace
provider type tracing) appears to have an issue I can't figure out.
systemd is starting up my application ( a bunch of processes and threads on
multiple cpu's) on boot.
I'm statically compiling and linking in lttng-ust. If I use just tracef
type tracing, when I do lttng list --userspace I get nothing. If I add in
a trace provider and a tracepoint, then I see my trace provider tracepoint
and:
lttng_ust_tracelog:TRACE_DEBUG (loglevel: TRACE_DEBUG (14)) (type:
tracepoint)
lttng_ust_tracelog:TRACE_DEBUG_LINE (loglevel: TRACE_DEBUG_LINE (13))
(type: tracepoint)
lttng_ust_tracelog:TRACE_DEBUG_FUNCTION (loglevel:
TRACE_DEBUG_FUNCTION (12)) (type: tracepoint)
lttng_ust_tracelog:TRACE_DEBUG_UNIT (loglevel: TRACE_DEBUG_UNIT (11))
(type: tracepoint)
lttng_ust_tracelog:TRACE_DEBUG_MODULE (loglevel: TRACE_DEBUG_MODULE
(10)) (type: tracepoint)
lttng_ust_tracelog:TRACE_DEBUG_PROCESS (loglevel: TRACE_DEBUG_PROCESS
(9)) (type: tracepoint)
lttng_ust_tracelog:TRACE_DEBUG_PROGRAM (loglevel: TRACE_DEBUG_PROGRAM
(8)) (type: tracepoint)
lttng_ust_tracelog:TRACE_DEBUG_SYSTEM (loglevel: TRACE_DEBUG_SYSTEM
(7)) (type: tracepoint)
lttng_ust_tracelog:TRACE_INFO (loglevel: TRACE_INFO (6)) (type:
tracepoint)
lttng_ust_tracelog:TRACE_NOTICE (loglevel: TRACE_NOTICE (5)) (type:
tracepoint)
lttng_ust_tracelog:TRACE_WARNING (loglevel: TRACE_WARNING (4)) (type:
tracepoint)
lttng_ust_tracelog:TRACE_ERR (loglevel: TRACE_ERR (3)) (type:
tracepoint)
lttng_ust_tracelog:TRACE_CRIT (loglevel: TRACE_CRIT (2)) (type:
tracepoint)
lttng_ust_tracelog:TRACE_ALERT (loglevel: TRACE_ALERT (1)) (type:
tracepoint)
lttng_ust_tracelog:TRACE_EMERG (loglevel: TRACE_EMERG (0)) (type:
tracepoint)
lttng_ust_tracef:event (loglevel: TRACE_DEBUG (14)) (type: tracepoint)
lttng_ust_lib:unload (loglevel: TRACE_DEBUG_LINE (13)) (type:
tracepoint)
lttng_ust_lib:debug_link (loglevel: TRACE_DEBUG_LINE (13)) (type:
tracepoint)
lttng_ust_lib:build_id (loglevel: TRACE_DEBUG_LINE (13)) (type:
tracepoint)
lttng_ust_lib:load (loglevel: TRACE_DEBUG_LINE (13)) (type:
tracepoint)
lttng_ust_statedump:end (loglevel: TRACE_DEBUG_LINE (13)) (type:
tracepoint)
lttng_ust_statedump:debug_link (loglevel: TRACE_DEBUG_LINE (13))
(type: tracepoint)
lttng_ust_statedump:build_id (loglevel: TRACE_DEBUG_LINE (13)) (type:
tracepoint)
lttng_ust_statedump:bin_info (loglevel: TRACE_DEBUG_LINE (13)) (type:
tracepoint)
lttng_ust_statedump:start (loglevel: TRACE_DEBUG_LINE (13)) (type:
tracepoint)
When I do lttng start, I get a directory structure in the trace directory
but the file sizes do not ever increase. It's just a directory structure
with files created and then that's it, no events being written to the
files. At first I thought things just weren't linked in right and not
working but then discovered how to run lttng-sessiond in -vvv mode and then
could see lots of things are going on, tracing appears to be trying to work
as there is tons of activity being output by lttng-sessiond, but like I
said the trace files aren't being added to.
I looked at the lttng-sessiond log I captured and can't quite make out the
problem so attaching it.
I'm probably not doing something right but can't figure out what that is so
any pointers appreciated.
Regards,
Brian
[-- Attachment #1.2: Type: text/html, Size: 4701 bytes --]
[-- Attachment #2: lttng-sessiond.log --]
[-- Type: text/x-log, Size: 170812 bytes --]
DEBUG1 - 10:52:39.603957375 [9674/9674]: [sessiond configuration]
DEBUG1 - 10:52:39.604306875 [9674/9674]: verbose: 3
DEBUG1 - 10:52:39.604353125 [9674/9674]: verbose consumer: 0
DEBUG1 - 10:52:39.604385875 [9674/9674]: quiet mode: False
DEBUG1 - 10:52:39.604417125 [9674/9674]: agent_tcp_port: [5345, 5354]
DEBUG1 - 10:52:39.604448875 [9674/9674]: application socket timeout: 5
DEBUG1 - 10:52:39.604480125 [9674/9674]: no-kernel: False
DEBUG1 - 10:52:39.604511750 [9674/9674]: background: False
DEBUG1 - 10:52:39.604544125 [9674/9674]: daemonize: False
DEBUG1 - 10:52:39.604576875 [9674/9674]: signal parent on start: False
DEBUG1 - 10:52:39.604607000 [9674/9674]: tracing group name: tracing
DEBUG1 - 10:52:39.604639000 [9674/9674]: kmod_probe_list: None
DEBUG1 - 10:52:39.604670750 [9674/9674]: kmod_extra_probe_list: None
DEBUG1 - 10:52:39.604703625 [9674/9674]: rundir: /var/run/lttng
DEBUG1 - 10:52:39.604731875 [9674/9674]: application socket path: /var/run/lttng/lttng-ust-sock-8
DEBUG1 - 10:52:39.604763500 [9674/9674]: client socket path: /var/run/lttng/client-lttng-sessiond
DEBUG1 - 10:52:39.604800250 [9674/9674]: wait shm path: /lttng-ust-wait-8
DEBUG1 - 10:52:39.604833750 [9674/9674]: health socket path: /var/run/lttng/sessiond-health
DEBUG1 - 10:52:39.604865500 [9674/9674]: LTTNG_UST_CLOCK_PLUGIN: None
DEBUG1 - 10:52:39.604896250 [9674/9674]: pid file path: /var/run/lttng/lttng-sessiond.pid
DEBUG1 - 10:52:39.604929500 [9674/9674]: lock file path: /var/run/lttng/lttng-sessiond.lck
DEBUG1 - 10:52:39.604960750 [9674/9674]: session load path: None
DEBUG1 - 10:52:39.604994500 [9674/9674]: agent port file path: /var/run/lttng/agent.port
DEBUG1 - 10:52:39.605024250 [9674/9674]: consumerd32 path: /var/run/lttng/ustconsumerd32
DEBUG1 - 10:52:39.605053750 [9674/9674]: consumerd32 bin path: Unknown
DEBUG1 - 10:52:39.605084250 [9674/9674]: consumerd32 lib dir: Unknown
DEBUG1 - 10:52:39.605138875 [9674/9674]: consumerd32 err unix sock path:/var/run/lttng/ustconsumerd32/error
DEBUG1 - 10:52:39.605182125 [9674/9674]: consumerd32 cmd unix sock path:/var/run/lttng/ustconsumerd32/command
DEBUG1 - 10:52:39.605214875 [9674/9674]: consumerd64 path: /var/run/lttng/ustconsumerd64
DEBUG1 - 10:52:39.605250625 [9674/9674]: consumerd64 bin path: /usr/lib/lttng/libexec/lttng-consumerd
DEBUG1 - 10:52:39.605281000 [9674/9674]: consumerd64 lib dir: /usr/lib
DEBUG1 - 10:52:39.605313000 [9674/9674]: consumerd64 err unix sock path:/var/run/lttng/ustconsumerd64/error
DEBUG1 - 10:52:39.605343250 [9674/9674]: consumerd64 cmd unix sock path:/var/run/lttng/ustconsumerd64/command
DEBUG1 - 10:52:39.605377125 [9674/9674]: kconsumerd path: /var/run/lttng/kconsumerd
DEBUG1 - 10:52:39.605408625 [9674/9674]: kconsumerd err unix sock path: /var/run/lttng/kconsumerd/error
DEBUG1 - 10:52:39.605438500 [9674/9674]: kconsumerd cmd unix sock path: /var/run/lttng/kconsumerd/command
DEBUG1 - 10:52:39.605475375 [9674/9674]: Starting lttng-sessiond {7ceef295-4348-4998-86c7-4b637bd0d947} (in sessiond_uuid_log() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/main.c:1288)
DEBUG3 - 10:52:39.605509500 [9674/9674]: Creating LTTng run directory: /var/run/lttng (in create_lttng_rundir() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/main.c:1001)
DEBUG1 - 10:52:39.608292500 [9675/9675]: Resetting run_as worker signal handlers to default (in reset_sighandler() at ../../../lttng-tools-2.11.5/src/common/runas.c:1084)
DEBUG1 - 10:52:39.608822875 [9675/9675]: run_as signal handler set for SIGTERM and SIGINT (in set_worker_sighandlers() at ../../../lttng-tools-2.11.5/src/common/runas.c:1145)
DEBUG1 - 10:52:39.614801750 [9674/9674]: Health check time delta in seconds set to 20 (in health_init() at ../../../../lttng-tools-2.11.5/src/common/health/health.c:72)
DEBUG3 - 10:52:39.616609875 [9674/9674]: Created hashtable size 4 at 0xaaaafaa98360 of type 1 (in lttng_ht_new() at ../../../../lttng-tools-2.11.5/src/common/hashtable/hashtable.c:145)
DEBUG3 - 10:52:39.616712625 [9674/9674]: Created hashtable size 4 at 0xaaaafaa987a0 of type 1 (in lttng_ht_new() at ../../../../lttng-tools-2.11.5/src/common/hashtable/hashtable.c:145)
DEBUG3 - 10:52:39.616749750 [9674/9674]: Created hashtable size 4 at 0xaaaafaa98be0 of type 1 (in lttng_ht_new() at ../../../../lttng-tools-2.11.5/src/common/hashtable/hashtable.c:145)
DEBUG3 - 10:52:39.616800000 [9674/9674]: Created hashtable size 4 at 0xaaaafaa99020 of type 1 (in lttng_ht_new() at ../../../../lttng-tools-2.11.5/src/common/hashtable/hashtable.c:145)
DEBUG2 - 10:52:39.616834375 [9674/9674]: Creating consumer directory: /var/run/lttng/kconsumerd (in set_consumer_sockets() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/main.c:1043)
DEBUG1 - 10:52:39.625261375 [9674/9676]: Launching "HT cleanup" thread (in launch_thread() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/thread.c:74)
DEBUG1 - 10:52:39.625427250 [9674/9676]: [ht-thread] startup. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:108)
DEBUG1 - 10:52:39.625616625 [9674/9676]: epoll set max size is 405504 (in compat_epoll_set_max_size() at ../../../../lttng-tools-2.11.5/src/common/compat/compat-epoll.c:356)
DEBUG3 - 10:52:39.625888625 [9674/9676]: [ht-thread] Polling. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:132)
DEBUG1 - 10:52:39.632641375 [9674/9674]: Modprobe successfully lttng-ring-buffer-client-discard (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:347)
DEBUG1 - 10:52:39.645432375 [9674/9674]: Modprobe successfully lttng-ring-buffer-client-overwrite (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:347)
DEBUG1 - 10:52:39.657929750 [9674/9674]: Modprobe successfully lttng-ring-buffer-metadata-client (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:347)
DEBUG1 - 10:52:39.670383000 [9674/9674]: Modprobe successfully lttng-ring-buffer-client-mmap-discard (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:347)
DEBUG1 - 10:52:39.685496625 [9674/9674]: Modprobe successfully lttng-ring-buffer-client-mmap-overwrite (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:347)
DEBUG1 - 10:52:39.697801125 [9674/9674]: Modprobe successfully lttng-ring-buffer-metadata-mmap-client (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:347)
DEBUG2 - 10:52:39.697963750 [9674/9674]: Kernel tracer version validated (2.11, ABI 2.4) (in kernel_validate_version() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/kernel.c:1142)
DEBUG1 - 10:52:39.710457875 [9674/9674]: Modprobe successfully lttng-probe-asoc (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:347)
DEBUG1 - 10:52:39.722895375 [9674/9674]: Modprobe successfully lttng-probe-block (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:347)
DEBUG1 - 10:52:39.735599375 [9674/9674]: Unable to load optional module lttng-probe-btrfs; continuing (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:342)
DEBUG1 - 10:52:39.747955625 [9674/9674]: Modprobe successfully lttng-probe-compaction (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:347)
DEBUG1 - 10:52:39.760349125 [9674/9674]: Unable to load optional module lttng-probe-ext3; continuing (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:342)
DEBUG1 - 10:52:39.772897125 [9674/9674]: Modprobe successfully lttng-probe-ext4 (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:347)
DEBUG1 - 10:52:39.785590375 [9674/9674]: Modprobe successfully lttng-probe-gpio (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:347)
DEBUG1 - 10:52:39.797986625 [9674/9674]: Modprobe successfully lttng-probe-i2c (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:347)
DEBUG1 - 10:52:39.810620500 [9674/9674]: Modprobe successfully lttng-probe-irq (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:347)
DEBUG1 - 10:52:39.823049125 [9674/9674]: Unable to load optional module lttng-probe-jbd; continuing (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:342)
DEBUG1 - 10:52:39.835681000 [9674/9674]: Modprobe successfully lttng-probe-jbd2 (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:347)
DEBUG1 - 10:52:39.848332125 [9674/9674]: Modprobe successfully lttng-probe-kmem (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:347)
DEBUG1 - 10:52:39.860791125 [9674/9674]: Unable to load optional module lttng-probe-kvm; continuing (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:342)
DEBUG1 - 10:52:39.873278750 [9674/9674]: Unable to load optional module lttng-probe-kvm-x86; continuing (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:342)
DEBUG1 - 10:52:39.885839750 [9674/9674]: Unable to load optional module lttng-probe-kvm-x86-mmu; continuing (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:342)
DEBUG1 - 10:52:39.898352125 [9674/9674]: Unable to load optional module lttng-probe-lock; continuing (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:342)
DEBUG1 - 10:52:39.910851375 [9674/9674]: Modprobe successfully lttng-probe-module (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:347)
DEBUG1 - 10:52:39.923342000 [9674/9674]: Modprobe successfully lttng-probe-napi (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:347)
DEBUG1 - 10:52:39.936080750 [9674/9674]: Modprobe successfully lttng-probe-net (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:347)
DEBUG1 - 10:52:39.948481750 [9674/9674]: Modprobe successfully lttng-probe-power (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:347)
DEBUG1 - 10:52:39.960975500 [9674/9674]: Unable to load optional module lttng-probe-preemptirq; continuing (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:342)
DEBUG1 - 10:52:39.973571375 [9674/9674]: Modprobe successfully lttng-probe-printk (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:347)
DEBUG1 - 10:52:39.986175875 [9674/9674]: Modprobe successfully lttng-probe-random (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:347)
DEBUG1 - 10:52:39.998614750 [9674/9674]: Modprobe successfully lttng-probe-rcu (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:347)
DEBUG1 - 10:52:40.012540500 [9674/9674]: Modprobe successfully lttng-probe-regmap (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:347)
DEBUG1 - 10:52:40.025339875 [9674/9674]: Modprobe successfully lttng-probe-regulator (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:347)
DEBUG1 - 10:52:40.037904375 [9674/9674]: Unable to load optional module lttng-probe-rpm; continuing (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:342)
DEBUG1 - 10:52:40.050393500 [9674/9674]: Modprobe successfully lttng-probe-sched (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:347)
DEBUG1 - 10:52:40.065834625 [9674/9674]: Modprobe successfully lttng-probe-scsi (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:347)
DEBUG1 - 10:52:40.078366625 [9674/9674]: Modprobe successfully lttng-probe-signal (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:347)
DEBUG1 - 10:52:40.091056000 [9674/9674]: Modprobe successfully lttng-probe-skb (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:347)
DEBUG1 - 10:52:40.103675625 [9674/9674]: Modprobe successfully lttng-probe-sock (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:347)
DEBUG1 - 10:52:40.116282875 [9674/9674]: Modprobe successfully lttng-probe-statedump (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:347)
DEBUG1 - 10:52:40.128906125 [9674/9674]: Modprobe successfully lttng-probe-sunrpc (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:347)
DEBUG1 - 10:52:40.141389875 [9674/9674]: Modprobe successfully lttng-probe-timer (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:347)
DEBUG1 - 10:52:40.153974375 [9674/9674]: Modprobe successfully lttng-probe-udp (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:347)
DEBUG1 - 10:52:40.166470000 [9674/9674]: Modprobe successfully lttng-probe-vmscan (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:347)
DEBUG1 - 10:52:40.178876000 [9674/9674]: Unable to load optional module lttng-probe-v4l2; continuing (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:342)
DEBUG1 - 10:52:40.191337625 [9674/9674]: Modprobe successfully lttng-probe-workqueue (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:347)
DEBUG1 - 10:52:40.203751875 [9674/9674]: Modprobe successfully lttng-probe-writeback (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:347)
DEBUG1 - 10:52:40.216316750 [9674/9674]: Unable to load optional module lttng-probe-x86-irq-vectors; continuing (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:342)
DEBUG1 - 10:52:40.229580625 [9674/9674]: Unable to load optional module lttng-probe-x86-exceptions; continuing (in modprobe_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:342)
DEBUG1 - 10:52:40.229684875 [9674/9674]: Kernel tracer fd 21 (in init_kernel_tracer() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/kernel.c:1590)
DEBUG3 - 10:52:40.229718625 [9674/9674]: Syscall init system call table (in syscall_init_table() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/lttng-syscall.c:52)
DEBUG1 - 10:52:40.231361500 [9674/9674]: Reallocating syscall table from 256 to 512 entries (in syscall_init_table() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/lttng-syscall.c:97)
DEBUG1 - 10:52:40.233236375 [9674/9674]: Reallocating syscall table from 512 to 1024 entries (in syscall_init_table() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/lttng-syscall.c:97)
DEBUG2 - 10:52:40.234564750 [9674/9674]: Creating consumer directory: /var/run/lttng/ustconsumerd64 (in set_consumer_sockets() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/main.c:1043)
DEBUG2 - 10:52:40.235294750 [9674/9674]: Creating consumer directory: /var/run/lttng/ustconsumerd32 (in set_consumer_sockets() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/main.c:1043)
DEBUG3 - 10:52:40.235967125 [9674/9674]: Created hashtable size 4 at 0xaaaafaa9ad00 of type 2 (in lttng_ht_new() at ../../../../lttng-tools-2.11.5/src/common/hashtable/hashtable.c:145)
DEBUG3 - 10:52:40.236017250 [9674/9674]: Global buffer per UID registry initialized (in buffer_reg_init_uid_registry() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/buffer-registry.c:100)
DEBUG3 - 10:52:40.236055625 [9674/9674]: Created hashtable size 4 at 0xaaaafaa9b140 of type 2 (in lttng_ht_new() at ../../../../lttng-tools-2.11.5/src/common/hashtable/hashtable.c:145)
DEBUG3 - 10:52:40.236383375 [9674/9674]: Global buffer per PID registry initialized (in buffer_reg_init_pid_registry() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/buffer-registry.c:229)
DEBUG1 - 10:52:40.236430000 [9674/9674]: Command subsystem initialized (in cmd_init() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/cmd.c:5396)
DEBUG1 - 10:52:40.236636125 [9674/9674]: Pid 9674 written in file /var/run/lttng/lttng-sessiond.pid (in utils_create_pid_file() at ../../../lttng-tools-2.11.5/src/common/utils.c:625)
DEBUG1 - 10:52:40.236897875 [9674/9674]: TCP inet operation timeout set to 216 sec (in lttcomm_inet_init() at ../../../../lttng-tools-2.11.5/src/common/sessiond-comm/inet.c:555)
DEBUG1 - 10:52:40.237295125 [9674/9674]: Waiting for health management thread to be ready (in wait_until_thread_is_ready() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/health.c:45)
DEBUG1 - 10:52:40.237382000 [9674/9731]: Launching "Health management" thread (in launch_thread() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/thread.c:74)
DEBUG1 - 10:52:40.237457750 [9674/9731]: [thread] Manage health check started (in thread_manage_health() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/health.c:75)
DEBUG1 - 10:52:40.238175250 [9674/9731]: Marking health management thread as ready (in mark_thread_as_ready() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/health.c:38)
DEBUG1 - 10:52:40.238268000 [9674/9674]: Health management thread is ready (in wait_until_thread_is_ready() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/health.c:47)
DEBUG1 - 10:52:40.238610000 [9674/9674]: Waiting for notification thread to be ready (in wait_until_thread_is_ready() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:397)
DEBUG1 - 10:52:40.238667250 [9674/9731]: Health check ready (in thread_manage_health() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/health.c:146)
DEBUG1 - 10:52:40.238728125 [9674/9732]: Launching "Notification" thread (in launch_thread() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/thread.c:74)
DEBUG1 - 10:52:40.238806500 [9674/9732]: [notification-thread] Started notification thread (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:531)
DEBUG1 - 10:52:40.238926125 [9674/9732]: [notification-thread] Creating notification channel UNIX socket at /var/run/lttng/sessiond-notification (in notification_channel_socket_create() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:224)
DEBUG1 - 10:52:40.239569000 [9674/9732]: [notification-thread] Notification channel UNIX socket created (fd = 36) (in notification_channel_socket_create() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:259)
DEBUG1 - 10:52:40.239766125 [9674/9732]: [notification-thread] Listening on notification channel socket (in init_thread_state() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:424)
DEBUG1 - 10:52:40.239845250 [9674/9732]: Marking notification thread as ready (in mark_thread_as_ready() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:390)
DEBUG1 - 10:52:40.239909625 [9674/9674]: Notification thread is ready (in wait_until_thread_is_ready() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:399)
DEBUG1 - 10:52:40.241053500 [9674/9674]: Created client socket (fd = 42) (in create_client_sock() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:1997)
DEBUG1 - 10:52:40.241410625 [9674/9674]: Waiting for client thread to be ready (in wait_thread_status() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:59)
DEBUG1 - 10:52:40.241496500 [9674/9732]: [notification-thread] Entering poll wait (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:553)
DEBUG1 - 10:52:40.241569125 [9674/9735]: Launching "Client management" thread (in launch_thread() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/thread.c:74)
DEBUG1 - 10:52:40.241724375 [9674/9735]: [thread] Manage client started (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2031)
DEBUG1 - 10:52:40.241979875 [9674/9735]: Marking client thread's state as running (in set_thread_status() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:52)
DEBUG1 - 10:52:40.242040875 [9674/9674]: Client thread is ready (in wait_thread_status() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:62)
DEBUG1 - 10:52:40.242442625 [9674/9674]: All permissions are set (in set_permissions() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/main.c:989)
DEBUG3 - 10:52:40.243053500 [9674/9674]: Session daemon application socket created (fd = 46) (in create_application_socket() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/register.c:79)
DEBUG1 - 10:52:40.243462500 [9674/9674]: Waiting for application registration thread to be ready (in wait_thread_status() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/register.c:139)
DEBUG1 - 10:52:40.243548625 [9674/9735]: Accepting client command ... (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2087)
DEBUG1 - 10:52:40.243610625 [9674/9734]: Launching "Rotation" thread (in launch_thread() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/thread.c:74)
DEBUG1 - 10:52:40.243684375 [9674/9734]: [rotation-thread] Started rotation thread (in thread_rotation() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/rotation-thread.c:806)
DEBUG1 - 10:52:40.244182375 [9674/9732]: [notification-thread] Poll wait returned (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:555)
DEBUG1 - 10:52:40.244236625 [9674/9732]: [notification-thread] Handling fd (36) activity (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:573)
DEBUG1 - 10:52:40.244272500 [9674/9732]: [notification-thread] Handling new notification channel client connection (in handle_notification_thread_client_connect() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread-events.c:2424)
DEBUG1 - 10:52:40.244374000 [9674/9732]: Client socket (fd = 49) set as non-blocking (in socket_set_non_blocking() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread-events.c:2392)
DEBUG1 - 10:52:40.244440250 [9674/9732]: [notification-thread] Added new notification channel client socket (49) to poll set (in handle_notification_thread_client_connect() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread-events.c:2473)
DEBUG1 - 10:52:40.244480375 [9674/9732]: [notification-thread] Entering poll wait (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:553)
DEBUG1 - 10:52:40.244618250 [9674/9732]: [notification-thread] Poll wait returned (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:555)
DEBUG1 - 10:52:40.244651750 [9674/9732]: [notification-thread] Handling fd (49) activity (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:573)
DEBUG1 - 10:52:40.244706500 [9674/9732]: [notification-thread] Entering poll wait (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:553)
DEBUG1 - 10:52:40.244747250 [9674/9732]: [notification-thread] Poll wait returned (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:555)
DEBUG1 - 10:52:40.244779875 [9674/9732]: [notification-thread] Handling fd (49) activity (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:573)
DEBUG1 - 10:52:40.244832125 [9674/9732]: [notification-thread] Received handshake from client (uid = 0, gid = 0) with version 1.1 (in client_dispatch_message() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread-events.c:2772)
DEBUG1 - 10:52:40.244950250 [9674/9732]: [notification-thread] Flushing client (socket fd = 49) outgoing queue (in client_flush_outgoing_queue() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread-events.c:2571)
DEBUG1 - 10:52:40.245010125 [9674/9732]: [notification-thread] Send command reply (0) (in client_send_command_reply() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread-events.c:2655)
DEBUG1 - 10:52:40.245041000 [9674/9732]: [notification-thread] Flushing client (socket fd = 49) outgoing queue (in client_flush_outgoing_queue() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread-events.c:2571)
DEBUG1 - 10:52:40.245093000 [9674/9732]: [notification-thread] Entering poll wait (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:553)
DEBUG1 - 10:52:40.245336500 [9674/9734]: [rotation-thread] Entering poll wait (in thread_rotation() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/rotation-thread.c:830)
DEBUG1 - 10:52:40.245411000 [9674/9733]: Launching "Timer" thread (in launch_thread() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/thread.c:74)
DEBUG1 - 10:52:40.245518125 [9674/9737]: Launching "UST application registration" thread (in launch_thread() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/thread.c:74)
DEBUG1 - 10:52:40.245591750 [9674/9737]: [thread] Manage application registration started (in thread_application_registration() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/register.c:176)
DEBUG1 - 10:52:40.245786375 [9674/9737]: Marking application registration thread's state as running (in set_thread_status() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/register.c:132)
DEBUG1 - 10:52:40.245849500 [9674/9674]: Application registration thread is ready (in wait_thread_status() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/register.c:142)
DEBUG1 - 10:52:40.245883625 [9674/9674]: Notifying applications of session daemon state: 1 (in notify_ust_apps() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/register.c:100)
DEBUG1 - 10:52:40.246050750 [9674/9674]: Got the wait shm fd 51 (in get_wait_shm() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/shm.c:148)
DEBUG1 - 10:52:40.247381375 [9674/9674]: Futex wait update active 1 (in futex_wait_update() at ../../../lttng-tools-2.11.5/src/common/futex.c:65)
DEBUG1 - 10:52:40.248435000 [9674/9674]: Waiting for agent management thread to be ready (in wait_until_thread_is_ready() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/agent-thread.c:344)
DEBUG1 - 10:52:40.248556500 [9674/9737]: Accepting application registration (in thread_application_registration() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/register.c:215)
DEBUG1 - 10:52:40.248791625 [9674/9737]: UST registration received with pid:643 ppid:1 uid:0 gid:0 sock:57 name:TrafficControll (version 8.0) (in thread_application_registration() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/register.c:319)
DEBUG1 - 10:52:40.248830000 [9674/9737]: Futex n to 1 wake done (in futex_nto1_wake() at ../../../lttng-tools-2.11.5/src/common/futex.c:122)
DEBUG1 - 10:52:40.248864625 [9674/9737]: Accepting application registration (in thread_application_registration() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/register.c:215)
DEBUG1 - 10:52:40.249009000 [9674/9737]: UST registration received with pid:643 ppid:1 uid:0 gid:0 sock:58 name:TrafficControll (version 8.0) (in thread_application_registration() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/register.c:319)
DEBUG1 - 10:52:40.249043000 [9674/9737]: Futex n to 1 wake done (in futex_nto1_wake() at ../../../lttng-tools-2.11.5/src/common/futex.c:122)
DEBUG1 - 10:52:40.249074000 [9674/9737]: Accepting application registration (in thread_application_registration() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/register.c:215)
DEBUG1 - 10:52:40.249254000 [9674/9736]: Launching "UST registration dispatch" thread (in launch_thread() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/thread.c:74)
DEBUG1 - 10:52:40.249639625 [9674/9736]: [thread] Dispatch UST command started (in thread_dispatch_ust_registration() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/dispatch.c:254)
DEBUG1 - 10:52:40.249672125 [9674/9736]: Futex n to 1 prepare done (in futex_nto1_prepare() at ../../../lttng-tools-2.11.5/src/common/futex.c:77)
DEBUG1 - 10:52:40.249705000 [9674/9736]: Dispatching UST registration pid:643 ppid:1 uid:0 gid:0 sock:57 name:TrafficControll (version 8.0) (in thread_dispatch_ust_registration() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/dispatch.c:290)
DEBUG3 - 10:52:40.249861500 [9674/9736]: UST app creating application for socket 57 (in ust_app_create() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:3336)
DEBUG3 - 10:52:40.249925000 [9674/9736]: Created hashtable size 4 at 0xffff80000cf0 of type 2 (in lttng_ht_new() at ../../../../lttng-tools-2.11.5/src/common/hashtable/hashtable.c:145)
DEBUG3 - 10:52:40.249966750 [9674/9736]: Created hashtable size 4 at 0xffff80001130 of type 1 (in lttng_ht_new() at ../../../../lttng-tools-2.11.5/src/common/hashtable/hashtable.c:145)
DEBUG3 - 10:52:40.250003625 [9674/9736]: Created hashtable size 4 at 0xffff80001570 of type 1 (in lttng_ht_new() at ../../../../lttng-tools-2.11.5/src/common/hashtable/hashtable.c:145)
DEBUG1 - 10:52:40.250306750 [9674/9737]: UST registration received with pid:635 ppid:1 uid:0 gid:0 sock:59 name:rfm-ust (version 8.0) (in thread_application_registration() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/register.c:319)
DEBUG1 - 10:52:40.250366875 [9674/9737]: Futex n to 1 wake done (in futex_nto1_wake() at ../../../lttng-tools-2.11.5/src/common/futex.c:122)
DEBUG1 - 10:52:40.250398000 [9674/9737]: Accepting application registration (in thread_application_registration() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/register.c:215)
DEBUG1 - 10:52:40.250973875 [9674/9736]: Dispatching UST registration pid:643 ppid:1 uid:0 gid:0 sock:58 name:TrafficControll (version 8.0) (in thread_dispatch_ust_registration() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/dispatch.c:290)
DEBUG3 - 10:52:40.251012250 [9674/9736]: UST app notify socket 58 is set (in thread_dispatch_ust_registration() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/dispatch.c:357)
DEBUG1 - 10:52:40.251060000 [9674/9736]: App registered with pid:643 ppid:1 uid:0 gid:0 sock:57 name:TrafficControll notify_sock:58 (version 8.0) (in ust_app_add() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:3424)
DEBUG1 - 10:52:40.251837750 [9674/9737]: UST registration received with pid:635 ppid:1 uid:0 gid:0 sock:60 name:rfm-ust (version 8.0) (in thread_application_registration() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/register.c:319)
DEBUG1 - 10:52:40.251898375 [9674/9737]: Futex n to 1 wake done (in futex_nto1_wake() at ../../../lttng-tools-2.11.5/src/common/futex.c:122)
DEBUG1 - 10:52:40.251930125 [9674/9737]: Accepting application registration (in thread_application_registration() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/register.c:215)
DEBUG1 - 10:52:40.252336500 [9674/9736]: Dispatching UST registration pid:635 ppid:1 uid:0 gid:0 sock:59 name:rfm-ust (version 8.0) (in thread_dispatch_ust_registration() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/dispatch.c:290)
DEBUG3 - 10:52:40.252389875 [9674/9736]: UST app creating application for socket 59 (in ust_app_create() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:3336)
DEBUG3 - 10:52:40.252430375 [9674/9736]: Created hashtable size 4 at 0xffff80001b40 of type 2 (in lttng_ht_new() at ../../../../lttng-tools-2.11.5/src/common/hashtable/hashtable.c:145)
DEBUG3 - 10:52:40.252490000 [9674/9736]: Created hashtable size 4 at 0xffff80001f80 of type 1 (in lttng_ht_new() at ../../../../lttng-tools-2.11.5/src/common/hashtable/hashtable.c:145)
DEBUG3 - 10:52:40.252613750 [9674/9736]: Created hashtable size 4 at 0xffff800023c0 of type 1 (in lttng_ht_new() at ../../../../lttng-tools-2.11.5/src/common/hashtable/hashtable.c:145)
DEBUG1 - 10:52:40.252781625 [9674/9736]: Dispatching UST registration pid:635 ppid:1 uid:0 gid:0 sock:60 name:rfm-ust (version 8.0) (in thread_dispatch_ust_registration() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/dispatch.c:290)
DEBUG3 - 10:52:40.252818625 [9674/9736]: UST app notify socket 60 is set (in thread_dispatch_ust_registration() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/dispatch.c:357)
DEBUG1 - 10:52:40.252864000 [9674/9736]: App registered with pid:635 ppid:1 uid:0 gid:0 sock:59 name:rfm-ust notify_sock:60 (version 8.0) (in ust_app_add() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:3424)
DEBUG1 - 10:52:40.253424875 [9674/9736]: Woken up but nothing in the UST command queue (in thread_dispatch_ust_registration() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/dispatch.c:283)
DEBUG1 - 10:52:40.253485500 [9674/9736]: Futex n to 1 wait done (in futex_nto1_wait() at ../../../lttng-tools-2.11.5/src/common/futex.c:105)
DEBUG1 - 10:52:40.253518500 [9674/9736]: Futex n to 1 prepare done (in futex_nto1_prepare() at ../../../lttng-tools-2.11.5/src/common/futex.c:77)
DEBUG1 - 10:52:40.253552125 [9674/9736]: Woken up but nothing in the UST command queue (in thread_dispatch_ust_registration() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/dispatch.c:283)
DEBUG1 - 10:52:40.253619375 [9674/9740]: Launching "Agent management" thread (in launch_thread() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/thread.c:74)
DEBUG1 - 10:52:40.253718500 [9674/9740]: [agent-thread] Manage agent application registration. (in thread_agent_management() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/agent-thread.c:362)
DEBUG3 - 10:52:40.253912125 [9674/9740]: URI string: tcp://localhost (in uri_parse() at ../../../lttng-tools-2.11.5/src/common/uri.c:324)
DEBUG2 - 10:52:40.255464375 [9674/9740]: IP address resolved to 127.0.0.1 (in set_ip_address() at ../../../lttng-tools-2.11.5/src/common/uri.c:165)
DEBUG3 - 10:52:40.255540625 [9674/9740]: URI dtype: 1, proto: 1, host: localhost, subdir: , ctrl: 0, data: 0 (in uri_parse() at ../../../lttng-tools-2.11.5/src/common/uri.c:536)
DEBUG3 - 10:52:40.255653750 [9674/9740]: [agent-thread] Trying to bind on port 5345 (in init_tcp_socket() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/agent-thread.c:137)
DEBUG1 - 10:52:40.255728750 [9674/9740]: [agent-thread] Listening on TCP port 5345 and socket 62 (in init_tcp_socket() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/agent-thread.c:173)
DEBUG1 - 10:52:40.255926125 [9674/9740]: Pid 5345 written in file /var/run/lttng/agent.port (in utils_create_pid_file() at ../../../lttng-tools-2.11.5/src/common/utils.c:625)
DEBUG1 - 10:52:40.255960250 [9674/9740]: Marking agent management thread as ready (in mark_thread_as_ready() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/agent-thread.c:337)
DEBUG1 - 10:52:40.256032000 [9674/9674]: Agent management thread is ready (in wait_until_thread_is_ready() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/agent-thread.c:346)
DEBUG1 - 10:52:40.262278375 [9674/9739]: Launching "Application notification" thread (in launch_thread() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/thread.c:74)
DEBUG1 - 10:52:40.262456500 [9674/9739]: [ust-thread] Manage application notify command (in thread_application_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notify-apps.c:49)
DEBUG3 - 10:52:40.262924375 [9674/9739]: [ust-thread] Manage notify polling (in thread_application_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notify-apps.c:84)
DEBUG3 - 10:52:40.262978250 [9674/9739]: [ust-thread] Manage notify return from poll on 2 fds (in thread_application_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notify-apps.c:90)
DEBUG3 - 10:52:40.263175000 [9674/9739]: UST thread notify added sock 58 to pollset (in thread_application_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notify-apps.c:144)
DEBUG3 - 10:52:40.263220250 [9674/9739]: [ust-thread] Manage notify polling (in thread_application_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notify-apps.c:84)
DEBUG3 - 10:52:40.263260750 [9674/9739]: [ust-thread] Manage notify return from poll on 3 fds (in thread_application_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notify-apps.c:90)
DEBUG3 - 10:52:40.263319250 [9674/9739]: UST thread notify added sock 60 to pollset (in thread_application_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notify-apps.c:144)
DEBUG3 - 10:52:40.263351500 [9674/9739]: [ust-thread] Manage notify polling (in thread_application_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notify-apps.c:84)
DEBUG1 - 10:52:40.263417750 [9674/9738]: Launching "UST application management" thread (in launch_thread() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/thread.c:74)
DEBUG1 - 10:52:40.263500250 [9674/9738]: [thread] Manage application started (in thread_application_management() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/manage-apps.c:62)
DEBUG1 - 10:52:40.263689000 [9674/9738]: Apps thread polling (in thread_application_management() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/manage-apps.c:98)
DEBUG1 - 10:52:40.263728500 [9674/9738]: Apps thread return from poll on 2 fds (in thread_application_management() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/manage-apps.c:104)
DEBUG1 - 10:52:40.263794125 [9674/9738]: Apps with sock 57 added to poll set (in thread_application_management() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/manage-apps.c:155)
DEBUG1 - 10:52:40.263824750 [9674/9738]: Apps thread polling (in thread_application_management() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/manage-apps.c:98)
DEBUG1 - 10:52:40.263869750 [9674/9738]: Apps thread return from poll on 3 fds (in thread_application_management() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/manage-apps.c:104)
DEBUG1 - 10:52:40.263928500 [9674/9738]: Apps with sock 59 added to poll set (in thread_application_management() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/manage-apps.c:155)
DEBUG1 - 10:52:40.263959750 [9674/9738]: Apps thread polling (in thread_application_management() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/manage-apps.c:98)
DEBUG3 - 10:52:40.264042250 [9674/9740]: [agent-thread] Manage agent polling (in thread_agent_management() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/agent-thread.c:416)
DEBUG1 - 10:52:40.264097250 [9674/9741]: Launching "Kernel management" thread (in launch_thread() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/thread.c:74)
DEBUG1 - 10:52:40.264215875 [9674/9741]: [thread] Thread manage kernel started (in thread_kernel_management() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/manage-kernel.c:183)
DEBUG1 - 10:52:40.264420750 [9674/9741]: Updating kernel poll set (in update_kernel_poll() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/manage-kernel.c:47)
DEBUG1 - 10:52:40.264456000 [9674/9741]: Thread kernel polling (in thread_kernel_management() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/manage-kernel.c:237)
DEBUG1 - 10:53:10.592498000 [9674/9735]: Wait for client response (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2129)
DEBUG1 - 10:53:10.592799750 [9674/9735]: Receiving data from client ... (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2174)
DEBUG1 - 10:53:10.592917875 [9674/9735]: Nothing recv() from client... continuing (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2178)
DEBUG1 - 10:53:10.593013000 [9674/9735]: Clean command context structure (in clean_command_ctx() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:659)
DEBUG1 - 10:53:10.593207500 [9674/9735]: Accepting client command ... (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2087)
DEBUG1 - 10:53:10.593611250 [9674/9735]: Wait for client response (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2129)
DEBUG1 - 10:53:10.593725250 [9674/9735]: Receiving data from client ... (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2174)
DEBUG1 - 10:53:10.593970125 [9674/9735]: Processing client command 49 (in process_client_msg() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:723)
DEBUG3 - 10:53:10.594289875 [9674/9735]: Created hashtable size 4 at 0xffff9000c390 of type 1 (in lttng_ht_new() at ../../../../lttng-tools-2.11.5/src/common/hashtable/hashtable.c:145)
DEBUG2 - 10:53:10.594419875 [9674/9735]: Trying to find session by name auto-20210324-105310 (in session_find_by_name() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/session.c:914)
DEBUG1 - 10:53:10.594453250 [9674/9735]: Generated session name "auto-20210324-105310" (in session_create() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/session.c:1068)
DEBUG3 - 10:53:10.594495625 [9674/9735]: Created hashtable size 4 at 0xffff9000c9b0 of type 1 (in lttng_ht_new() at ../../../../lttng-tools-2.11.5/src/common/hashtable/hashtable.c:145)
DEBUG1 - 10:53:10.594529625 [9674/9735]: Allocating ltt_sessions_ht_by_id (in ltt_sessions_ht_alloc() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/session.c:309)
DEBUG3 - 10:53:10.594582125 [9674/9735]: Created hashtable size 4 at 0xffff9000cdf0 of type 2 (in lttng_ht_new() at ../../../../lttng-tools-2.11.5/src/common/hashtable/hashtable.c:145)
DEBUG1 - 10:53:10.594626625 [9674/9735]: Tracing session auto-20210324-105310 created with ID 0 by uid = 0, gid = 0 (in session_create() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/session.c:1116)
DEBUG3 - 10:53:10.594664875 [9674/9735]: URI string: file:///home/root/lttng-traces/auto-20210324-105310 (in uri_parse() at ../../../lttng-tools-2.11.5/src/common/uri.c:324)
DEBUG3 - 10:53:10.594778500 [9674/9735]: URI file destination: /home/root/lttng-traces/auto-20210324-105310 (in uri_parse() at ../../../lttng-tools-2.11.5/src/common/uri.c:361)
DEBUG3 - 10:53:10.594809625 [9674/9735]: URI dtype: 3, proto: 0, host: , subdir: , ctrl: 0, data: 0 (in uri_parse() at ../../../lttng-tools-2.11.5/src/common/uri.c:536)
DEBUG2 - 10:53:10.594853375 [9674/9735]: Setting trace directory path from URI to /home/root/lttng-traces/auto-20210324-105310 (in add_uri_to_consumer() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/cmd.c:912)
DEBUG1 - 10:53:10.594997500 [9674/9735]: Sending response (size: 8258, retcode: Success (10)) (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2236)
DEBUG1 - 10:53:10.595177500 [9674/9735]: Clean command context structure (in clean_command_ctx() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:659)
DEBUG1 - 10:53:10.595225625 [9674/9735]: Accepting client command ... (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2087)
DEBUG1 - 10:53:10.595719000 [9674/9735]: Wait for client response (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2129)
DEBUG1 - 10:53:10.595861125 [9674/9735]: Receiving data from client ... (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2174)
DEBUG1 - 10:53:10.596064875 [9674/9735]: Processing client command 13 (in process_client_msg() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:723)
DEBUG1 - 10:53:10.596104500 [9674/9735]: Counting number of available session for UID 0 GID 0 (in lttng_sessions_count() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:521)
DEBUG1 - 10:53:10.596306625 [9674/9735]: Getting all available session for UID 0 GID 0 (in cmd_list_lttng_sessions() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/cmd.c:3697)
DEBUG1 - 10:53:10.596447125 [9674/9735]: Sending response (size: 4412, retcode: Success (10)) (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2236)
DEBUG1 - 10:53:10.596579250 [9674/9735]: Clean command context structure (in clean_command_ctx() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:659)
DEBUG1 - 10:53:10.596612875 [9674/9735]: Accepting client command ... (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2087)
DEBUG1 - 10:53:27.217209500 [9674/9735]: Wait for client response (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2129)
DEBUG1 - 10:53:27.217480250 [9674/9735]: Receiving data from client ... (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2174)
DEBUG1 - 10:53:27.217706625 [9674/9735]: Processing client command 14 (in process_client_msg() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:723)
DEBUG2 - 10:53:27.224679375 [9674/9735]: Reallocating event list from 32 to 64 entries (in ust_app_list_events() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:3658)
DEBUG2 - 10:53:27.228610625 [9674/9735]: UST app list events done (52 events) (in ust_app_list_events() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:3700)
DEBUG1 - 10:53:27.228858500 [9674/9735]: Sending response (size: 30388, retcode: Success (10)) (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2236)
DEBUG1 - 10:53:27.229054000 [9674/9735]: Clean command context structure (in clean_command_ctx() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:659)
DEBUG1 - 10:53:27.229098875 [9674/9735]: Accepting client command ... (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2087)
DEBUG1 - 10:53:51.641306375 [9674/9735]: Wait for client response (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2129)
DEBUG1 - 10:53:51.641529875 [9674/9735]: Receiving data from client ... (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2174)
DEBUG1 - 10:53:51.641750250 [9674/9735]: Processing client command 6 (in process_client_msg() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:723)
DEBUG1 - 10:53:51.641798000 [9674/9735]: Getting session auto-20210324-105310 by name (in process_client_msg() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:819)
DEBUG2 - 10:53:51.641838375 [9674/9735]: Trying to find session by name auto-20210324-105310 (in session_find_by_name() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/session.c:914)
DEBUG1 - 10:53:51.641881750 [9674/9735]: Creating UST session (in create_ust_session() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:435)
DEBUG3 - 10:53:51.641940500 [9674/9735]: Created hashtable size 4 at 0xffff90002ef0 of type 0 (in lttng_ht_new() at ../../../../lttng-tools-2.11.5/src/common/hashtable/hashtable.c:145)
DEBUG3 - 10:53:51.641983750 [9674/9735]: Created hashtable size 4 at 0xffff90003330 of type 2 (in lttng_ht_new() at ../../../../lttng-tools-2.11.5/src/common/hashtable/hashtable.c:145)
DEBUG3 - 10:53:51.642031125 [9674/9735]: Created hashtable size 4 at 0xffff90003770 of type 1 (in lttng_ht_new() at ../../../../lttng-tools-2.11.5/src/common/hashtable/hashtable.c:145)
DEBUG2 - 10:53:51.642073750 [9674/9735]: UST trace session create successful (in trace_ust_create_session() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/trace-ust.c:321)
DEBUG3 - 10:53:51.642152375 [9674/9735]: Copying tracing session consumer output in UST session (in copy_session_consumer() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:379)
DEBUG3 - 10:53:51.642267250 [9674/9676]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:135)
DEBUG3 - 10:53:51.642635375 [9674/9676]: [ht-thread] Polling. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:132)
DEBUG3 - 10:53:51.642708875 [9674/9735]: Created hashtable size 4 at 0xffff90003bb0 of type 1 (in lttng_ht_new() at ../../../../lttng-tools-2.11.5/src/common/hashtable/hashtable.c:145)
DEBUG3 - 10:53:51.642758625 [9674/9735]: Copy session consumer subdir ust (in copy_session_consumer() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:401)
DEBUG1 - 10:53:51.642798625 [9674/9735]: Spawning consumerd (in spawn_consumerd() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:141)
DEBUG2 - 10:53:51.646900625 [9674/9735]: Consumer pid 10129 (in start_consumerd() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:315)
DEBUG2 - 10:53:51.647236875 [9674/9735]: Spawning consumer control thread (in start_consumerd() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:318)
DEBUG1 - 10:53:51.647810625 [9674/9735]: Waiting for consumer management thread to be ready (in wait_until_thread_is_ready() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/manage-consumer.c:56)
DEBUG1 - 10:53:51.647886000 [9674/10130]: Launching "Consumer management" thread (in launch_thread() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/thread.c:74)
DEBUG1 - 10:53:51.647959000 [9674/10130]: [thread] Manage consumer started (in thread_consumer_management() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/manage-consumer.c:75)
DEBUG1 - 10:53:51.649155500 [10129/10129]: Using 64-bit UST consumer at: /usr/lib/lttng/libexec/lttng-consumerd (in spawn_consumerd() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:219)
DEBUG2 - 10:53:52.024325750 [9674/10130]: Receiving code from consumer err_sock (in thread_consumer_management() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/manage-consumer.c:172)
DEBUG1 - 10:53:52.127282125 [9674/10130]: Consumer command socket ready (fd: 74) (in thread_consumer_management() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/manage-consumer.c:214)
DEBUG1 - 10:53:52.127417250 [9674/10130]: Consumer metadata socket ready (fd: 75) (in thread_consumer_management() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/manage-consumer.c:215)
DEBUG1 - 10:53:52.127547250 [9674/10130]: Sending consumer initialization command (in consumer_init() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/consumer.c:1741)
DEBUG3 - 10:53:52.128716125 [9674/10130]: Sending SET_CHANNEL_MONITOR_PIPE command to consumer (in consumer_send_pipe() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/consumer.c:1234)
DEBUG3 - 10:53:52.129081375 [9674/10130]: Sending channel monitor pipe 18 to consumer on socket 74 (in consumer_send_pipe() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/consumer.c:1240)
DEBUG2 - 10:53:52.129419250 [9674/10130]: channel monitor pipe successfully sent (in consumer_send_pipe() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/consumer.c:1248)
DEBUG1 - 10:53:52.129874625 [9674/10130]: Marking consumer management thread as ready (in mark_thread_as_ready() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/manage-consumer.c:41)
DEBUG1 - 10:53:52.129985375 [9674/9735]: Consumer management thread is ready (in wait_until_thread_is_ready() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/manage-consumer.c:58)
DEBUG3 - 10:53:52.130057750 [9674/9735]: Consumer socket created (fd: 74) and added to output (in consumer_create_socket() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/consumer.c:358)
DEBUG1 - 10:53:52.130106250 [9674/9735]: Setting relayd for session auto-20210324-105310 (in cmd_setup_relayd() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/cmd.c:1185)
DEBUG1 - 10:53:52.130237000 [9674/9735]: Enable event command for event 'lttng_ust_tracef:*' (in _cmd_enable_event() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/cmd.c:2036)
DEBUG2 - 10:53:52.130399500 [9674/9735]: Trace UST channel channel0 not found by name (in trace_ust_find_channel_by_name() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/trace-ust.c:197)
DEBUG1 - 10:53:52.130450125 [9674/9735]: Enabling channel for session auto-20210324-105310 (in cmd_enable_channel() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/cmd.c:1510)
DEBUG2 - 10:53:52.130496375 [9674/9735]: Trace UST channel channel0 not found by name (in trace_ust_find_channel_by_name() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/trace-ust.c:197)
DEBUG3 - 10:53:52.130572000 [9674/9735]: Created hashtable size 4 at 0xffff90017170 of type 0 (in lttng_ht_new() at ../../../../lttng-tools-2.11.5/src/common/hashtable/hashtable.c:145)
DEBUG3 - 10:53:52.130619625 [9674/9735]: Created hashtable size 4 at 0xffff900175b0 of type 1 (in lttng_ht_new() at ../../../../lttng-tools-2.11.5/src/common/hashtable/hashtable.c:145)
DEBUG2 - 10:53:52.130666000 [9674/9735]: Trace UST channel channel0 created (in trace_ust_create_channel() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/trace-ust.c:396)
DEBUG2 - 10:53:52.130713625 [9674/9735]: Channel channel0 is being created for UST with buffer 1 and id 0 (in channel_ust_create() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/channel.c:461)
DEBUG2 - 10:53:52.130762250 [9674/9735]: Channel channel0 created successfully (in channel_ust_create() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/channel.c:500)
DEBUG2 - 10:53:52.130807500 [9674/9735]: Trace UST channel channel0 found by name (in trace_ust_find_channel_by_name() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/trace-ust.c:192)
DEBUG2 - 10:53:52.130851750 [9674/9735]: Trace UST event lttng_ust_tracef:* NOT found (in trace_ust_find_event() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/trace-ust.c:235)
DEBUG2 - 10:53:52.130896500 [9674/9735]: Trace UST event lttng_ust_tracef:*, loglevel (0,-1) created (in trace_ust_create_event() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/trace-ust.c:517)
DEBUG1 - 10:53:52.130968375 [9674/9735]: Sending response (size: 20, retcode: Success (10)) (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2236)
DEBUG1 - 10:53:52.134962250 [9674/9735]: Clean command context structure (in clean_command_ctx() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:659)
DEBUG1 - 10:53:52.136463875 [9674/9735]: Accepting client command ... (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2087)
DEBUG1 - 10:53:57.626099000 [9674/9735]: Wait for client response (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2129)
DEBUG1 - 10:53:57.626422875 [9674/9735]: Receiving data from client ... (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2174)
DEBUG1 - 10:53:57.626642500 [9674/9735]: Processing client command 16 (in process_client_msg() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:723)
DEBUG1 - 10:53:57.626685125 [9674/9735]: Getting session auto-20210324-105310 by name (in process_client_msg() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:819)
DEBUG2 - 10:53:57.626724750 [9674/9735]: Trying to find session by name auto-20210324-105310 (in session_find_by_name() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/session.c:914)
DEBUG1 - 10:53:57.626768250 [9674/9735]: Creating initial trace chunk of session "auto-20210324-105310" (in cmd_start_trace() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/cmd.c:2625)
DEBUG1 - 10:53:57.626807125 [9674/9735]: Creating trace chunk: chunk_id = 0, creation time = 20210324-105357 (in lttng_trace_chunk_create() at ../../../lttng-tools-2.11.5/src/common/trace-chunk.c:288)
DEBUG1 - 10:53:57.626841250 [9674/9735]: Chunk name set to "(none)" (in lttng_trace_chunk_create() at ../../../lttng-tools-2.11.5/src/common/trace-chunk.c:306)
DEBUG1 - 10:53:57.626969000 [9674/9735]: Creating base output directory of session "auto-20210324-105310" at /home/root/lttng-traces/auto-20210324-105310 (in session_create_new_trace_chunk() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/session.c:636)
DEBUG3 - 10:53:57.627009750 [9674/9735]: mkdirat() recursive fd = -100 (AT_FDCWD), path = /home/root/lttng-traces/auto-20210324-105310, mode = 504, uid = 0, gid = 0 (in run_as_mkdirat_recursive() at ../../../lttng-tools-2.11.5/src/common/runas.c:1394)
DEBUG1 - 10:53:57.627061250 [9674/9735]: Using run_as worker (in run_as() at ../../../lttng-tools-2.11.5/src/common/runas.c:1350)
DEBUG1 - 10:53:57.628080500 [9674/9735]: Sending consumer create trace chunk command: relayd_id = -1, session_id = 0, chunk_id = 0, creation_timestamp = 20210324T105357+0000 (in consumer_create_trace_chunk() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/consumer.c:1873)
DEBUG1 - 10:53:57.628442250 [9674/9735]: Sending trace chunk directory fd to consumer (in consumer_create_trace_chunk() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/consumer.c:1888)
DEBUG1 - 10:53:57.628907500 [9674/9735]: Starting all UST traces (in ust_app_start_trace_all() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:4930)
DEBUG1 - 10:53:57.628951875 [9674/9735]: Clearing stream quiescent state for all ust apps (in ust_app_clear_quiescent_session() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:4806)
DEBUG2 - 10:53:57.628985875 [9674/9735]: UST app global update for app sock 57 for session id 0 (in ust_app_global_update() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:5190)
DEBUG2 - 10:53:57.629021500 [9674/9735]: UST app pid: 643 session id 0 not found, creating it (in find_or_create_ust_app_session() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:2130)
DEBUG3 - 10:53:57.629085875 [9674/9735]: Created hashtable size 4 at 0xffff9001afd0 of type 0 (in lttng_ht_new() at ../../../../lttng-tools-2.11.5/src/common/hashtable/hashtable.c:145)
DEBUG2 - 10:53:57.629310000 [9674/9735]: Shadow copy of session handle -1 (in shadow_copy_session() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:1856)
DEBUG3 - 10:53:57.629366500 [9674/9735]: Buffer registry per UID find id: 0, ABI: 64, uid: 0 (in buffer_reg_uid_find() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/buffer-registry.c:203)
DEBUG3 - 10:53:57.629419375 [9674/9735]: Created hashtable size 4 at 0xffff9001d3e0 of type 2 (in lttng_ht_new() at ../../../../lttng-tools-2.11.5/src/common/hashtable/hashtable.c:145)
DEBUG3 - 10:53:57.629451625 [9674/9735]: Buffer registry per UID created id: 0, ABI: 64, uid: 0, domain: 2 (in buffer_reg_uid_create() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/buffer-registry.c:152)
DEBUG3 - 10:53:57.629505250 [9674/9735]: Created hashtable size 4 at 0xffff900208f0 of type 0 (in lttng_ht_new() at ../../../../lttng-tools-2.11.5/src/common/hashtable/hashtable.c:145)
DEBUG3 - 10:53:57.629575125 [9674/9735]: Created hashtable size 4 at 0xffff90020d30 of type 2 (in lttng_ht_new() at ../../../../lttng-tools-2.11.5/src/common/hashtable/hashtable.c:145)
DEBUG3 - 10:53:57.629695750 [9674/9735]: Append to metadata: "/* CTF 1.8 */
" (in lttng_metadata_printf() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-metadata.c:180)
DEBUG3 - 10:53:57.629740875 [9674/9735]: Append to metadata: "typealias integer { size = 8; align = 8; signed = false; } := uint8_t;
typealias integer { size = 16; align = 16; signed = false; } := uint16_t;
typealias integer { size = 32; align = 32; signed = false; } := uint32_t;
typealias integer { size = 64; align = 64; signed = false; } := uint64_t;
typealias integer { size = 64; align = 64; 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 = "1d464682-d624-44d5-8ee7-163857826faa";
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 ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-metadata.c:180)
DEBUG3 - 10:53:57.629862375 [9674/9735]: Append to metadata: "env {
domain = "ust";
tracer_name = "lttng-ust";
tracer_major = 2;
tracer_minor = 11;
tracer_buffering_scheme = "uid";
tracer_buffering_id = 0;
architecture_bit_width = 64;
" (in lttng_metadata_printf() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-metadata.c:180)
DEBUG3 - 10:53:57.629900125 [9674/9735]: Session 0 found by id. (in session_find_by_id() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/session.c:952)
DEBUG3 - 10:53:57.629932500 [9674/9735]: Append to metadata: " trace_name = "" (in lttng_metadata_printf() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-metadata.c:180)
DEBUG3 - 10:53:57.629968500 [9674/9735]: Append to metadata: "a" (in lttng_metadata_printf() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-metadata.c:180)
DEBUG3 - 10:53:57.630000750 [9674/9735]: Append to metadata: "u" (in lttng_metadata_printf() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-metadata.c:180)
DEBUG3 - 10:53:57.630033750 [9674/9735]: Append to metadata: "t" (in lttng_metadata_printf() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-metadata.c:180)
DEBUG3 - 10:53:57.630064500 [9674/9735]: Append to metadata: "o" (in lttng_metadata_printf() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-metadata.c:180)
DEBUG3 - 10:53:57.630095000 [9674/9735]: Append to metadata: "";
" (in lttng_metadata_printf() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-metadata.c:180)
DEBUG3 - 10:53:57.630247750 [9674/9735]: Append to metadata: " trace_creation_datetime = "20210324T105310+0000";
hostname = "localhost";
" (in lttng_metadata_printf() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-metadata.c:180)
DEBUG3 - 10:53:57.630300500 [9674/9735]: Append to metadata: "};
" (in lttng_metadata_printf() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-metadata.c:180)
DEBUG3 - 10:53:57.630336125 [9674/9735]: Append to metadata: "clock {
name = "monotonic";
" (in lttng_metadata_printf() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-metadata.c:180)
DEBUG3 - 10:53:57.630525875 [9674/9735]: Append to metadata: " uuid = "a6fbd271-044e-43a6-9f79-552748ffff14";
" (in lttng_metadata_printf() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-metadata.c:180)
DEBUG3 - 10:53:57.630565250 [9674/9735]: Append to metadata: " description = "Monotonic Clock";
freq = 1000000000; /* Frequency, in Hz */
/* clock value offset from Epoch is: offset * (1/freq) */
offset = 1616581514203107500;
};
" (in lttng_metadata_printf() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-metadata.c:180)
DEBUG3 - 10:53:57.630602375 [9674/9735]: Append to metadata: "typealias integer {
size = 27; align = 1; signed = false;
map = clock.monotonic.value;
} := uint27_clock_monotonic_t;
typealias integer {
size = 32; align = 32; signed = false;
map = clock.monotonic.value;
} := uint32_clock_monotonic_t;
typealias integer {
size = 64; align = 64; signed = false;
map = clock.monotonic.value;
} := uint64_clock_monotonic_t;
" (in lttng_metadata_printf() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-metadata.c:180)
DEBUG3 - 10:53:57.630639500 [9674/9735]: 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 ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-metadata.c:180)
DEBUG3 - 10:53:57.630702875 [9674/9735]: 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(32);
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(16);
" (in lttng_metadata_printf() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-metadata.c:180)
DEBUG3 - 10:53:57.630798125 [9674/9735]: Buffer registry per UID adding to global registry with id: 0 (in buffer_reg_uid_add() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/buffer-registry.c:174)
DEBUG3 - 10:53:57.630847875 [9674/9735]: UST app buffer registry per UID created successfully (in setup_buffer_reg_uid() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:2094)
DEBUG2 - 10:53:57.631243375 [9674/9735]: UST app session created successfully with handle 1 (in find_or_create_ust_app_session() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:2206)
DEBUG3 - 10:53:57.631313625 [9674/9735]: Created hashtable size 4 at 0xffff90022100 of type 1 (in lttng_ht_new() at ../../../../lttng-tools-2.11.5/src/common/hashtable/hashtable.c:145)
DEBUG3 - 10:53:57.631353375 [9674/9735]: Created hashtable size 4 at 0xffff90023c20 of type 0 (in lttng_ht_new() at ../../../../lttng-tools-2.11.5/src/common/hashtable/hashtable.c:145)
DEBUG3 - 10:53:57.631388875 [9674/9735]: UST app channel channel0 allocated (in alloc_ust_app_channel() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:1074)
DEBUG2 - 10:53:57.631419250 [9674/9735]: UST app shadow copy of channel channel0 started (in shadow_copy_channel() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:1813)
DEBUG3 - 10:53:57.631450125 [9674/9735]: UST app shadow copy of channel channel0 done (in shadow_copy_channel() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:1839)
DEBUG1 - 10:53:57.631483250 [9674/9735]: UST app creating channel channel0 with per UID buffers (in create_channel_per_uid() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:2828)
DEBUG3 - 10:53:57.631514250 [9674/9735]: Buffer registry per UID find id: 0, ABI: 64, uid: 0 (in buffer_reg_uid_find() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/buffer-registry.c:203)
DEBUG2 - 10:53:57.631551000 [9674/9735]: UST app creating buffer registry channel for channel0 (in create_buffer_reg_channel() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:2667)
DEBUG3 - 10:53:57.631584125 [9674/9735]: Buffer registry channel create with key: 0 (in buffer_reg_channel_create() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/buffer-registry.c:380)
DEBUG3 - 10:53:57.631653000 [9674/9735]: Created hashtable size 4 at 0xffff90023f60 of type 0 (in lttng_ht_new() at ../../../../lttng-tools-2.11.5/src/common/hashtable/hashtable.c:145)
DEBUG3 - 10:53:57.631691000 [9674/9735]: Session 0 found by id. (in session_find_by_id() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/session.c:952)
DEBUG2 - 10:53:57.631727250 [9674/9735]: Asking UST consumer for channel (in ask_channel_creation() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-consumer.c:66)
DEBUG3 - 10:53:57.631796500 [9674/9735]: Consumer trace path relative to current trace chunk: "ust/uid/0/64-bit" (in setup_channel_trace_path() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/consumer.c:80)
DEBUG1 - 10:53:57.631832625 [9674/9735]: Creating trace chunk subdirectory "ust/uid/0/64-bit/index" (in lttng_trace_chunk_create_subdirectory() at ../../../lttng-tools-2.11.5/src/common/trace-chunk.c:775)
DEBUG3 - 10:53:57.631872500 [9674/9735]: mkdirat() recursive fd = 77, path = ust/uid/0/64-bit/index, mode = 504, uid = 0, gid = 0 (in run_as_mkdirat_recursive() at ../../../lttng-tools-2.11.5/src/common/runas.c:1394)
DEBUG1 - 10:53:57.631925000 [9674/9735]: Using run_as worker (in run_as() at ../../../lttng-tools-2.11.5/src/common/runas.c:1350)
DEBUG1 - 10:53:57.634255125 [9674/9735]: Adding new top-level directory "ust/uid/0/64-bit/index" to trace chunk "(unnamed)" (in add_top_level_directory_unique() at ../../../lttng-tools-2.11.5/src/common/trace-chunk.c:748)
DEBUG3 - 10:53:57.634346250 [9674/9735]: UST registry channel finding key 0 (in ust_registry_channel_find() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-registry.c:820)
DEBUG2 - 10:53:57.721382250 [9674/9735]: UST ask channel 1 successfully done with 4 stream(s) (in ask_channel_creation() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-consumer.c:187)
DEBUG2 - 10:53:57.722316875 [9674/9735]: UST app stream 1 received successfully (in ust_consumer_get_channel() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-consumer.c:309)
DEBUG2 - 10:53:57.722684625 [9674/9735]: UST app stream 2 received successfully (in ust_consumer_get_channel() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-consumer.c:309)
DEBUG2 - 10:53:57.723008625 [9674/9735]: UST app stream 3 received successfully (in ust_consumer_get_channel() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-consumer.c:309)
DEBUG2 - 10:53:57.723344500 [9674/9735]: UST app stream 4 received successfully (in ust_consumer_get_channel() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-consumer.c:309)
DEBUG3 - 10:53:57.723495500 [9674/9735]: UST app consumer has no more stream available (in ust_consumer_get_channel() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-consumer.c:293)
DEBUG2 - 10:53:57.723952875 [9674/9735]: UST app setup buffer registry channel for channel0 (in setup_buffer_reg_channel() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:2717)
DEBUG2 - 10:53:57.723991125 [9674/9735]: UST app setup buffer registry stream (in setup_buffer_reg_streams() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:2622)
DEBUG3 - 10:53:57.724025875 [9674/9735]: Buffer registry creating stream (in buffer_reg_stream_create() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/buffer-registry.c:410)
DEBUG3 - 10:53:57.724064500 [9674/9735]: Buffer registry creating stream (in buffer_reg_stream_create() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/buffer-registry.c:410)
DEBUG3 - 10:53:57.724096125 [9674/9735]: Buffer registry creating stream (in buffer_reg_stream_create() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/buffer-registry.c:410)
DEBUG3 - 10:53:57.724170000 [9674/9735]: Buffer registry creating stream (in buffer_reg_stream_create() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/buffer-registry.c:410)
DEBUG3 - 10:53:57.724206375 [9674/9735]: UST registry channel finding key 0 (in ust_registry_channel_find() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-registry.c:820)
DEBUG1 - 10:53:57.724287000 [9674/9735]: Beginning of waiter wait period (in lttng_waiter_wait() at ../../../lttng-tools-2.11.5/src/common/waiter.c:58)
DEBUG1 - 10:53:57.724383500 [9674/9732]: [notification-thread] Poll wait returned (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:555)
DEBUG1 - 10:53:57.724431000 [9674/9732]: [notification-thread] Handling fd (34) activity (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:573)
DEBUG1 - 10:53:57.724473750 [9674/9732]: [notification-thread] Received add channel command (in handle_notification_thread_command() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread-events.c:2306)
DEBUG1 - 10:53:57.724507250 [9674/9732]: [notification-thread] Adding channel channel0 from session auto-20210324-105310, channel key = 1 in user space domain (in handle_notification_thread_command_add_channel() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread-events.c:1560)
DEBUG1 - 10:53:57.724555125 [9674/9732]: [notification-thread] Found 0 triggers that apply to newly created session (in lttng_session_trigger_list_build() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread-events.c:1478)
DEBUG1 - 10:53:57.724692375 [9674/9732]: [notification-thread] Found 0 triggers that apply to newly added channel (in handle_notification_thread_command_add_channel() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread-events.c:1602)
DEBUG1 - 10:53:57.724747500 [9674/9732]: [notification-thread] Entering poll wait (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:553)
DEBUG1 - 10:53:57.724802000 [9674/9735]: End of waiter wait period (in lttng_waiter_wait() at ../../../lttng-tools-2.11.5/src/common/waiter.c:101)
DEBUG1 - 10:53:57.724834375 [9674/9735]: UST app sending buffer registry channel to ust sock 57 (in send_channel_uid_to_ust() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:2753)
DEBUG2 - 10:53:57.724877500 [9674/9735]: UST app send channel to sock 57 pid 643 (name: channel0, key: 0) (in ust_consumer_send_channel_to_ust() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-consumer.c:414)
DEBUG2 - 10:53:57.725409250 [9674/9735]: UST consumer send stream to app 57 (in ust_consumer_send_stream_to_ust() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-consumer.c:378)
DEBUG2 - 10:53:57.727955000 [9674/9735]: UST consumer send stream to app 57 (in ust_consumer_send_stream_to_ust() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-consumer.c:378)
DEBUG2 - 10:53:57.730507625 [9674/9735]: UST consumer send stream to app 57 (in ust_consumer_send_stream_to_ust() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-consumer.c:378)
DEBUG2 - 10:53:57.732989000 [9674/9735]: UST consumer send stream to app 57 (in ust_consumer_send_stream_to_ust() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-consumer.c:378)
DEBUG3 - 10:53:57.735545875 [9674/9735]: UST app event lttng_ust_tracef:* allocated (in alloc_ust_app_event() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:1130)
DEBUG2 - 10:53:57.735832875 [9674/9735]: UST app event lttng_ust_tracef:* created successfully for pid:643 (in create_ust_event() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:1717)
DEBUG2 - 10:53:57.736052750 [9674/9735]: UST app event lttng_ust_tracef:* enabled successfully for app (pid: 643) (in enable_ust_event() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:1620)
DEBUG2 - 10:53:57.736089375 [9674/9735]: UST app create event lttng_ust_tracef:* for PID 643 completed (in create_ust_app_event() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:3176)
DEBUG1 - 10:53:57.736151375 [9674/9735]: Starting tracing for ust app pid 643 (in ust_app_start_trace() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:4407)
DEBUG3 - 10:53:57.736202250 [9674/9735]: Buffer registry per UID find id: 0, ABI: 64, uid: 0 (in buffer_reg_uid_find() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/buffer-registry.c:203)
DEBUG3 - 10:53:57.736251125 [9674/9735]: Created hashtable size 4 at 0xffff90025d40 of type 1 (in lttng_ht_new() at ../../../../lttng-tools-2.11.5/src/common/hashtable/hashtable.c:145)
DEBUG3 - 10:53:57.736287375 [9674/9735]: Created hashtable size 4 at 0xffff90026180 of type 0 (in lttng_ht_new() at ../../../../lttng-tools-2.11.5/src/common/hashtable/hashtable.c:145)
DEBUG3 - 10:53:57.736318500 [9674/9735]: UST app channel metadata allocated (in alloc_ust_app_channel() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:1074)
DEBUG3 - 10:53:57.736352500 [9674/9735]: Session 0 found by id. (in session_find_by_id() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/session.c:952)
DEBUG2 - 10:53:57.736387625 [9674/9735]: Asking UST consumer for channel (in ask_channel_creation() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-consumer.c:66)
DEBUG3 - 10:53:57.736425250 [9674/9735]: Consumer trace path relative to current trace chunk: "ust/uid/0/64-bit" (in setup_channel_trace_path() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/consumer.c:80)
DEBUG1 - 10:53:57.736568000 [9674/9735]: Creating trace chunk subdirectory "ust/uid/0/64-bit/index" (in lttng_trace_chunk_create_subdirectory() at ../../../lttng-tools-2.11.5/src/common/trace-chunk.c:775)
DEBUG3 - 10:53:57.736601500 [9674/9735]: mkdirat() recursive fd = 77, path = ust/uid/0/64-bit/index, mode = 504, uid = 0, gid = 0 (in run_as_mkdirat_recursive() at ../../../lttng-tools-2.11.5/src/common/runas.c:1394)
DEBUG1 - 10:53:57.736641625 [9674/9735]: Using run_as worker (in run_as() at ../../../lttng-tools-2.11.5/src/common/runas.c:1350)
DEBUG2 - 10:53:57.739092750 [9674/9735]: UST ask channel 2 successfully done with 1 stream(s) (in ask_channel_creation() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-consumer.c:187)
DEBUG2 - 10:53:57.739229500 [9674/9735]: Consumer setup metadata channel key 2 (in consumer_setup_metadata() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/consumer.c:1431)
DEBUG2 - 10:53:57.739633875 [9674/9735]: UST metadata with key 2 created for app pid 643 (in create_ust_app_metadata() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:3283)
DEBUG3 - 10:53:57.739676875 [9674/9735]: UST app deleting channel metadata (in delete_ust_app_channel() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:469)
DEBUG3 - 10:53:57.739976250 [9674/9739]: [ust-thread] Manage notify return from poll on 4 fds (in thread_application_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notify-apps.c:90)
DEBUG3 - 10:53:57.740024875 [9674/9739]: UST app receiving notify from sock 58 (in ust_app_recv_notify() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:5695)
DEBUG2 - 10:53:57.740069125 [9674/9739]: UST app ustctl register channel received (in ust_app_recv_notify() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:5749)
DEBUG3 - 10:53:57.740203125 [9674/9739]: Buffer registry per UID find id: 0, ABI: 64, uid: 0 (in buffer_reg_uid_find() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/buffer-registry.c:203)
DEBUG3 - 10:53:57.740282375 [9674/9739]: UST registry channel finding key 0 (in ust_registry_channel_find() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-registry.c:820)
DEBUG3 - 10:53:57.740327875 [9674/9739]: Append to metadata: "stream {
id = 0;
event.header := struct event_header_large;
packet.context := struct packet_context;
" (in lttng_metadata_printf() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-metadata.c:180)
DEBUG3 - 10:53:57.740366000 [9674/9739]: Append to metadata: "};
" (in lttng_metadata_printf() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-metadata.c:180)
DEBUG3 - 10:53:57.740398875 [9674/9739]: UST app replying to register channel key 0 with id 0, type: 2, ret: 0 (in reply_ust_register_channel() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:5473)
DEBUG3 - 10:53:57.740680125 [9674/9739]: [ust-thread] Manage notify polling (in thread_application_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notify-apps.c:84)
DEBUG3 - 10:53:57.740724750 [9674/9739]: [ust-thread] Manage notify return from poll on 4 fds (in thread_application_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notify-apps.c:90)
DEBUG3 - 10:53:57.740756125 [9674/9739]: UST app receiving notify from sock 58 (in ust_app_recv_notify() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:5695)
DEBUG2 - 10:53:57.740793625 [9674/9739]: UST app ustctl register event received (in ust_app_recv_notify() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:5715)
DEBUG3 - 10:53:57.741021875 [9674/9739]: Buffer registry per UID find id: 0, ABI: 64, uid: 0 (in buffer_reg_uid_find() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/buffer-registry.c:203)
DEBUG3 - 10:53:57.741061625 [9674/9739]: UST registry channel finding key 0 (in ust_registry_channel_find() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-registry.c:820)
DEBUG3 - 10:53:57.741310375 [9674/9739]: UST registry creating event with event: lttng_ust_tracef:event, sig: const char *, msg, unsigned int, len, void *, ip, id: 0, chan_objd: 2, sess_objd: 1, chan_id: 0 (in ust_registry_create_event() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-registry.c:447)
DEBUG3 - 10:53:57.741376375 [9674/9739]: Append to metadata: "event {
name = "lttng_ust_tracef:event";
id = 0;
stream_id = 0;
" (in lttng_metadata_printf() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-metadata.c:180)
DEBUG3 - 10:53:57.741410625 [9674/9739]: Append to metadata: " loglevel = 14;
" (in lttng_metadata_printf() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-metadata.c:180)
DEBUG3 - 10:53:57.741443250 [9674/9739]: Append to metadata: " fields := struct {
" (in lttng_metadata_printf() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-metadata.c:180)
DEBUG3 - 10:53:57.741474625 [9674/9739]: Append to metadata: " " (in lttng_metadata_printf() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-metadata.c:180)
DEBUG3 - 10:53:57.741521500 [9674/9739]: Append to metadata: " " (in lttng_metadata_printf() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-metadata.c:180)
DEBUG3 - 10:53:57.741557375 [9674/9739]: Append to metadata: "integer { size = 32; align = 32; signed = 0; encoding = none; base = 10; } __msg_length;
" (in lttng_metadata_printf() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-metadata.c:180)
DEBUG3 - 10:53:57.741587875 [9674/9739]: Append to metadata: " " (in lttng_metadata_printf() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-metadata.c:180)
DEBUG3 - 10:53:57.741618375 [9674/9739]: Append to metadata: " " (in lttng_metadata_printf() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-metadata.c:180)
DEBUG3 - 10:53:57.741651500 [9674/9739]: Append to metadata: "integer { size = 8; align = 8; signed = 0; encoding = UTF8; base = 10; } _msg[ __msg_length ];
" (in lttng_metadata_printf() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-metadata.c:180)
DEBUG3 - 10:53:57.741682500 [9674/9739]: Append to metadata: " };
};
" (in lttng_metadata_printf() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-metadata.c:180)
DEBUG3 - 10:53:57.751284875 [9674/9739]: UST registry event lttng_ust_tracef:event with id 0 added successfully (in add_event_ust_registry() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:5588)
DEBUG3 - 10:53:57.751395250 [9674/9739]: [ust-thread] Manage notify polling (in thread_application_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notify-apps.c:84)
DEBUG2 - 10:53:57.756290000 [9674/9735]: UST app global update for app sock 59 for session id 0 (in ust_app_global_update() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:5190)
DEBUG2 - 10:53:57.756391625 [9674/9735]: UST app pid: 635 session id 0 not found, creating it (in find_or_create_ust_app_session() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:2130)
DEBUG3 - 10:53:57.756514000 [9674/9735]: Created hashtable size 4 at 0xffff900265a0 of type 0 (in lttng_ht_new() at ../../../../lttng-tools-2.11.5/src/common/hashtable/hashtable.c:145)
DEBUG2 - 10:53:57.756602500 [9674/9735]: Shadow copy of session handle -1 (in shadow_copy_session() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:1856)
DEBUG3 - 10:53:57.756688125 [9674/9735]: Buffer registry per UID find id: 0, ABI: 64, uid: 0 (in buffer_reg_uid_find() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/buffer-registry.c:203)
DEBUG2 - 10:53:57.757034750 [9674/9735]: UST app session created successfully with handle 1 (in find_or_create_ust_app_session() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:2206)
DEBUG3 - 10:53:57.757090000 [9674/9735]: Created hashtable size 4 at 0xffff90026d80 of type 1 (in lttng_ht_new() at ../../../../lttng-tools-2.11.5/src/common/hashtable/hashtable.c:145)
DEBUG3 - 10:53:57.757163625 [9674/9735]: Created hashtable size 4 at 0xffff900271c0 of type 0 (in lttng_ht_new() at ../../../../lttng-tools-2.11.5/src/common/hashtable/hashtable.c:145)
DEBUG3 - 10:53:57.757305625 [9674/9735]: UST app channel channel0 allocated (in alloc_ust_app_channel() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:1074)
DEBUG2 - 10:53:57.757339250 [9674/9735]: UST app shadow copy of channel channel0 started (in shadow_copy_channel() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:1813)
DEBUG3 - 10:53:57.757373625 [9674/9735]: UST app shadow copy of channel channel0 done (in shadow_copy_channel() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:1839)
DEBUG1 - 10:53:57.757408125 [9674/9735]: UST app creating channel channel0 with per UID buffers (in create_channel_per_uid() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:2828)
DEBUG3 - 10:53:57.757438750 [9674/9735]: Buffer registry per UID find id: 0, ABI: 64, uid: 0 (in buffer_reg_uid_find() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/buffer-registry.c:203)
DEBUG1 - 10:53:57.757473250 [9674/9735]: UST app sending buffer registry channel to ust sock 59 (in send_channel_uid_to_ust() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:2753)
DEBUG2 - 10:53:57.757515125 [9674/9735]: UST app send channel to sock 59 pid 635 (name: channel0, key: 0) (in ust_consumer_send_channel_to_ust() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-consumer.c:414)
DEBUG2 - 10:53:57.757905125 [9674/9735]: UST consumer send stream to app 59 (in ust_consumer_send_stream_to_ust() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-consumer.c:378)
DEBUG2 - 10:53:57.760580875 [9674/9735]: UST consumer send stream to app 59 (in ust_consumer_send_stream_to_ust() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-consumer.c:378)
DEBUG2 - 10:53:57.763087375 [9674/9735]: UST consumer send stream to app 59 (in ust_consumer_send_stream_to_ust() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-consumer.c:378)
DEBUG2 - 10:53:57.765692000 [9674/9735]: UST consumer send stream to app 59 (in ust_consumer_send_stream_to_ust() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-consumer.c:378)
DEBUG3 - 10:53:57.768404875 [9674/9735]: UST app event lttng_ust_tracef:* allocated (in alloc_ust_app_event() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:1130)
DEBUG2 - 10:53:57.768789500 [9674/9735]: UST app event lttng_ust_tracef:* created successfully for pid:635 (in create_ust_event() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:1717)
DEBUG2 - 10:53:57.769031500 [9674/9735]: UST app event lttng_ust_tracef:* enabled successfully for app (pid: 635) (in enable_ust_event() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:1620)
DEBUG2 - 10:53:57.769071625 [9674/9735]: UST app create event lttng_ust_tracef:* for PID 635 completed (in create_ust_app_event() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:3176)
DEBUG1 - 10:53:57.769187625 [9674/9735]: Starting tracing for ust app pid 635 (in ust_app_start_trace() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:4407)
DEBUG3 - 10:53:57.769243250 [9674/9735]: Buffer registry per UID find id: 0, ABI: 64, uid: 0 (in buffer_reg_uid_find() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/buffer-registry.c:203)
DEBUG3 - 10:53:57.769472625 [9674/9739]: [ust-thread] Manage notify return from poll on 4 fds (in thread_application_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notify-apps.c:90)
DEBUG3 - 10:53:57.769509500 [9674/9739]: UST app receiving notify from sock 60 (in ust_app_recv_notify() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:5695)
DEBUG2 - 10:53:57.769549875 [9674/9739]: UST app ustctl register channel received (in ust_app_recv_notify() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:5749)
DEBUG3 - 10:53:57.769604500 [9674/9739]: Buffer registry per UID find id: 0, ABI: 64, uid: 0 (in buffer_reg_uid_find() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/buffer-registry.c:203)
DEBUG3 - 10:53:57.769743125 [9674/9739]: UST registry channel finding key 0 (in ust_registry_channel_find() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-registry.c:820)
DEBUG3 - 10:53:57.769777750 [9674/9739]: UST app replying to register channel key 0 with id 0, type: 2, ret: 0 (in reply_ust_register_channel() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:5473)
DEBUG3 - 10:53:57.769872000 [9674/9739]: [ust-thread] Manage notify polling (in thread_application_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notify-apps.c:84)
DEBUG3 - 10:53:57.770077500 [9674/9739]: [ust-thread] Manage notify return from poll on 4 fds (in thread_application_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notify-apps.c:90)
DEBUG3 - 10:53:57.770141375 [9674/9739]: UST app receiving notify from sock 60 (in ust_app_recv_notify() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:5695)
DEBUG2 - 10:53:57.770196000 [9674/9739]: UST app ustctl register event received (in ust_app_recv_notify() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:5715)
DEBUG3 - 10:53:57.770432750 [9674/9739]: Buffer registry per UID find id: 0, ABI: 64, uid: 0 (in buffer_reg_uid_find() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/buffer-registry.c:203)
DEBUG3 - 10:53:57.770473250 [9674/9739]: UST registry channel finding key 0 (in ust_registry_channel_find() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-registry.c:820)
DEBUG3 - 10:53:57.770512500 [9674/9739]: UST registry creating event with event: lttng_ust_tracef:event, sig: const char *, msg, unsigned int, len, void *, ip, id: 0, chan_objd: 2, sess_objd: 1, chan_id: 0 (in ust_registry_create_event() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-registry.c:447)
DEBUG3 - 10:53:57.770591125 [9674/9739]: UST registry event lttng_ust_tracef:event with id 0 added successfully (in add_event_ust_registry() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:5588)
DEBUG3 - 10:53:57.770640250 [9674/9739]: [ust-thread] Manage notify polling (in thread_application_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notify-apps.c:84)
DEBUG3 - 10:53:57.785739500 [9674/9676]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:135)
DEBUG3 - 10:53:57.785959875 [9674/9676]: [ht-thread] Polling. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:132)
DEBUG3 - 10:53:57.786010375 [9674/9676]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:135)
DEBUG3 - 10:53:57.786104125 [9674/9676]: [ht-thread] Polling. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:132)
DEBUG1 - 10:53:57.786206125 [9674/9735]: Sending response (size: 20, retcode: Success (10)) (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2236)
DEBUG1 - 10:53:57.786381500 [9674/9735]: Clean command context structure (in clean_command_ctx() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:659)
DEBUG1 - 10:53:57.786418750 [9674/9735]: Accepting client command ... (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2087)
DEBUG1 - 10:53:58.721395750 [9674/9732]: [notification-thread] Poll wait returned (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:555)
DEBUG1 - 10:53:58.721542125 [9674/9732]: [notification-thread] Handling fd (17) activity (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:573)
DEBUG1 - 10:53:58.721610750 [9674/9732]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session auto-20210324-105310 (highest usage = 84, lowest usage = 84, total consumed = 0) (in handle_notification_thread_channel_sample() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread-events.c:3264)
DEBUG1 - 10:53:58.721794125 [9674/9732]: [notification-thread] Entering poll wait (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:553)
DEBUG1 - 10:53:59.721326875 [9674/9732]: [notification-thread] Poll wait returned (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:555)
DEBUG1 - 10:53:59.721490375 [9674/9732]: [notification-thread] Handling fd (17) activity (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:573)
DEBUG1 - 10:53:59.721553625 [9674/9732]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session auto-20210324-105310 (highest usage = 84, lowest usage = 84, total consumed = 0) (in handle_notification_thread_channel_sample() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread-events.c:3264)
DEBUG1 - 10:53:59.721596625 [9674/9732]: [notification-thread] Entering poll wait (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:553)
DEBUG1 - 10:54:00.721369125 [9674/9732]: [notification-thread] Poll wait returned (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:555)
DEBUG1 - 10:54:00.721525375 [9674/9732]: [notification-thread] Handling fd (17) activity (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:573)
DEBUG1 - 10:54:00.721605750 [9674/9732]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session auto-20210324-105310 (highest usage = 84, lowest usage = 84, total consumed = 0) (in handle_notification_thread_channel_sample() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread-events.c:3264)
DEBUG1 - 10:54:00.721662375 [9674/9732]: [notification-thread] Entering poll wait (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:553)
DEBUG1 - 10:54:01.721374875 [9674/9732]: [notification-thread] Poll wait returned (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:555)
DEBUG1 - 10:54:01.721532000 [9674/9732]: [notification-thread] Handling fd (17) activity (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:573)
DEBUG1 - 10:54:01.721611000 [9674/9732]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session auto-20210324-105310 (highest usage = 84, lowest usage = 84, total consumed = 0) (in handle_notification_thread_channel_sample() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread-events.c:3264)
DEBUG1 - 10:54:01.721667750 [9674/9732]: [notification-thread] Entering poll wait (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:553)
DEBUG1 - 10:54:02.721366250 [9674/9732]: [notification-thread] Poll wait returned (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:555)
DEBUG1 - 10:54:02.721542500 [9674/9732]: [notification-thread] Handling fd (17) activity (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:573)
DEBUG1 - 10:54:02.721625125 [9674/9732]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session auto-20210324-105310 (highest usage = 84, lowest usage = 84, total consumed = 0) (in handle_notification_thread_channel_sample() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread-events.c:3264)
DEBUG1 - 10:54:02.721683625 [9674/9732]: [notification-thread] Entering poll wait (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:553)
DEBUG1 - 10:54:03.721368000 [9674/9732]: [notification-thread] Poll wait returned (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:555)
DEBUG1 - 10:54:03.721538875 [9674/9732]: [notification-thread] Handling fd (17) activity (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:573)
DEBUG1 - 10:54:03.721609750 [9674/9732]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session auto-20210324-105310 (highest usage = 84, lowest usage = 84, total consumed = 0) (in handle_notification_thread_channel_sample() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread-events.c:3264)
DEBUG1 - 10:54:03.721659625 [9674/9732]: [notification-thread] Entering poll wait (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:553)
DEBUG1 - 10:54:04.721369250 [9674/9732]: [notification-thread] Poll wait returned (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:555)
DEBUG1 - 10:54:04.721514625 [9674/9732]: [notification-thread] Handling fd (17) activity (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:573)
DEBUG1 - 10:54:04.721588125 [9674/9732]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session auto-20210324-105310 (highest usage = 84, lowest usage = 84, total consumed = 0) (in handle_notification_thread_channel_sample() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread-events.c:3264)
DEBUG1 - 10:54:04.721640125 [9674/9732]: [notification-thread] Entering poll wait (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:553)
DEBUG1 - 10:54:05.721367125 [9674/9732]: [notification-thread] Poll wait returned (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:555)
DEBUG1 - 10:54:05.721513125 [9674/9732]: [notification-thread] Handling fd (17) activity (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:573)
DEBUG1 - 10:54:05.721583250 [9674/9732]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session auto-20210324-105310 (highest usage = 84, lowest usage = 84, total consumed = 0) (in handle_notification_thread_channel_sample() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread-events.c:3264)
DEBUG1 - 10:54:05.721632750 [9674/9732]: [notification-thread] Entering poll wait (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:553)
DEBUG1 - 10:54:06.721364250 [9674/9732]: [notification-thread] Poll wait returned (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:555)
DEBUG1 - 10:54:06.721514875 [9674/9732]: [notification-thread] Handling fd (17) activity (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:573)
DEBUG1 - 10:54:06.721585250 [9674/9732]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session auto-20210324-105310 (highest usage = 84, lowest usage = 84, total consumed = 0) (in handle_notification_thread_channel_sample() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread-events.c:3264)
DEBUG1 - 10:54:06.721634375 [9674/9732]: [notification-thread] Entering poll wait (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:553)
DEBUG1 - 10:54:07.721374625 [9674/9732]: [notification-thread] Poll wait returned (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:555)
DEBUG1 - 10:54:07.721522500 [9674/9732]: [notification-thread] Handling fd (17) activity (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:573)
DEBUG1 - 10:54:07.721743500 [9674/9732]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session auto-20210324-105310 (highest usage = 84, lowest usage = 84, total consumed = 0) (in handle_notification_thread_channel_sample() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread-events.c:3264)
DEBUG1 - 10:54:07.721793500 [9674/9732]: [notification-thread] Entering poll wait (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:553)
DEBUG1 - 10:54:08.721367750 [9674/9732]: [notification-thread] Poll wait returned (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:555)
DEBUG1 - 10:54:08.724615000 [9674/9732]: [notification-thread] Handling fd (17) activity (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:573)
DEBUG1 - 10:54:08.724730375 [9674/9732]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session auto-20210324-105310 (highest usage = 84, lowest usage = 84, total consumed = 0) (in handle_notification_thread_channel_sample() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread-events.c:3264)
DEBUG1 - 10:54:08.724781000 [9674/9732]: [notification-thread] Entering poll wait (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:553)
DEBUG1 - 10:54:09.721362875 [9674/9732]: [notification-thread] Poll wait returned (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:555)
DEBUG1 - 10:54:09.721509750 [9674/9732]: [notification-thread] Handling fd (17) activity (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:573)
DEBUG1 - 10:54:09.721582625 [9674/9732]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session auto-20210324-105310 (highest usage = 84, lowest usage = 84, total consumed = 0) (in handle_notification_thread_channel_sample() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread-events.c:3264)
DEBUG1 - 10:54:09.721633625 [9674/9732]: [notification-thread] Entering poll wait (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:553)
DEBUG1 - 10:54:10.721364250 [9674/9732]: [notification-thread] Poll wait returned (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:555)
DEBUG1 - 10:54:10.721510500 [9674/9732]: [notification-thread] Handling fd (17) activity (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:573)
DEBUG1 - 10:54:10.721581875 [9674/9732]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session auto-20210324-105310 (highest usage = 84, lowest usage = 84, total consumed = 0) (in handle_notification_thread_channel_sample() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread-events.c:3264)
DEBUG1 - 10:54:10.721629250 [9674/9732]: [notification-thread] Entering poll wait (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:553)
DEBUG1 - 10:54:11.721360250 [9674/9732]: [notification-thread] Poll wait returned (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:555)
DEBUG1 - 10:54:11.721507125 [9674/9732]: [notification-thread] Handling fd (17) activity (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:573)
DEBUG1 - 10:54:11.721582250 [9674/9732]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session auto-20210324-105310 (highest usage = 84, lowest usage = 84, total consumed = 0) (in handle_notification_thread_channel_sample() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread-events.c:3264)
DEBUG1 - 10:54:11.721773750 [9674/9732]: [notification-thread] Entering poll wait (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:553)
DEBUG1 - 10:54:12.721362500 [9674/9732]: [notification-thread] Poll wait returned (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:555)
DEBUG1 - 10:54:12.721514000 [9674/9732]: [notification-thread] Handling fd (17) activity (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:573)
DEBUG1 - 10:54:12.721584750 [9674/9732]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session auto-20210324-105310 (highest usage = 84, lowest usage = 84, total consumed = 0) (in handle_notification_thread_channel_sample() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread-events.c:3264)
DEBUG1 - 10:54:12.721638875 [9674/9732]: [notification-thread] Entering poll wait (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:553)
DEBUG1 - 10:54:13.721362750 [9674/9732]: [notification-thread] Poll wait returned (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:555)
DEBUG1 - 10:54:13.721507875 [9674/9732]: [notification-thread] Handling fd (17) activity (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:573)
DEBUG1 - 10:54:13.721579500 [9674/9732]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session auto-20210324-105310 (highest usage = 84, lowest usage = 84, total consumed = 0) (in handle_notification_thread_channel_sample() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread-events.c:3264)
DEBUG1 - 10:54:13.721627625 [9674/9732]: [notification-thread] Entering poll wait (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:553)
DEBUG1 - 10:54:14.721365375 [9674/9732]: [notification-thread] Poll wait returned (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:555)
DEBUG1 - 10:54:14.721543000 [9674/9732]: [notification-thread] Handling fd (17) activity (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:573)
DEBUG1 - 10:54:14.721616125 [9674/9732]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session auto-20210324-105310 (highest usage = 84, lowest usage = 84, total consumed = 0) (in handle_notification_thread_channel_sample() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread-events.c:3264)
DEBUG1 - 10:54:14.721665125 [9674/9732]: [notification-thread] Entering poll wait (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:553)
DEBUG1 - 10:54:15.721361250 [9674/9732]: [notification-thread] Poll wait returned (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:555)
DEBUG1 - 10:54:15.721508125 [9674/9732]: [notification-thread] Handling fd (17) activity (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:573)
DEBUG1 - 10:54:15.721580250 [9674/9732]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session auto-20210324-105310 (highest usage = 84, lowest usage = 84, total consumed = 0) (in handle_notification_thread_channel_sample() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread-events.c:3264)
DEBUG1 - 10:54:15.721630750 [9674/9732]: [notification-thread] Entering poll wait (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:553)
DEBUG1 - 10:54:16.325001500 [9674/9735]: Wait for client response (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2129)
DEBUG1 - 10:54:16.325272375 [9674/9735]: Receiving data from client ... (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2174)
DEBUG1 - 10:54:16.325992875 [9674/9735]: Processing client command 13 (in process_client_msg() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:723)
DEBUG1 - 10:54:16.326060250 [9674/9735]: Counting number of available session for UID 0 GID 0 (in lttng_sessions_count() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:521)
DEBUG1 - 10:54:16.326099500 [9674/9735]: Getting all available session for UID 0 GID 0 (in cmd_list_lttng_sessions() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/cmd.c:3697)
DEBUG1 - 10:54:16.326233000 [9674/9735]: Sending response (size: 4412, retcode: Success (10)) (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2236)
DEBUG1 - 10:54:16.326385500 [9674/9735]: Clean command context structure (in clean_command_ctx() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:659)
DEBUG1 - 10:54:16.326420375 [9674/9735]: Accepting client command ... (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2087)
DEBUG1 - 10:54:16.328628125 [9674/9735]: Wait for client response (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2129)
DEBUG1 - 10:54:16.328839750 [9674/9735]: Receiving data from client ... (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2174)
DEBUG1 - 10:54:16.329516000 [9674/9735]: Processing client command 17 (in process_client_msg() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:723)
DEBUG1 - 10:54:16.329581625 [9674/9735]: Getting session auto-20210324-105310 by name (in process_client_msg() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:819)
DEBUG2 - 10:54:16.329619375 [9674/9735]: Trying to find session by name auto-20210324-105310 (in session_find_by_name() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/session.c:914)
DEBUG1 - 10:54:16.329656625 [9674/9735]: Begin stop session auto-20210324-105310 (id 0) (in cmd_stop_trace() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/cmd.c:2725)
DEBUG1 - 10:54:16.329690375 [9674/9735]: Stopping all UST traces (in ust_app_stop_trace_all() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:4967)
DEBUG1 - 10:54:16.329725625 [9674/9735]: Stopping tracing for ust app pid 643 (in ust_app_stop_trace() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:4504)
DEBUG3 - 10:54:16.330269375 [9674/9735]: Buffer registry per UID find id: 0, ABI: 64, uid: 0 (in buffer_reg_uid_find() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/buffer-registry.c:203)
DEBUG2 - 10:54:16.330338000 [9674/9735]: Consumer push metadata to consumer socket 74 (in consumer_push_metadata() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/consumer.c:1466)
DEBUG3 - 10:54:16.330605875 [9674/9735]: Consumer pushing metadata on sock 74 of len 2834 (in consumer_push_metadata() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/consumer.c:1483)
DEBUG1 - 10:54:16.332052250 [9674/9735]: Stopping tracing for ust app pid 635 (in ust_app_stop_trace() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:4504)
DEBUG3 - 10:54:16.333016250 [9674/9735]: Buffer registry per UID find id: 0, ABI: 64, uid: 0 (in buffer_reg_uid_find() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/buffer-registry.c:203)
DEBUG3 - 10:54:16.333089250 [9674/9735]: No metadata to push for metadata key 2 (in ust_app_push_metadata() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:594)
DEBUG1 - 10:54:16.333159500 [9674/9735]: Flushing session buffers for all ust apps (in ust_app_flush_session() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:4661)
DEBUG2 - 10:54:16.333306875 [9674/9735]: Consumer flush channel key 1 (in consumer_flush_channel() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/consumer.c:1332)
DEBUG3 - 10:54:16.337231375 [9674/9735]: No metadata to push for metadata key 2 (in ust_app_push_metadata() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:594)
DEBUG1 - 10:54:16.337318625 [9674/9735]: Sending response (size: 20, retcode: Success (10)) (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2236)
DEBUG1 - 10:54:16.337454500 [9674/9735]: Clean command context structure (in clean_command_ctx() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:659)
DEBUG1 - 10:54:16.337490500 [9674/9735]: Accepting client command ... (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2087)
DEBUG1 - 10:54:16.338056500 [9674/9735]: Wait for client response (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2129)
DEBUG1 - 10:54:16.338269750 [9674/9735]: Receiving data from client ... (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2174)
DEBUG1 - 10:54:16.338488750 [9674/9735]: Processing client command 24 (in process_client_msg() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:723)
DEBUG1 - 10:54:16.338524500 [9674/9735]: Getting session auto-20210324-105310 by name (in process_client_msg() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:819)
DEBUG2 - 10:54:16.338557125 [9674/9735]: Trying to find session by name auto-20210324-105310 (in session_find_by_name() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/session.c:914)
DEBUG1 - 10:54:16.338590875 [9674/9735]: Data pending for session auto-20210324-105310 (in cmd_data_pending() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/cmd.c:3758)
DEBUG3 - 10:54:16.338622000 [9674/9735]: Consumer data pending for id 0 (in consumer_is_data_pending() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/consumer.c:1276)
DEBUG1 - 10:54:16.338892000 [9674/9735]: Consumer data is NOT pending for session id 0 (in consumer_is_data_pending() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/consumer.c:1311)
DEBUG1 - 10:54:16.338938750 [9674/9735]: Sending response (size: 21, retcode: Success (10)) (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2236)
DEBUG1 - 10:54:16.339056375 [9674/9735]: Clean command context structure (in clean_command_ctx() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:659)
DEBUG1 - 10:54:16.339091625 [9674/9735]: Accepting client command ... (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2087)
DEBUG1 - 10:54:16.339516000 [9674/9735]: Wait for client response (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2129)
DEBUG1 - 10:54:16.339664500 [9674/9735]: Receiving data from client ... (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2174)
DEBUG1 - 10:54:16.339741000 [9674/9735]: Processing client command 13 (in process_client_msg() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:723)
DEBUG1 - 10:54:16.339776750 [9674/9735]: Counting number of available session for UID 0 GID 0 (in lttng_sessions_count() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:521)
DEBUG1 - 10:54:16.339812375 [9674/9735]: Getting all available session for UID 0 GID 0 (in cmd_list_lttng_sessions() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/cmd.c:3697)
DEBUG1 - 10:54:16.339853875 [9674/9735]: Sending response (size: 4412, retcode: Success (10)) (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2236)
DEBUG1 - 10:54:16.339977625 [9674/9735]: Clean command context structure (in clean_command_ctx() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:659)
DEBUG1 - 10:54:16.340098750 [9674/9735]: Accepting client command ... (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2087)
DEBUG1 - 10:54:16.340639750 [9674/9735]: Wait for client response (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2129)
DEBUG1 - 10:54:16.340758500 [9674/9735]: Receiving data from client ... (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2174)
DEBUG1 - 10:54:16.340844000 [9674/9735]: Processing client command 11 (in process_client_msg() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:723)
DEBUG1 - 10:54:16.340880125 [9674/9735]: Getting session auto-20210324-105310 by name (in process_client_msg() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:819)
DEBUG2 - 10:54:16.340916750 [9674/9735]: Trying to find session by name auto-20210324-105310 (in session_find_by_name() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/session.c:914)
DEBUG3 - 10:54:16.340956000 [9674/9735]: Listing domains found UST global domain (in cmd_list_domains() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/cmd.c:3498)
DEBUG1 - 10:54:16.341001750 [9674/9735]: Sending response (size: 328, retcode: Success (10)) (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2236)
DEBUG1 - 10:54:16.341228250 [9674/9735]: Clean command context structure (in clean_command_ctx() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:659)
DEBUG1 - 10:54:16.341278500 [9674/9735]: Accepting client command ... (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2087)
DEBUG1 - 10:54:16.341704500 [9674/9735]: Wait for client response (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2129)
DEBUG1 - 10:54:16.341834000 [9674/9735]: Receiving data from client ... (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2174)
DEBUG1 - 10:54:16.341920625 [9674/9735]: Processing client command 10 (in process_client_msg() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:723)
DEBUG1 - 10:54:16.341957625 [9674/9735]: Getting session auto-20210324-105310 by name (in process_client_msg() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:819)
DEBUG2 - 10:54:16.341989375 [9674/9735]: Trying to find session by name auto-20210324-105310 (in session_find_by_name() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/session.c:914)
DEBUG3 - 10:54:16.342029000 [9674/9735]: Consumer socket created (fd: 74) and added to output (in consumer_create_socket() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/consumer.c:358)
DEBUG1 - 10:54:16.342064500 [9674/9735]: Setting relayd for session auto-20210324-105310 (in cmd_setup_relayd() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/cmd.c:1185)
DEBUG3 - 10:54:16.342102375 [9674/9735]: Number of UST global channels 1 (in cmd_list_channels() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/cmd.c:3581)
DEBUG1 - 10:54:16.342244125 [9674/9735]: Listing channels for session auto-20210324-105310 (in list_lttng_channels() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/cmd.c:301)
DEBUG3 - 10:54:16.342280250 [9674/9735]: Consumer discarded events id 0 (in consumer_get_discarded_events() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/consumer.c:1581)
DEBUG1 - 10:54:16.342523375 [9674/9735]: Consumer discarded 0 events in session id 0 (in consumer_get_discarded_events() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/consumer.c:1617)
DEBUG1 - 10:54:16.342570375 [9674/9735]: Sending response (size: 676, retcode: Success (10)) (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2236)
DEBUG1 - 10:54:16.342682500 [9674/9735]: Clean command context structure (in clean_command_ctx() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:659)
DEBUG1 - 10:54:16.342815750 [9674/9735]: Accepting client command ... (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2087)
DEBUG1 - 10:54:16.343517000 [9674/9735]: Wait for client response (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2129)
DEBUG1 - 10:54:16.343697125 [9674/9735]: Receiving data from client ... (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2174)
DEBUG1 - 10:54:16.343778625 [9674/9735]: Processing client command 9 (in process_client_msg() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:723)
DEBUG1 - 10:54:16.343816750 [9674/9735]: Getting session auto-20210324-105310 by name (in process_client_msg() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:819)
DEBUG2 - 10:54:16.343849625 [9674/9735]: Trying to find session by name auto-20210324-105310 (in session_find_by_name() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/session.c:914)
DEBUG1 - 10:54:16.343885375 [9674/9735]: Begin destroy session auto-20210324-105310 (id 0) (in cmd_destroy_session() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/cmd.c:3263)
DEBUG1 - 10:54:16.343926500 [9674/9735]: Consumer rotate channel key 1 (in consumer_rotate_channel() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/consumer.c:1698)
DEBUG3 - 10:54:16.347972250 [9674/9735]: No metadata to push for metadata key 2 (in ust_app_push_metadata() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:594)
DEBUG1 - 10:54:16.348052875 [9674/9735]: Consumer rotate channel key 2 (in consumer_rotate_channel() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/consumer.c:1698)
DEBUG1 - 10:54:16.348426750 [9674/9735]: Sending consumer close trace chunk command: relayd_id = -1, session_id = 0, chunk_id = 0, close command = "none" (in consumer_close_trace_chunk() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/consumer.c:1971)
DEBUG1 - 10:54:16.349032125 [9674/9735]: Enabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_start() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/timer.c:222)
DEBUG1 - 10:54:16.349234625 [9674/9735]: Cmd rotate session auto-20210324-105310, archive_id 0 sent (in cmd_rotate_session() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/cmd.c:5032)
DEBUG1 - 10:54:16.349295500 [9674/9735]: Clean command context structure (in clean_command_ctx() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:659)
DEBUG1 - 10:54:16.349334750 [9674/9735]: Accepting client command ... (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2087)
DEBUG1 - 10:54:16.721361500 [9674/9732]: [notification-thread] Poll wait returned (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:555)
DEBUG1 - 10:54:16.721504500 [9674/9732]: [notification-thread] Handling fd (17) activity (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:573)
DEBUG1 - 10:54:16.721575000 [9674/9732]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session auto-20210324-105310 (highest usage = 0, lowest usage = 0, total consumed = 32768) (in handle_notification_thread_channel_sample() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread-events.c:3264)
DEBUG1 - 10:54:16.721626750 [9674/9732]: [notification-thread] Entering poll wait (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:553)
DEBUG1 - 10:54:16.849585750 [9674/9734]: [rotation-thread] Poll wait returned (1) (in thread_rotation() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/rotation-thread.c:832)
DEBUG1 - 10:54:16.849723875 [9674/9734]: [rotation-thread] Handling fd (15) activity (1) (in thread_rotation() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/rotation-thread.c:850)
DEBUG1 - 10:54:16.849876375 [9674/9734]: [rotation-thread] Checking for pending rotation on session "auto-20210324-105310", trace archive 0 (in check_session_rotation_pending() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/rotation-thread.c:479)
DEBUG1 - 10:54:16.849921125 [9674/9734]: Disabling session rotation pending check timer on session 0 (in timer_session_rotation_pending_check_stop() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/timer.c:254)
DEBUG1 - 10:54:16.850296500 [9674/9734]: Sending consumer trace chunk exists command: relayd_id = -1, session_id = 0, chunk_id = 0 (in consumer_trace_chunk_exists() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/consumer.c:2065)
DEBUG1 - 10:54:16.850706750 [9674/9734]: Consumer ret code -128 (in consumer_recv_status_reply() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/consumer.c:208)
DEBUG1 - 10:54:16.850758500 [9674/9734]: Consumer reply to TRACE_CHUNK_EXISTS command: unknown trace chunk (in consumer_trace_chunk_exists() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/consumer.c:2089)
DEBUG1 - 10:54:16.850808500 [9674/9734]: [rotation-thread] Rotation of trace archive 0 of session "auto-20210324-105310" is complete on all consumers (in check_session_rotation_pending_on_consumers() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/rotation-thread.c:439)
DEBUG3 - 10:54:16.850909250 [9674/9734]: No kernel session when tearing down session (in kernel_destroy_session() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/kernel.c:1196)
DEBUG1 - 10:54:16.850952000 [9674/9734]: Destroy all UST traces (in ust_app_destroy_trace_all() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:5001)
DEBUG1 - 10:54:16.850996000 [9674/9734]: Destroy tracing for ust app pid 643 (in destroy_trace() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:4887)
DEBUG3 - 10:54:16.851045250 [9674/9734]: Buffer registry per UID find id: 0, ABI: 64, uid: 0 (in buffer_reg_uid_find() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/buffer-registry.c:203)
DEBUG3 - 10:54:16.851196375 [9674/9734]: No metadata to push for metadata key 2 (in ust_app_push_metadata() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:594)
DEBUG3 - 10:54:16.851262250 [9674/9734]: UST app deleting channel channel0 (in delete_ust_app_channel() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:469)
DEBUG1 - 10:54:16.856547500 [9674/9734]: Destroy tracing for ust app pid 635 (in destroy_trace() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:4887)
DEBUG3 - 10:54:16.856684250 [9674/9734]: Buffer registry per UID find id: 0, ABI: 64, uid: 0 (in buffer_reg_uid_find() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/buffer-registry.c:203)
DEBUG3 - 10:54:16.856735750 [9674/9734]: No metadata to push for metadata key 2 (in ust_app_push_metadata() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:594)
DEBUG3 - 10:54:16.856783375 [9674/9734]: UST app deleting channel channel0 (in delete_ust_app_channel() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:469)
DEBUG2 - 10:54:16.861986500 [9674/9734]: Trace UST destroy session 0 (in trace_ust_destroy_session() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/trace-ust.c:1181)
DEBUG3 - 10:54:16.862322250 [9674/9734]: Buffer registry per UID destroy with id: 0, ABI: 64, uid: 0 (in buffer_reg_uid_destroy() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/buffer-registry.c:677)
DEBUG2 - 10:54:16.862380375 [9674/9734]: Consumer close metadata channel key 2 (in consumer_close_metadata() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/consumer.c:1398)
DEBUG3 - 10:54:16.862530625 [9674/9676]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:135)
DEBUG3 - 10:54:16.862669125 [9674/9676]: [ht-thread] Polling. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:132)
DEBUG3 - 10:54:16.862815875 [9674/9676]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:135)
DEBUG3 - 10:54:16.862913750 [9674/9676]: [ht-thread] Polling. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:132)
DEBUG3 - 10:54:16.862957250 [9674/9676]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:135)
DEBUG3 - 10:54:16.863046375 [9674/9676]: [ht-thread] Polling. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:132)
DEBUG3 - 10:54:16.863085375 [9674/9676]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:135)
DEBUG3 - 10:54:16.863275125 [9674/9676]: [ht-thread] Polling. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:132)
DEBUG1 - 10:54:16.863842375 [9674/9741]: Thread kernel return from poll on 2 fds (in thread_kernel_management() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/manage-kernel.c:243)
DEBUG1 - 10:54:16.864048375 [9674/9741]: Updating kernel poll set (in update_kernel_poll() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/manage-kernel.c:47)
DEBUG1 - 10:54:16.864106875 [9674/9734]: Destroying session auto-20210324-105310 (id 0) (in session_release() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/session.c:812)
DEBUG1 - 10:54:16.864228875 [9674/9734]: Empty ltt_sessions_ht_by_id, destroying it (in del_session_ht() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/session.c:396)
DEBUG1 - 10:54:16.864276125 [9674/9734]: No implicit rotation performed during the destruction of session "auto-20210324-105310", sending reply (in cmd_destroy_session_reply() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/cmd.c:3194)
DEBUG2 - 10:54:16.868187750 [9674/10143]: Trace destroy UST event lttng_ust_tracef:* (in trace_ust_destroy_event() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/trace-ust.c:1024)
DEBUG2 - 10:54:16.868362875 [9674/10143]: Trace destroy UST channel channel0 (in _trace_ust_destroy_channel() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/trace-ust.c:1089)
DEBUG3 - 10:54:16.868397625 [9674/10143]: Buffer registry session destroy (in buffer_reg_session_destroy() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/buffer-registry.c:597)
DEBUG3 - 10:54:16.868436000 [9674/10143]: Buffer registry channel destroy with key 0 (in buffer_reg_channel_destroy() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/buffer-registry.c:552)
DEBUG3 - 10:54:16.868469250 [9674/10143]: Buffer registry stream destroy with handle -1 (in buffer_reg_stream_destroy() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/buffer-registry.c:499)
DEBUG3 - 10:54:16.868514375 [9674/10143]: Buffer registry stream destroy with handle -1 (in buffer_reg_stream_destroy() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/buffer-registry.c:499)
DEBUG3 - 10:54:16.868550875 [9674/10143]: Buffer registry stream destroy with handle -1 (in buffer_reg_stream_destroy() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/buffer-registry.c:499)
DEBUG3 - 10:54:16.868586375 [9674/10143]: Buffer registry stream destroy with handle -1 (in buffer_reg_stream_destroy() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/buffer-registry.c:499)
DEBUG1 - 10:54:16.868710125 [9674/10143]: Beginning of waiter wait period (in lttng_waiter_wait() at ../../../lttng-tools-2.11.5/src/common/waiter.c:58)
DEBUG1 - 10:54:16.871221375 [9674/9732]: [notification-thread] Poll wait returned (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:555)
DEBUG1 - 10:54:16.871331250 [9674/9732]: [notification-thread] Handling fd (34) activity (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:573)
DEBUG1 - 10:54:16.871500875 [9674/9732]: [notification-thread] Received remove channel command (in handle_notification_thread_command() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread-events.c:2319)
DEBUG1 - 10:54:16.871534500 [9674/9732]: [notification-thread] Removing channel key = 1 in user space domain (in handle_notification_thread_command_remove_channel() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread-events.c:1662)
DEBUG3 - 10:54:16.871684875 [9674/9676]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:135)
DEBUG3 - 10:54:16.871795125 [9674/9676]: [ht-thread] Polling. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:132)
DEBUG3 - 10:54:16.871837625 [9674/9676]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:135)
DEBUG1 - 10:54:16.871956500 [9674/9732]: [notification-thread] Entering poll wait (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:553)
DEBUG1 - 10:54:16.872207625 [9674/10143]: End of waiter wait period (in lttng_waiter_wait() at ../../../lttng-tools-2.11.5/src/common/waiter.c:101)
DEBUG3 - 10:54:16.872326875 [9674/9676]: [ht-thread] Polling. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:132)
DEBUG3 - 10:54:16.872367500 [9674/9676]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:135)
DEBUG3 - 10:54:16.872465500 [9674/9676]: [ht-thread] Polling. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:132)
DEBUG3 - 10:54:16.872504750 [9674/9676]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:135)
DEBUG3 - 10:54:16.872599875 [9674/9676]: [ht-thread] Polling. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:132)
DEBUG3 - 10:54:16.872641500 [9674/9676]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:135)
DEBUG3 - 10:54:16.872826500 [9674/9676]: [ht-thread] Polling. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:132)
DEBUG3 - 10:54:16.872869000 [9674/9676]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:135)
DEBUG3 - 10:54:16.872963375 [9674/9676]: [ht-thread] Polling. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:132)
DEBUG3 - 10:54:16.873003875 [9674/9676]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:135)
DEBUG3 - 10:54:16.873094000 [9674/9676]: [ht-thread] Polling. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:132)
DEBUG3 - 10:54:16.873166625 [9674/9676]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:135)
DEBUG3 - 10:54:16.873278000 [9674/9676]: [ht-thread] Polling. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:132)
DEBUG3 - 10:54:16.873318375 [9674/9676]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:135)
DEBUG3 - 10:54:16.873408625 [9674/9676]: [ht-thread] Polling. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:132)
DEBUG3 - 10:54:16.873451000 [9674/9676]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:135)
DEBUG3 - 10:54:16.873632875 [9674/9676]: [ht-thread] Polling. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:132)
DEBUG3 - 10:54:16.873675750 [9674/9676]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:135)
DEBUG3 - 10:54:16.873765375 [9674/9676]: [ht-thread] Polling. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:132)
DEBUG1 - 10:54:16.874075125 [9674/9741]: Thread kernel polling (in thread_kernel_management() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/manage-kernel.c:237)
DEBUG3 - 10:54:16.874284375 [9674/9676]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:135)
DEBUG3 - 10:54:16.874401750 [9674/9676]: [ht-thread] Polling. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:132)
DEBUG3 - 10:54:16.874442500 [9674/9676]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:135)
DEBUG3 - 10:54:16.874532625 [9674/9676]: [ht-thread] Polling. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:132)
DEBUG1 - 10:54:16.874604125 [9674/9734]: [rotation-thread] Entering poll wait (in thread_rotation() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/rotation-thread.c:830)
DEBUG3 - 10:54:16.882574625 [9674/9676]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:135)
DEBUG3 - 10:54:16.882779750 [9674/9676]: [ht-thread] Polling. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:132)
DEBUG1 - 10:54:22.536599500 [9675/9675]: run_as worker received signal SIGINT (in worker_sighandler() at ../../../lttng-tools-2.11.5/src/common/runas.c:1114)
DEBUG1 - 10:54:22.536884875 [9674/9674]: SIGINT caught (in sighandler() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/main.c:1111)
DEBUG1 - 10:54:22.536962000 [9674/9674]: Terminating all threads (in stop_threads() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/main.c:172)
DEBUG1 - 10:54:22.537193625 [9674/9674]: Shutting down "Client management" thread (in _lttng_thread_shutdown() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/thread.c:162)
DEBUG1 - 10:54:22.537410625 [9674/9735]: Clean command context structure (in clean_command_ctx() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:659)
DEBUG1 - 10:54:22.537659500 [9674/9735]: Client thread dying (in thread_manage_clients() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2286)
DEBUG1 - 10:54:22.537707000 [9674/9735]: Thread "Client management" has returned (in launch_thread() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/thread.c:76)
DEBUG1 - 10:54:22.538276625 [9674/9674]: Initiating destruction of all sessions (in destroy_all_sessions_and_wait() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/main.c:1230)
DEBUG1 - 10:54:22.538352375 [9674/9674]: Waiting for the destruction of all sessions to complete (in destroy_all_sessions_and_wait() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/main.c:1258)
DEBUG1 - 10:54:22.538400625 [9674/9674]: Destruction of all sessions completed (in destroy_all_sessions_and_wait() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/main.c:1260)
DEBUG1 - 10:54:22.538441375 [9674/9674]: Shutting down "UST application registration" thread (in _lttng_thread_shutdown() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/thread.c:162)
DEBUG1 - 10:54:22.538604875 [9674/9737]: Notifying applications of session daemon state: 0 (in notify_ust_apps() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/register.c:100)
DEBUG1 - 10:54:22.538793000 [9674/9737]: Got the wait shm fd 40 (in get_wait_shm() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/shm.c:148)
DEBUG1 - 10:54:22.539020375 [9674/9737]: Futex wait update active 0 (in futex_wait_update() at ../../../lttng-tools-2.11.5/src/common/futex.c:65)
DEBUG1 - 10:54:22.539369375 [9674/9737]: UST Registration thread cleanup complete (in thread_application_registration() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/register.c:372)
DEBUG1 - 10:54:22.539436750 [9674/9737]: Thread "UST application registration" has returned (in launch_thread() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/thread.c:76)
DEBUG1 - 10:54:22.539882500 [9674/9674]: Shutting down "Consumer management" thread (in _lttng_thread_shutdown() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/thread.c:162)
DEBUG1 - 10:54:22.540531625 [9674/10130]: consumer thread cleanup completed (in thread_consumer_management() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/manage-consumer.c:420)
DEBUG1 - 10:54:22.540603250 [9674/10130]: Thread "Consumer management" has returned (in launch_thread() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/thread.c:76)
DEBUG1 - 10:54:22.543821375 [9674/9674]: Shutting down "Kernel management" thread (in _lttng_thread_shutdown() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/thread.c:162)
DEBUG1 - 10:54:22.544104875 [9674/9741]: Thread kernel return from poll on 2 fds (in thread_kernel_management() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/manage-kernel.c:243)
DEBUG1 - 10:54:22.544260000 [9674/9741]: Kernel thread dying (in thread_kernel_management() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/manage-kernel.c:319)
DEBUG1 - 10:54:22.544293375 [9674/9741]: Thread "Kernel management" has returned (in launch_thread() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/thread.c:76)
DEBUG1 - 10:54:22.544627125 [9674/9674]: Shutting down "Agent management" thread (in _lttng_thread_shutdown() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/thread.c:162)
DEBUG3 - 10:54:22.544738125 [9674/9740]: [agent-thread] Manage agent return from poll on 2 fds (in thread_agent_management() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/agent-thread.c:421)
DEBUG3 - 10:54:22.544784375 [9674/9740]: [agent-thread] 1 fd ready (in thread_agent_management() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/agent-thread.c:433)
DEBUG3 - 10:54:22.544833750 [9674/9740]: [agent-thread] Destroy TCP socket on port 5345 (in destroy_tcp_socket() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/agent-thread.c:201)
DEBUG1 - 10:54:22.544910500 [9674/9740]: [agent-thread] Cleaning up and stopping. (in thread_agent_management() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/agent-thread.c:541)
DEBUG1 - 10:54:22.544944500 [9674/9740]: Thread "Agent management" has returned (in launch_thread() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/thread.c:76)
DEBUG1 - 10:54:22.545394750 [9674/9674]: Shutting down "Application notification" thread (in _lttng_thread_shutdown() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/thread.c:162)
DEBUG3 - 10:54:22.545519250 [9674/9739]: [ust-thread] Manage notify return from poll on 4 fds (in thread_application_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notify-apps.c:90)
DEBUG1 - 10:54:22.545611375 [9674/9739]: Application notify communication apps thread cleanup complete (in thread_application_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notify-apps.c:193)
DEBUG1 - 10:54:22.545645625 [9674/9739]: Thread "Application notification" has returned (in launch_thread() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/thread.c:76)
DEBUG1 - 10:54:22.546029500 [9674/9674]: Shutting down "UST application management" thread (in _lttng_thread_shutdown() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/thread.c:162)
DEBUG1 - 10:54:22.546273625 [9674/9738]: Apps thread return from poll on 4 fds (in thread_application_management() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/manage-apps.c:104)
DEBUG1 - 10:54:22.546484625 [9674/9738]: Application communication apps thread cleanup complete (in thread_application_management() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/manage-apps.c:204)
DEBUG1 - 10:54:22.546520875 [9674/9738]: Thread "UST application management" has returned (in launch_thread() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/thread.c:76)
DEBUG1 - 10:54:22.546904625 [9674/9674]: Shutting down "UST registration dispatch" thread (in _lttng_thread_shutdown() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/thread.c:162)
DEBUG1 - 10:54:22.546957625 [9674/9674]: Futex n to 1 wake done (in futex_nto1_wake() at ../../../lttng-tools-2.11.5/src/common/futex.c:122)
DEBUG1 - 10:54:22.547017125 [9674/9736]: Futex n to 1 wait done (in futex_nto1_wait() at ../../../lttng-tools-2.11.5/src/common/futex.c:105)
DEBUG1 - 10:54:22.547059750 [9674/9736]: Futex n to 1 prepare done (in futex_nto1_prepare() at ../../../lttng-tools-2.11.5/src/common/futex.c:77)
DEBUG1 - 10:54:22.547093000 [9674/9736]: Dispatch thread dying (in thread_dispatch_ust_registration() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/dispatch.c:488)
DEBUG1 - 10:54:22.547276750 [9674/9736]: Thread "UST registration dispatch" has returned (in launch_thread() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/thread.c:76)
DEBUG1 - 10:54:22.547575500 [9674/9674]: Shutting down "Rotation" thread (in _lttng_thread_shutdown() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/thread.c:162)
DEBUG1 - 10:54:22.547678875 [9674/9734]: [rotation-thread] Poll wait returned (1) (in thread_rotation() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/rotation-thread.c:832)
DEBUG1 - 10:54:22.547715875 [9674/9734]: [rotation-thread] Handling fd (38) activity (1) (in thread_rotation() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/rotation-thread.c:850)
DEBUG1 - 10:54:22.547750500 [9674/9734]: [rotation-thread] Quit pipe activity (in thread_rotation() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/rotation-thread.c:890)
DEBUG1 - 10:54:22.547784500 [9674/9734]: [rotation-thread] Exit (in thread_rotation() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/rotation-thread.c:898)
DEBUG1 - 10:54:22.547913500 [9674/9734]: Thread "Rotation" has returned (in launch_thread() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/thread.c:76)
DEBUG1 - 10:54:22.548178000 [9674/9732]: [notification-thread] Poll wait returned (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:555)
DEBUG1 - 10:54:22.548227250 [9674/9732]: [notification-thread] Handling fd (49) activity (8209) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:573)
DEBUG1 - 10:54:22.548259875 [9674/9732]: [notification-thread] Closing client connection (socket fd = 49) (in handle_notification_thread_client_disconnect() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread-events.c:2496)
DEBUG1 - 10:54:22.548345625 [9674/9732]: [notification-thread] Entering poll wait (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:553)
DEBUG1 - 10:54:22.548500625 [9674/9674]: Shutting down "Timer" thread (in _lttng_thread_shutdown() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/thread.c:162)
DEBUG1 - 10:54:22.548597750 [9674/9733]: [timer-thread] Exit (in thread_timer() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/timer.c:412)
DEBUG1 - 10:54:22.548648625 [9674/9733]: Thread "Timer" has returned (in launch_thread() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/thread.c:76)
DEBUG1 - 10:54:22.548941375 [9674/9674]: Shutting down "Health management" thread (in _lttng_thread_shutdown() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/thread.c:162)
DEBUG1 - 10:54:22.549038125 [9674/9731]: Health check thread dying (in thread_manage_health() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/health.c:241)
DEBUG1 - 10:54:22.549413750 [9674/9731]: Thread "Health management" has returned (in launch_thread() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/thread.c:76)
DEBUG1 - 10:54:22.558555250 [9674/9674]: Cleanup sessiond (in sessiond_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/main.c:277)
DEBUG1 - 10:54:22.559022500 [9674/9674]: Removing sessiond and consumerd content of directory /var/run/lttng (in sessiond_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/main.c:293)
DEBUG1 - 10:54:22.559066500 [9674/9674]: Removing /var/run/lttng/lttng-sessiond.pid (in sessiond_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/main.c:297)
DEBUG1 - 10:54:22.559251750 [9674/9674]: Removing /var/run/lttng/agent.port (in sessiond_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/main.c:300)
DEBUG1 - 10:54:22.559378750 [9674/9674]: Removing /var/run/lttng/kconsumerd/error (in sessiond_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/main.c:304)
DEBUG1 - 10:54:22.559450250 [9674/9674]: Removing directory /var/run/lttng/kconsumerd (in sessiond_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/main.c:307)
DEBUG1 - 10:54:22.559540125 [9674/9674]: Removing /var/run/lttng/ustconsumerd32/error (in sessiond_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/main.c:311)
DEBUG1 - 10:54:22.559605250 [9674/9674]: Removing directory /var/run/lttng/ustconsumerd32 (in sessiond_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/main.c:314)
DEBUG1 - 10:54:22.559678875 [9674/9674]: Removing /var/run/lttng/ustconsumerd64/error (in sessiond_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/main.c:318)
DEBUG1 - 10:54:22.559750500 [9674/9674]: Removing directory /var/run/lttng/ustconsumerd64 (in sessiond_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/main.c:321)
DEBUG1 - 10:54:22.559829125 [9674/9674]: Cleaning up all agent apps (in sessiond_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/main.c:326)
DEBUG1 - 10:54:22.559956000 [9674/9674]: Closing all UST sockets (in sessiond_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/main.c:328)
DEBUG2 - 10:54:22.559988625 [9674/9674]: UST app cleaning registered apps hash table (in ust_app_clean_list() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:3859)
DEBUG1 - 10:54:22.560026875 [9674/9674]: UST app notify socket unregister 60 (in ust_app_notify_sock_unregister() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:5852)
DEBUG1 - 10:54:22.560179375 [9674/9674]: UST app notify socket unregister 58 (in ust_app_notify_sock_unregister() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:5852)
DEBUG3 - 10:54:22.560289375 [9674/9676]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:135)
DEBUG3 - 10:54:22.560412375 [9674/9676]: [ht-thread] Polling. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:132)
DEBUG3 - 10:54:22.560508500 [9674/9676]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:135)
DEBUG3 - 10:54:22.560606375 [9674/9676]: [ht-thread] Polling. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:132)
DEBUG3 - 10:54:22.560700375 [9674/9676]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:135)
DEBUG3 - 10:54:22.560793375 [9674/9676]: [ht-thread] Polling. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:132)
DEBUG3 - 10:54:22.560852125 [9674/9674]: Buffer registry destroy all registry (in buffer_reg_destroy_registries() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/buffer-registry.c:753)
DEBUG3 - 10:54:22.561008000 [9674/9676]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:135)
DEBUG3 - 10:54:22.561100750 [9674/9676]: [ht-thread] Polling. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:132)
DEBUG3 - 10:54:22.561229000 [9674/9676]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:135)
DEBUG3 - 10:54:22.561329500 [9674/9676]: [ht-thread] Polling. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:132)
DEBUG1 - 10:54:22.561600125 [9674/9674]: Waiting for complete teardown of consumerd (PID: 10129) (in wait_consumer() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/main.c:257)
DEBUG3 - 10:54:22.570372125 [9674/10143]: Call RCU deleting app PID 643 (in delete_ust_app_rcu() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:969)
DEBUG2 - 10:54:22.570732125 [9674/10143]: UST app pid 643 deleted (in delete_ust_app() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:953)
DEBUG3 - 10:54:22.570791250 [9674/10143]: Call RCU deleting app PID 635 (in delete_ust_app_rcu() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:969)
DEBUG2 - 10:54:22.571052250 [9674/10143]: UST app pid 635 deleted (in delete_ust_app() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ust-app.c:953)
DEBUG3 - 10:54:22.571251125 [9674/9676]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:135)
DEBUG3 - 10:54:22.571430375 [9674/9676]: [ht-thread] Polling. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:132)
DEBUG3 - 10:54:22.571489125 [9674/9676]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:135)
DEBUG3 - 10:54:22.571609500 [9674/9676]: [ht-thread] Polling. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:132)
DEBUG3 - 10:54:22.571661875 [9674/9676]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:135)
DEBUG3 - 10:54:22.571781250 [9674/9676]: [ht-thread] Polling. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:132)
DEBUG3 - 10:54:22.571834375 [9674/9676]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:135)
DEBUG3 - 10:54:22.571958125 [9674/9676]: [ht-thread] Polling. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:132)
DEBUG3 - 10:54:22.572013250 [9674/9676]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:135)
DEBUG3 - 10:54:22.572222750 [9674/9676]: [ht-thread] Polling. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:132)
DEBUG3 - 10:54:22.572299000 [9674/9676]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:135)
DEBUG3 - 10:54:22.572426500 [9674/9676]: [ht-thread] Polling. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:132)
DEBUG1 - 10:54:22.590998000 [9674/9732]: [notification-thread] Poll wait returned (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:555)
DEBUG1 - 10:54:22.591179750 [9674/9732]: [notification-thread] Handling fd (17) activity (16) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:573)
DEBUG1 - 10:54:22.591266125 [9674/9732]: [notification-thread] Entering poll wait (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:553)
DEBUG1 - 10:54:22.591501875 [9674/9732]: [notification-thread] Poll wait returned (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:555)
DEBUG1 - 10:54:22.591548000 [9674/9732]: [notification-thread] Handling fd (13) activity (16) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:573)
DEBUG1 - 10:54:22.591608375 [9674/9732]: [notification-thread] Entering poll wait (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:553)
DEBUG1 - 10:54:22.591720250 [9674/9732]: [notification-thread] Poll wait returned (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:555)
DEBUG1 - 10:54:22.591763750 [9674/9732]: [notification-thread] Handling fd (11) activity (16) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:573)
DEBUG1 - 10:54:22.591828875 [9674/9732]: [notification-thread] Entering poll wait (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:553)
DEBUG2 - 10:54:22.592300625 [9674/9674]: Closing kernel fd (in cleanup_kernel_tracer() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/kernel.c:1632)
DEBUG1 - 10:54:22.592389750 [9674/9674]: Unloading kernel modules (in cleanup_kernel_tracer() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/kernel.c:1640)
DEBUG1 - 10:54:22.606010625 [9674/9674]: Modprobe removal successful lttng-probe-writeback (in modprobe_remove_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:382)
DEBUG1 - 10:54:22.618809875 [9674/9674]: Modprobe removal successful lttng-probe-workqueue (in modprobe_remove_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:382)
DEBUG1 - 10:54:22.631337375 [9674/9674]: Modprobe removal successful lttng-probe-vmscan (in modprobe_remove_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:382)
DEBUG1 - 10:54:22.643997125 [9674/9674]: Modprobe removal successful lttng-probe-udp (in modprobe_remove_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:382)
DEBUG1 - 10:54:22.657984375 [9674/9674]: Modprobe removal successful lttng-probe-timer (in modprobe_remove_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:382)
DEBUG1 - 10:54:22.670515750 [9674/9674]: Modprobe removal successful lttng-probe-sunrpc (in modprobe_remove_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:382)
DEBUG1 - 10:54:22.682914750 [9674/9674]: Modprobe removal successful lttng-probe-statedump (in modprobe_remove_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:382)
DEBUG1 - 10:54:22.695364375 [9674/9674]: Modprobe removal successful lttng-probe-sock (in modprobe_remove_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:382)
DEBUG1 - 10:54:22.707812500 [9674/9674]: Modprobe removal successful lttng-probe-skb (in modprobe_remove_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:382)
DEBUG1 - 10:54:22.720422375 [9674/9674]: Modprobe removal successful lttng-probe-signal (in modprobe_remove_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:382)
DEBUG1 - 10:54:22.732894750 [9674/9674]: Modprobe removal successful lttng-probe-scsi (in modprobe_remove_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:382)
DEBUG1 - 10:54:22.745320125 [9674/9674]: Modprobe removal successful lttng-probe-sched (in modprobe_remove_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:382)
DEBUG1 - 10:54:22.757986875 [9674/9674]: Modprobe removal successful lttng-probe-regulator (in modprobe_remove_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:382)
DEBUG1 - 10:54:22.770557750 [9674/9674]: Modprobe removal successful lttng-probe-regmap (in modprobe_remove_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:382)
DEBUG1 - 10:54:22.783179500 [9674/9674]: Modprobe removal successful lttng-probe-rcu (in modprobe_remove_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:382)
DEBUG1 - 10:54:22.795806250 [9674/9674]: Modprobe removal successful lttng-probe-random (in modprobe_remove_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:382)
DEBUG1 - 10:54:22.808376875 [9674/9674]: Modprobe removal successful lttng-probe-printk (in modprobe_remove_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:382)
DEBUG1 - 10:54:22.820904875 [9674/9674]: Modprobe removal successful lttng-probe-power (in modprobe_remove_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:382)
DEBUG1 - 10:54:22.833452000 [9674/9674]: Modprobe removal successful lttng-probe-net (in modprobe_remove_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:382)
DEBUG1 - 10:54:22.845856125 [9674/9674]: Modprobe removal successful lttng-probe-napi (in modprobe_remove_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:382)
DEBUG1 - 10:54:22.858474000 [9674/9674]: Modprobe removal successful lttng-probe-module (in modprobe_remove_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:382)
DEBUG1 - 10:54:22.870892250 [9674/9674]: Modprobe removal successful lttng-probe-kmem (in modprobe_remove_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:382)
DEBUG1 - 10:54:22.883362500 [9674/9674]: Modprobe removal successful lttng-probe-jbd2 (in modprobe_remove_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:382)
DEBUG1 - 10:54:22.895983625 [9674/9674]: Modprobe removal successful lttng-probe-irq (in modprobe_remove_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:382)
DEBUG1 - 10:54:22.908522875 [9674/9674]: Modprobe removal successful lttng-probe-i2c (in modprobe_remove_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:382)
DEBUG1 - 10:54:22.921297125 [9674/9674]: Modprobe removal successful lttng-probe-gpio (in modprobe_remove_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:382)
DEBUG1 - 10:54:22.933805000 [9674/9674]: Modprobe removal successful lttng-probe-ext4 (in modprobe_remove_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:382)
DEBUG1 - 10:54:22.946430625 [9674/9674]: Modprobe removal successful lttng-probe-compaction (in modprobe_remove_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:382)
DEBUG1 - 10:54:22.959051500 [9674/9674]: Modprobe removal successful lttng-probe-block (in modprobe_remove_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:382)
DEBUG1 - 10:54:22.971592875 [9674/9674]: Modprobe removal successful lttng-probe-asoc (in modprobe_remove_lttng() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/modprobe.c:382)
Error: Unable to remove module lttng-ring-buffer-metadata-mmap-client
Error: Unable to remove module lttng-ring-buffer-client-mmap-overwrite
Error: Unable to remove module lttng-ring-buffer-client-mmap-discard
Error: Unable to remove module lttng-ring-buffer-metadata-client
Error: Unable to remove module lttng-ring-buffer-client-overwrite
Error: Unable to remove module lttng-ring-buffer-client-discard
DEBUG1 - 10:54:23.047534125 [9674/9674]: Shutting down "Notification" thread (in _lttng_thread_shutdown() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/thread.c:162)
DEBUG1 - 10:54:23.047622000 [9674/9674]: Beginning of waiter wait period (in lttng_waiter_wait() at ../../../lttng-tools-2.11.5/src/common/waiter.c:58)
DEBUG1 - 10:54:23.047691250 [9674/9732]: [notification-thread] Poll wait returned (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:555)
DEBUG1 - 10:54:23.047819250 [9674/9732]: [notification-thread] Handling fd (34) activity (1) (in thread_notification() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:573)
DEBUG1 - 10:54:23.047870375 [9674/9732]: [notification-thread] Received quit command (in handle_notification_thread_command() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread-events.c:2341)
DEBUG1 - 10:54:23.047917750 [9674/9732]: [notification-thread] Closing all client connections (in handle_notification_thread_client_disconnect_all() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread-events.c:2527)
DEBUG1 - 10:54:23.048784500 [9674/9732]: [notification-thread] Destroying notification channel socket (in notification_channel_socket_destroy() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/notification-thread.c:202)
DEBUG1 - 10:54:23.049062375 [9674/9732]: Thread "Notification" has returned (in launch_thread() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/thread.c:76)
DEBUG1 - 10:54:23.049254125 [9674/9674]: End of waiter wait period (in lttng_waiter_wait() at ../../../lttng-tools-2.11.5/src/common/waiter.c:101)
DEBUG1 - 10:54:23.059822875 [9674/9674]: Shutting down "HT cleanup" thread (in _lttng_thread_shutdown() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/thread.c:162)
DEBUG3 - 10:54:23.060033250 [9674/9676]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:135)
DEBUG1 - 10:54:23.060084500 [9674/9676]: [ht-cleanup] quit. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:216)
DEBUG1 - 10:54:23.060235000 [9674/9676]: [ht-cleanup] Thread terminates. (in thread_ht_cleanup() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/ht-cleanup.c:227)
DEBUG1 - 10:54:23.060301250 [9674/9676]: Thread "HT cleanup" has returned (in launch_thread() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/thread.c:76)
DEBUG1 - 10:54:23.061657375 [9674/9674]: Cleaning up options (in sessiond_cleanup_options() at ../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/main.c:354)
DEBUG1 - 10:54:23.061753875 [9674/9674]: Destroying run_as worker (in run_as_destroy_worker_no_lock() at ../../../lttng-tools-2.11.5/src/common/runas.c:1280)
DEBUG1 - 10:54:23.061798125 [9674/9674]: Closing run_as worker socket (in run_as_destroy_worker_no_lock() at ../../../lttng-tools-2.11.5/src/common/runas.c:1285)
DEBUG1 - 10:54:23.062083375 [9675/9675]: run_as worker exiting (ret = 0) (in run_as_create_worker_no_lock() at ../../../lttng-tools-2.11.5/src/common/runas.c:1230)
DEBUG1 - 10:54:23.066625875 [9674/9674]: lttng-runas terminated with status code 0 (in run_as_destroy_worker_no_lock() at ../../../lttng-tools-2.11.5/src/common/runas.c:1305)
[-- Attachment #3: Type: text/plain, Size: 156 bytes --]
_______________________________________________
lttng-dev mailing list
lttng-dev@lists.lttng.org
https://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev
^ permalink raw reply [flat|nested] 4+ messages in thread* [lttng-dev] Using lttng 2.11 and UST doesn't appear to work - getting empty trace files
@ 2023-04-25 4:13 Yitschak, Yehuda via lttng-dev
2023-04-25 4:56 ` Brian Hutchinson via lttng-dev
0 siblings, 1 reply; 4+ messages in thread
From: Yitschak, Yehuda via lttng-dev @ 2023-04-25 4:13 UTC (permalink / raw)
To: Brian Hutchinson, lttng-dev@lists.lttng.org
[-- Attachment #1.1: Type: text/plain, Size: 3879 bytes --]
It might be related to the static linking of lttng-ust
https://lists.lttng.org/pipermail/lttng-dev/2018-January/027705.html
I also went down that path just to figure it’s not supported.
Perhaps lttng documentation should be updated to make a clear note static linking is not supported (or maybe I missed it)
Yehuda
Hi,
I'm on an embedded platform, i.MX8 using Lttng 2.11 with 5.6.69 kernel.
Tracing kernel events with lttng works fine but userspace (tracef and trace provider type tracing) appears to have an issue I can't figure out.
systemd is starting up my application ( a bunch of processes and threads on multiple cpu's) on boot.
I'm statically compiling and linking in lttng-ust. If I use just tracef type tracing, when I do lttng list --userspace I get nothing. If I add in a trace provider and a tracepoint, then I see my trace provider tracepoint and:
lttng_ust_tracelog:TRACE_DEBUG (loglevel: TRACE_DEBUG (14)) (type: tracepoint)
lttng_ust_tracelog:TRACE_DEBUG_LINE (loglevel: TRACE_DEBUG_LINE (13)) (type: tracepoint)
lttng_ust_tracelog:TRACE_DEBUG_FUNCTION (loglevel: TRACE_DEBUG_FUNCTION (12)) (type: tracepoint)
lttng_ust_tracelog:TRACE_DEBUG_UNIT (loglevel: TRACE_DEBUG_UNIT (11)) (type: tracepoint)
lttng_ust_tracelog:TRACE_DEBUG_MODULE (loglevel: TRACE_DEBUG_MODULE (10)) (type: tracepoint)
lttng_ust_tracelog:TRACE_DEBUG_PROCESS (loglevel: TRACE_DEBUG_PROCESS (9)) (type: tracepoint)
lttng_ust_tracelog:TRACE_DEBUG_PROGRAM (loglevel: TRACE_DEBUG_PROGRAM (8)) (type: tracepoint)
lttng_ust_tracelog:TRACE_DEBUG_SYSTEM (loglevel: TRACE_DEBUG_SYSTEM (7)) (type: tracepoint)
lttng_ust_tracelog:TRACE_INFO (loglevel: TRACE_INFO (6)) (type: tracepoint)
lttng_ust_tracelog:TRACE_NOTICE (loglevel: TRACE_NOTICE (5)) (type: tracepoint)
lttng_ust_tracelog:TRACE_WARNING (loglevel: TRACE_WARNING (4)) (type: tracepoint)
lttng_ust_tracelog:TRACE_ERR (loglevel: TRACE_ERR (3)) (type: tracepoint)
lttng_ust_tracelog:TRACE_CRIT (loglevel: TRACE_CRIT (2)) (type: tracepoint)
lttng_ust_tracelog:TRACE_ALERT (loglevel: TRACE_ALERT (1)) (type: tracepoint)
lttng_ust_tracelog:TRACE_EMERG (loglevel: TRACE_EMERG (0)) (type: tracepoint)
lttng_ust_tracef:event (loglevel: TRACE_DEBUG (14)) (type: tracepoint)
lttng_ust_lib:unload (loglevel: TRACE_DEBUG_LINE (13)) (type: tracepoint)
lttng_ust_lib:debug_link (loglevel: TRACE_DEBUG_LINE (13)) (type: tracepoint)
lttng_ust_lib:build_id (loglevel: TRACE_DEBUG_LINE (13)) (type: tracepoint)
lttng_ust_lib:load (loglevel: TRACE_DEBUG_LINE (13)) (type: tracepoint)
lttng_ust_statedump:end (loglevel: TRACE_DEBUG_LINE (13)) (type: tracepoint)
lttng_ust_statedump:debug_link (loglevel: TRACE_DEBUG_LINE (13)) (type: tracepoint)
lttng_ust_statedump:build_id (loglevel: TRACE_DEBUG_LINE (13)) (type: tracepoint)
lttng_ust_statedump:bin_info (loglevel: TRACE_DEBUG_LINE (13)) (type: tracepoint)
lttng_ust_statedump:start (loglevel: TRACE_DEBUG_LINE (13)) (type: tracepoint)
When I do lttng start, I get a directory structure in the trace directory but the file sizes do not ever increase. It's just a directory structure with files created and then that's it, no events being written to the files. At first I thought things just weren't linked in right and not working but then discovered how to run lttng-sessiond in -vvv mode and then could see lots of things are going on, tracing appears to be trying to work as there is tons of activity being output by lttng-sessiond, but like I said the trace files aren't being added to.
I looked at the lttng-sessiond log I captured and can't quite make out the problem so attaching it.
I'm probably not doing something right but can't figure out what that is so any pointers appreciated.
Regards,
Brian
[-- Attachment #1.2: Type: text/html, Size: 8485 bytes --]
[-- Attachment #2: Type: text/plain, Size: 156 bytes --]
_______________________________________________
lttng-dev mailing list
lttng-dev@lists.lttng.org
https://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev
^ permalink raw reply [flat|nested] 4+ messages in thread* Re: [lttng-dev] Using lttng 2.11 and UST doesn't appear to work - getting empty trace files
2023-04-25 4:13 Yitschak, Yehuda via lttng-dev
@ 2023-04-25 4:56 ` Brian Hutchinson via lttng-dev
2023-04-25 12:30 ` Brian Hutchinson via lttng-dev
0 siblings, 1 reply; 4+ messages in thread
From: Brian Hutchinson via lttng-dev @ 2023-04-25 4:56 UTC (permalink / raw)
To: Yitschak, Yehuda; +Cc: lttng-dev@lists.lttng.org
[-- Attachment #1.1: Type: text/plain, Size: 5258 bytes --]
So instructions for tracef just say to link in lttng-ust, not dl, I didn't
use liblttng-ust.a so maybe I misspoke.
https://lttng.org/docs/v2.11/#doc-tracef
... so that's what I did.
When I compile in a tracepoint with trace provider, I link in lttng-ust and
dl. I'm assuming you can mix both tracef and tracepoint calls?
I included a lttng-sessiond -vvv log in original post. Are attachments
allowed or should I have posted the context as a plain text post? It's
quite big.
When I do lttng start, my app is already running via systemd at startup.
Do I need to disable that and start the executable manually after enabling
the lttng ust events?
Like I said, kernel trace is working fine, it's UST that appears to not be
working for some reason. I have less experience with UST but I've been
researching and searching archives and I see others complaining about what
looks to be my problem but either don't see a solution or maybe I just
don't understand it.
Thanks,
Brian
On Tue, Apr 25, 2023 at 12:13 AM Yitschak, Yehuda <yehuday@amazon.com>
wrote:
> It might be related to the static linking of lttng-ust
> https://lists.lttng.org/pipermail/lttng-dev/2018-January/027705.html
>
> I also went down that path just to figure it’s not supported.
>
> Perhaps lttng documentation should be updated to make a clear note static
> linking is not supported (or maybe I missed it)
>
> Yehuda
>
> Hi,
>
>
>
> I'm on an embedded platform, i.MX8 using Lttng 2.11 with 5.6.69 kernel.
>
>
>
> Tracing kernel events with lttng works fine but userspace (tracef and
> trace provider type tracing) appears to have an issue I can't figure out.
>
>
>
> systemd is starting up my application ( a bunch of processes and threads
> on multiple cpu's) on boot.
>
>
>
> I'm statically compiling and linking in lttng-ust. If I use just tracef
> type tracing, when I do lttng list --userspace I get nothing. If I add in
> a trace provider and a tracepoint, then I see my trace provider tracepoint
> and:
>
>
>
> lttng_ust_tracelog:TRACE_DEBUG (loglevel: TRACE_DEBUG (14)) (type:
> tracepoint)
> lttng_ust_tracelog:TRACE_DEBUG_LINE (loglevel: TRACE_DEBUG_LINE (13))
> (type: tracepoint)
> lttng_ust_tracelog:TRACE_DEBUG_FUNCTION (loglevel:
> TRACE_DEBUG_FUNCTION (12)) (type: tracepoint)
> lttng_ust_tracelog:TRACE_DEBUG_UNIT (loglevel: TRACE_DEBUG_UNIT (11))
> (type: tracepoint)
> lttng_ust_tracelog:TRACE_DEBUG_MODULE (loglevel: TRACE_DEBUG_MODULE
> (10)) (type: tracepoint)
> lttng_ust_tracelog:TRACE_DEBUG_PROCESS (loglevel: TRACE_DEBUG_PROCESS
> (9)) (type: tracepoint)
> lttng_ust_tracelog:TRACE_DEBUG_PROGRAM (loglevel: TRACE_DEBUG_PROGRAM
> (8)) (type: tracepoint)
> lttng_ust_tracelog:TRACE_DEBUG_SYSTEM (loglevel: TRACE_DEBUG_SYSTEM
> (7)) (type: tracepoint)
> lttng_ust_tracelog:TRACE_INFO (loglevel: TRACE_INFO (6)) (type:
> tracepoint)
> lttng_ust_tracelog:TRACE_NOTICE (loglevel: TRACE_NOTICE (5)) (type:
> tracepoint)
> lttng_ust_tracelog:TRACE_WARNING (loglevel: TRACE_WARNING (4)) (type:
> tracepoint)
> lttng_ust_tracelog:TRACE_ERR (loglevel: TRACE_ERR (3)) (type:
> tracepoint)
> lttng_ust_tracelog:TRACE_CRIT (loglevel: TRACE_CRIT (2)) (type:
> tracepoint)
> lttng_ust_tracelog:TRACE_ALERT (loglevel: TRACE_ALERT (1)) (type:
> tracepoint)
> lttng_ust_tracelog:TRACE_EMERG (loglevel: TRACE_EMERG (0)) (type:
> tracepoint)
> lttng_ust_tracef:event (loglevel: TRACE_DEBUG (14)) (type:
> tracepoint)
> lttng_ust_lib:unload (loglevel: TRACE_DEBUG_LINE (13)) (type:
> tracepoint)
> lttng_ust_lib:debug_link (loglevel: TRACE_DEBUG_LINE (13)) (type:
> tracepoint)
> lttng_ust_lib:build_id (loglevel: TRACE_DEBUG_LINE (13)) (type:
> tracepoint)
> lttng_ust_lib:load (loglevel: TRACE_DEBUG_LINE (13)) (type:
> tracepoint)
> lttng_ust_statedump:end (loglevel: TRACE_DEBUG_LINE (13)) (type:
> tracepoint)
> lttng_ust_statedump:debug_link (loglevel: TRACE_DEBUG_LINE (13))
> (type: tracepoint)
> lttng_ust_statedump:build_id (loglevel: TRACE_DEBUG_LINE (13)) (type:
> tracepoint)
> lttng_ust_statedump:bin_info (loglevel: TRACE_DEBUG_LINE (13)) (type:
> tracepoint)
> lttng_ust_statedump:start (loglevel: TRACE_DEBUG_LINE (13)) (type:
> tracepoint)
>
>
>
> When I do lttng start, I get a directory structure in the trace directory
> but the file sizes do not ever increase. It's just a directory structure
> with files created and then that's it, no events being written to the
> files. At first I thought things just weren't linked in right and not
> working but then discovered how to run lttng-sessiond in -vvv mode and then
> could see lots of things are going on, tracing appears to be trying to work
> as there is tons of activity being output by lttng-sessiond, but like I
> said the trace files aren't being added to.
>
>
>
> I looked at the lttng-sessiond log I captured and can't quite make out the
> problem so attaching it.
>
>
>
> I'm probably not doing something right but can't figure out what that is
> so any pointers appreciated.
>
>
>
> Regards,
>
>
>
> Brian
>
>
>
[-- Attachment #1.2: Type: text/html, Size: 8139 bytes --]
[-- Attachment #2: Type: text/plain, Size: 156 bytes --]
_______________________________________________
lttng-dev mailing list
lttng-dev@lists.lttng.org
https://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev
^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: [lttng-dev] Using lttng 2.11 and UST doesn't appear to work - getting empty trace files
2023-04-25 4:56 ` Brian Hutchinson via lttng-dev
@ 2023-04-25 12:30 ` Brian Hutchinson via lttng-dev
0 siblings, 0 replies; 4+ messages in thread
From: Brian Hutchinson via lttng-dev @ 2023-04-25 12:30 UTC (permalink / raw)
Cc: lttng-dev@lists.lttng.org
[-- Attachment #1.1: Type: text/plain, Size: 8384 bytes --]
So looking at my lttng-sessiond log I found some concerning issues of
things being "not found":
DEBUG1 - 10:53:52.130237000 [9674/9735]: Enable event command for event
'lttng_ust_tracef:*' (in _cmd_enable_event() at
../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/cmd.c:2036)
DEBUG2 - 10:53:52.130399500 [9674/9735]: Trace UST channel channel0 not
found by name (in trace_ust_find_channel_by_name() at
../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/trace-ust.c:197)
DEBUG1 - 10:53:52.130450125 [9674/9735]: Enabling channel for session
auto-20210324-105310 (in cmd_enable_channel() at
../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/cmd.c:1510)
DEBUG2 - 10:53:52.130496375 [9674/9735]: Trace UST channel channel0 not
found by name (in trace_ust_find_channel_by_name() at
../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/trace-ust.c:197)
DEBUG3 - 10:53:52.130572000 [9674/9735]: Created hashtable size 4 at
0xffff90017170 of type 0 (in lttng_ht_new() at
../../../../lttng-tools-2.11.5/src/common/hashtable/hashtable.c:145)
DEBUG3 - 10:53:52.130619625 [9674/9735]: Created hashtable size 4 at
0xffff900175b0 of type 1 (in lttng_ht_new() at
../../../../lttng-tools-2.11.5/src/common/hashtable/hashtable.c:145)
DEBUG2 - 10:53:52.130666000 [9674/9735]: Trace UST channel channel0 created
(in trace_ust_create_channel() at
../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/trace-ust.c:396)
DEBUG2 - 10:53:52.130713625 [9674/9735]: Channel channel0 is being created
for UST with buffer 1 and id 0 (in channel_ust_create() at
../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/channel.c:461)
DEBUG2 - 10:53:52.130762250 [9674/9735]: Channel channel0 created
successfully (in channel_ust_create() at
../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/channel.c:500)
DEBUG2 - 10:53:52.130807500 [9674/9735]: Trace UST channel channel0 found
by name (in trace_ust_find_channel_by_name() at
../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/trace-ust.c:192)
DEBUG2 - 10:53:52.130851750 [9674/9735]: Trace UST event lttng_ust_tracef:*
NOT found (in trace_ust_find_event() at
../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/trace-ust.c:235)
DEBUG2 - 10:53:52.130896500 [9674/9735]: Trace UST event
lttng_ust_tracef:*, loglevel (0,-1) created (in trace_ust_create_event() at
../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/trace-ust.c:517)
DEBUG1 - 10:53:52.130968375 [9674/9735]: Sending response (size: 20,
retcode: Success (10)) (in thread_manage_clients() at
../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:2236)
DEBUG1 - 10:53:52.134962250 [9674/9735]: Clean command context structure
(in clean_command_ctx() at
../../../../lttng-tools-2.11.5/src/bin/lttng-sessiond/client.c:659)
Not quite sure what to do about that.
Regards,
Brian
On Tue, Apr 25, 2023 at 12:56 AM Brian Hutchinson <b.hutchman@gmail.com>
wrote:
> So instructions for tracef just say to link in lttng-ust, not dl, I didn't
> use liblttng-ust.a so maybe I misspoke.
>
> https://lttng.org/docs/v2.11/#doc-tracef
>
> ... so that's what I did.
>
> When I compile in a tracepoint with trace provider, I link in lttng-ust
> and dl. I'm assuming you can mix both tracef and tracepoint calls?
>
> I included a lttng-sessiond -vvv log in original post. Are attachments
> allowed or should I have posted the context as a plain text post? It's
> quite big.
>
> When I do lttng start, my app is already running via systemd at startup.
> Do I need to disable that and start the executable manually after enabling
> the lttng ust events?
>
> Like I said, kernel trace is working fine, it's UST that appears to not be
> working for some reason. I have less experience with UST but I've been
> researching and searching archives and I see others complaining about what
> looks to be my problem but either don't see a solution or maybe I just
> don't understand it.
>
> Thanks,
>
> Brian
>
> On Tue, Apr 25, 2023 at 12:13 AM Yitschak, Yehuda <yehuday@amazon.com>
> wrote:
>
>> It might be related to the static linking of lttng-ust
>> https://lists.lttng.org/pipermail/lttng-dev/2018-January/027705.html
>>
>> I also went down that path just to figure it’s not supported.
>>
>> Perhaps lttng documentation should be updated to make a clear note static
>> linking is not supported (or maybe I missed it)
>>
>> Yehuda
>>
>> Hi,
>>
>>
>>
>> I'm on an embedded platform, i.MX8 using Lttng 2.11 with 5.6.69 kernel.
>>
>>
>>
>> Tracing kernel events with lttng works fine but userspace (tracef and
>> trace provider type tracing) appears to have an issue I can't figure out.
>>
>>
>>
>> systemd is starting up my application ( a bunch of processes and threads
>> on multiple cpu's) on boot.
>>
>>
>>
>> I'm statically compiling and linking in lttng-ust. If I use just tracef
>> type tracing, when I do lttng list --userspace I get nothing. If I add in
>> a trace provider and a tracepoint, then I see my trace provider tracepoint
>> and:
>>
>>
>>
>> lttng_ust_tracelog:TRACE_DEBUG (loglevel: TRACE_DEBUG (14)) (type:
>> tracepoint)
>> lttng_ust_tracelog:TRACE_DEBUG_LINE (loglevel: TRACE_DEBUG_LINE
>> (13)) (type: tracepoint)
>> lttng_ust_tracelog:TRACE_DEBUG_FUNCTION (loglevel:
>> TRACE_DEBUG_FUNCTION (12)) (type: tracepoint)
>> lttng_ust_tracelog:TRACE_DEBUG_UNIT (loglevel: TRACE_DEBUG_UNIT
>> (11)) (type: tracepoint)
>> lttng_ust_tracelog:TRACE_DEBUG_MODULE (loglevel: TRACE_DEBUG_MODULE
>> (10)) (type: tracepoint)
>> lttng_ust_tracelog:TRACE_DEBUG_PROCESS (loglevel:
>> TRACE_DEBUG_PROCESS (9)) (type: tracepoint)
>> lttng_ust_tracelog:TRACE_DEBUG_PROGRAM (loglevel:
>> TRACE_DEBUG_PROGRAM (8)) (type: tracepoint)
>> lttng_ust_tracelog:TRACE_DEBUG_SYSTEM (loglevel: TRACE_DEBUG_SYSTEM
>> (7)) (type: tracepoint)
>> lttng_ust_tracelog:TRACE_INFO (loglevel: TRACE_INFO (6)) (type:
>> tracepoint)
>> lttng_ust_tracelog:TRACE_NOTICE (loglevel: TRACE_NOTICE (5)) (type:
>> tracepoint)
>> lttng_ust_tracelog:TRACE_WARNING (loglevel: TRACE_WARNING (4))
>> (type: tracepoint)
>> lttng_ust_tracelog:TRACE_ERR (loglevel: TRACE_ERR (3)) (type:
>> tracepoint)
>> lttng_ust_tracelog:TRACE_CRIT (loglevel: TRACE_CRIT (2)) (type:
>> tracepoint)
>> lttng_ust_tracelog:TRACE_ALERT (loglevel: TRACE_ALERT (1)) (type:
>> tracepoint)
>> lttng_ust_tracelog:TRACE_EMERG (loglevel: TRACE_EMERG (0)) (type:
>> tracepoint)
>> lttng_ust_tracef:event (loglevel: TRACE_DEBUG (14)) (type:
>> tracepoint)
>> lttng_ust_lib:unload (loglevel: TRACE_DEBUG_LINE (13)) (type:
>> tracepoint)
>> lttng_ust_lib:debug_link (loglevel: TRACE_DEBUG_LINE (13)) (type:
>> tracepoint)
>> lttng_ust_lib:build_id (loglevel: TRACE_DEBUG_LINE (13)) (type:
>> tracepoint)
>> lttng_ust_lib:load (loglevel: TRACE_DEBUG_LINE (13)) (type:
>> tracepoint)
>> lttng_ust_statedump:end (loglevel: TRACE_DEBUG_LINE (13)) (type:
>> tracepoint)
>> lttng_ust_statedump:debug_link (loglevel: TRACE_DEBUG_LINE (13))
>> (type: tracepoint)
>> lttng_ust_statedump:build_id (loglevel: TRACE_DEBUG_LINE (13))
>> (type: tracepoint)
>> lttng_ust_statedump:bin_info (loglevel: TRACE_DEBUG_LINE (13))
>> (type: tracepoint)
>> lttng_ust_statedump:start (loglevel: TRACE_DEBUG_LINE (13)) (type:
>> tracepoint)
>>
>>
>>
>> When I do lttng start, I get a directory structure in the trace directory
>> but the file sizes do not ever increase. It's just a directory structure
>> with files created and then that's it, no events being written to the
>> files. At first I thought things just weren't linked in right and not
>> working but then discovered how to run lttng-sessiond in -vvv mode and then
>> could see lots of things are going on, tracing appears to be trying to work
>> as there is tons of activity being output by lttng-sessiond, but like I
>> said the trace files aren't being added to.
>>
>>
>>
>> I looked at the lttng-sessiond log I captured and can't quite make out
>> the problem so attaching it.
>>
>>
>>
>> I'm probably not doing something right but can't figure out what that is
>> so any pointers appreciated.
>>
>>
>>
>> Regards,
>>
>>
>>
>> Brian
>>
>>
>>
>
[-- Attachment #1.2: Type: text/html, Size: 12808 bytes --]
[-- Attachment #2: Type: text/plain, Size: 156 bytes --]
_______________________________________________
lttng-dev mailing list
lttng-dev@lists.lttng.org
https://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev
^ permalink raw reply [flat|nested] 4+ messages in thread
end of thread, other threads:[~2023-04-25 12:31 UTC | newest]
Thread overview: 4+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2023-04-24 13:48 [lttng-dev] Using lttng 2.11 and UST doesn't appear to work - getting empty trace files Brian Hutchinson via lttng-dev
-- strict thread matches above, loose matches on Subject: below --
2023-04-25 4:13 Yitschak, Yehuda via lttng-dev
2023-04-25 4:56 ` Brian Hutchinson via lttng-dev
2023-04-25 12:30 ` Brian Hutchinson via lttng-dev
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).