[lttng-dev] LTTng sessiond daemon Assertion `buf' failed and killed
Yonghong Yan
yanyh15 at gmail.com
Fri Jan 12 22:04:21 EST 2024
Hi Kienan,
Thank you. I tried and unfortunately, there is no debuginfo in the
https://debuginfod.ubuntu.com repo. I tried https://debuginfod.debian.net/
as well. No debug info. If you have a debug info file and can send to me, I
can use it in gdb to see the backtrace.
Best,
Yonghong
*yyan7 at CCI13SZWP3LWS*:*/var/lib/apport/coredump*$ export DEBUGINFOD_URLS="
https://debuginfod.ubuntu.com"
*yyan7 at CCI13SZWP3LWS*:*/var/lib/apport/coredump*$ gdb
/usr/bin/lttng-sessiond
core._usr_bin_lttng-sessiond.1000.8f22faa6-512c-49ca-9089-8b3f0801da8d.10470.2023109
*GNU gdb (Ubuntu 12.1-0ubuntu1~22.04) 12.1*
Copyright (C) 2022 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html
>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.
Type "show copying" and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<https://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from /usr/bin/lttng-sessiond...
This GDB supports auto-downloading debuginfo from the following URLs:
https://debuginfod.ubuntu.com
Enable debuginfod for this session? (y or [n]) y
Debuginfod has been enabled.
To make this setting permanent, add 'set debuginfod enabled on' to .gdbinit.
(No debugging symbols found in /usr/bin/lttng-sessiond)
[New LWP 10479]
[New LWP 10470]
[New LWP 10476]
[New LWP 10475]
[New LWP 10472]
[New LWP 10478]
[New LWP 10480]
[New LWP 10473]
[New LWP 10477]
[New LWP 10482]
[New LWP 10542]
[New LWP 10533]
[New LWP 10484]
[New LWP 10474]
[New LWP 10481]
[New LWP 10483]
Downloading 0.19 MB separate debug info for
/lib/x86_64-linux-gnu/libkmod.so.2
Downloading 0.89 MB separate debug info for
/lib/x86_64-linux-gnu/liblttng-ctl.so.0
Downloading 0.05 MB separate debug info for
/lib/x86_64-linux-gnu/liburcu.so.8
Downloading 0.01 MB separate debug info for
/home/yyan7/.cache/debuginfod_client/55485e3e07dd2ab7e3510c9f90e8e8607f07d0c2/debuginfo
Downloading 0.03 MB separate debug info for
/lib/x86_64-linux-gnu/liburcu-common.so.8
Downloading 0.07 MB separate debug info for
/lib/x86_64-linux-gnu/liburcu-cds.so.8
Downloading 2.45 MB separate debug info for
/lib/x86_64-linux-gnu/libxml2.so.2
Downloading 1.73 MB separate debug info for
/lib/x86_64-linux-gnu/libzstd.so.1
Downloading 0.30 MB separate debug info for
/lib/x86_64-linux-gnu/liblzma.so.5
Downloading 4.95 MB separate debug info for
/lib/x86_64-linux-gnu/libcrypto.so.3
Downloading 3.06 MB separate debug info for
/lib/x86_64-linux-gnu/libicuuc.so.70
Downloading 0.08 MB separate debug info for
/home/yyan7/.cache/debuginfod_client/bef3ff1d70aadd68aab07d858a759360c8b919ae/debuginfo
Downloading 0.07 MB separate debug info for
/lib/x86_64-linux-gnu/libnuma.so.1
Downloading 0.00 MB separate debug info for
/lib/x86_64-linux-gnu/libicudata.so.70
Downloading 5.99 MB separate debug info for
/lib/x86_64-linux-gnu/libstdc++.so.6
Downloading 0.18 MB separate debug info for
/lib/x86_64-linux-gnu/libgcc_s.so.1
Downloading 0.03 MB separate debug info for system-supplied DSO at
0x7ffdabeee000
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
--Type <RET> for more, q to quit, c to continue without paging--
Core was generated by `lttng-sessiond -vvv --verbose-consumer -b'.
Program terminated with signal SIGABRT, Aborted.
#0 __pthread_kill_implementation (no_tid=0, signo=6, threadid=140614729455104)
at ./nptl/pthread_kill.c:44
Download failed: Invalid argument. Continuing without source file
./nptl/./nptl/pthread_kill.c.
44 ./nptl/pthread_kill.c: No such file or directory.
[Current thread is 1 (Thread 0x7fe36affd600 (LWP 10479))]
(gdb) bt
#0 __pthread_kill_implementation (no_tid=0, signo=6, threadid=140614729455104)
at ./nptl/pthread_kill.c:44
#1 __pthread_kill_internal (signo=6, threadid=140614729455104) at
./nptl/pthread_kill.c:78
#2 __GI___pthread_kill (threadid=140614729455104, signo=signo at entry=6) at
./nptl/pthread_kill.c:89
#3 0x00007fe37d842476 in __GI_raise (sig=sig at entry=6) at
../sysdeps/posix/raise.c:26
#4 0x00007fe37d8287f3 in __GI_abort () at ./stdlib/abort.c:79
#5 0x00007fe37d82871b in __assert_fail_base (fmt=0x7fe37d9dd130
"%s%s%s:%u: %s%sAssertion `%s' failed.\n%n",
assertion=0x56371cd9a9ab "buf", file=0x56371cda20e7 "unix.c", line=185,
function=<optimized out>) at ./assert/assert.c:92
#6 0x00007fe37d839e96 in __GI___assert_fail (assertion=0x56371cd9a9ab
"buf", file=0x56371cda20e7 "unix.c", line=185,
function=0x56371cdc8830 "lttcomm_recv_unix_sock") at ./assert/assert.c
:101
#7 0x000056371cd561be in ?? ()
#8 0x000056371ccea96f in ?? ()
#9 0x000056371ccef7eb in ?? ()
#10 0x000056371ccf3b4c in ?? ()
#11 0x000056371cce0ab7 in ?? ()
#12 0x00007fe37d894ac3 in start_thread (arg=<optimized out>) at
./nptl/pthread_create.c:442
#13 0x00007fe37d926850 in clone3 () at
../sysdeps/unix/sysv/linux/x86_64/clone3.S:81
(gdb)
#0 __pthread_kill_implementation (no_tid=0, signo=6, threadid=140614729455104)
at ./nptl/pthread_kill.c:44
#1 __pthread_kill_internal (signo=6, threadid=140614729455104) at
./nptl/pthread_kill.c:78
#2 __GI___pthread_kill (threadid=140614729455104, signo=signo at entry=6) at
./nptl/pthread_kill.c:89
#3 0x00007fe37d842476 in __GI_raise (sig=sig at entry=6) at
../sysdeps/posix/raise.c:26
#4 0x00007fe37d8287f3 in __GI_abort () at ./stdlib/abort.c:79
#5 0x00007fe37d82871b in __assert_fail_base (fmt=0x7fe37d9dd130
"%s%s%s:%u: %s%sAssertion `%s' failed.\n%n",
assertion=0x56371cd9a9ab "buf", file=0x56371cda20e7 "unix.c", line=185,
function=<optimized out>) at ./assert/assert.c:92
#6 0x00007fe37d839e96 in __GI___assert_fail (assertion=0x56371cd9a9ab
"buf", file=0x56371cda20e7 "unix.c", line=185,
function=0x56371cdc8830 "lttcomm_recv_unix_sock") at ./assert/assert.c
:101
#7 0x000056371cd561be in ?? ()
#8 0x000056371ccea96f in ?? ()
#9 0x000056371ccef7eb in ?? ()
#10 0x000056371ccf3b4c in ?? ()
#11 0x000056371cce0ab7 in ?? ()
#12 0x00007fe37d894ac3 in start_thread (arg=<optimized out>) at
./nptl/pthread_create.c:442
#13 0x00007fe37d926850 in clone3 () at
../sysdeps/unix/sysv/linux/x86_64/clone3.S:81
On Fri, Jan 12, 2024 at 3:58 PM Kienan Stewart <kstewart at efficios.com>
wrote:
> Hi Yonghong,
>
> thanks for the extra info. As you say without the symbol resolution the
> backtrace isn't super useful.
>
> Based on the build-id in the file info for lttng-sessiond, it looks like
> you might be using the lttng/stable-2.13 ppa.
>
> In that case, you could try using debuginfod with gdb to automatically
> download the symbols. See
> https://ubuntu.com/server/docs/service-debuginfod for the instructions
> enabling the symbol download from Ubuntu's debuginfod server.
>
> thanks,
> kienan
>
> On 1/12/24 15:38, Yonghong Yan wrote:
> > Coredump is about 124MB and I am copying the backtrace of the coredump,
> > see below. Unfortunately, the sessiond is stripped and no debugging
> > info, so not able to see the the call stack that lead to the dump. guess
> > I need to build the lttng with debugging info and to get the symbol and
> > informed backtrace.
> >
> > From the log itself, it is asserted aat > > DBG1 -
> > 00:24:25.241138386 [Client management]: Setting relayd for
> >> > session auto-20240112-002417 (in cmd_setup_relayd() at
> cmd.c:1004)
> >> >
> >> > lttng-sessiond: unix.c:185: lttcomm_recv_unix_sock: Assertion
> >> `buf' failed.
> >
> > *yyan7 at CCI13SZWP3LWS*:*/var/log*$ tail apport.log
> >
> >
> > ERROR: apport (pid 3787) Fri Jan 12 10:52:37 2024: debug: session gdbus
> > call:
> >
> > ERROR: apport (pid 3787) Fri Jan 12 10:52:37 2024: this executable
> > already crashed 2 times, ignoring
> >
> > ERROR: apport (pid 10543) Fri Jan 12 15:18:07 2024: called for pid
> > 10470, signal 6, core limit 18446744073709551615, dump mode 1
> >
> > ERROR: apport (pid 10543) Fri Jan 12 15:18:07 2024: ignoring implausibly
> > big core limit, treating as unlimited
> >
> > ERROR: apport (pid 10543) Fri Jan 12 15:18:07 2024: executable:
> > /usr/bin/lttng-sessiond (command line "lttng-sessiond -vvv
> > --verbose-consumer -b")
> >
> > ERROR: apport (pid 10543) Fri Jan 12 15:18:08 2024: debug: session gdbus
> > call: (true,)
> >
> >
> > ERROR: apport (pid 10543) Fri Jan 12 15:18:08 2024: writing core dump to
> >
> core._usr_bin_lttng-sessiond.1000.8f22faa6-512c-49ca-9089-8b3f0801da8d.10470.2023109
> (limit: -1)
> >
> > ERROR: apport (pid 10543) Fri Jan 12 15:18:08 2024: this executable
> > already crashed 2 times, ignoring
> >
> > *yyan7 at CCI13SZWP3LWS*:*/var/log*$ cd /var/lib/apport/coredump
> >
> > *yyan7 at CCI13SZWP3LWS*:*/var/lib/apport/coredump*$ ls
> >
> >
> core._usr_bin_lttng-sessiond.1000.8f22faa6-512c-49ca-9089-8b3f0801da8d.10470.2023109
> >
> > *yyan7 at CCI13SZWP3LWS*:*/var/lib/apport/coredump*$ file
> >
> core._usr_bin_lttng-sessiond.1000.8f22faa6-512c-49ca-9089-8b3f0801da8d.10470.2023109
> >
> >
> core._usr_bin_lttng-sessiond.1000.8f22faa6-512c-49ca-9089-8b3f0801da8d.10470.2023109:
> ELF 64-bit LSB core file, x86-64, version 1 (SYSV), SVR4-style, from
> 'lttng-sessiond -vvv --verbose-consumer -b', real uid: 1000, effective uid:
> 1000, real gid: 1000, effective gid: 1000, execfn:
> '/usr/bin/lttng-sessiond', platform: 'x86_64'
> >
> > *yyan7 at CCI13SZWP3LWS*:*/var/lib/apport/coredump*$ du -h
> >
> core._usr_bin_lttng-sessiond.1000.8f22faa6-512c-49ca-9089-8b3f0801da8d.10470.2023109
> >
> >
> 124Mcore._usr_bin_lttng-sessiond.1000.8f22faa6-512c-49ca-9089-8b3f0801da8d.10470.2023109
> >
> > *yyan7 at CCI13SZWP3LWS*:*/var/lib/apport/coredump*$ gdb
> > /usr/bin/lttng-sessiond
> >
> core._usr_bin_lttng-sessiond.1000.8f22faa6-512c-49ca-9089-8b3f0801da8d.10470.2023109
> >
> > *GNU gdb (Ubuntu 12.1-0ubuntu1~22.04) 12.1*
> >
> > Copyright (C) 2022 Free Software Foundation, Inc.
> >
> > License GPLv3+: GNU GPL version 3 or later
> > <http://gnu.org/licenses/gpl.html <http://gnu.org/licenses/gpl.html>>
> >
> > This is free software: you are free to change and redistribute it.
> >
> > There is NO WARRANTY, to the extent permitted by law.
> >
> > Type "show copying" and "show warranty" for details.
> >
> > This GDB was configured as "x86_64-linux-gnu".
> >
> > Type "show configuration" for configuration details.
> >
> > For bug reporting instructions, please see:
> >
> > <https://www.gnu.org/software/gdb/bugs/
> > <https://www.gnu.org/software/gdb/bugs/>>.
> >
> > Find the GDB manual and other documentation resources online at:
> >
> > <http://www.gnu.org/software/gdb/documentation/
> > <http://www.gnu.org/software/gdb/documentation/>>.
> >
> >
> > For help, type "help".
> >
> > Type "apropos word" to search for commands related to "word"...
> >
> > Reading symbols from /usr/bin/lttng-sessiond...
> >
> > (No debugging symbols found in /usr/bin/lttng-sessiond)
> >
> > [New LWP 10479]
> >
> > [New LWP 10470]
> >
> > [New LWP 10476]
> >
> > [New LWP 10475]
> >
> > [New LWP 10472]
> >
> > [New LWP 10478]
> >
> > [New LWP 10480]
> >
> > [New LWP 10473]
> >
> > [New LWP 10477]
> >
> > [New LWP 10482]
> >
> > [New LWP 10542]
> >
> > [New LWP 10533]
> >
> > [New LWP 10484]
> >
> > [New LWP 10474]
> >
> > [New LWP 10481]
> >
> > [New LWP 10483]
> >
> > [Thread debugging using libthread_db enabled]
> >
> > Using host libthread_db library
> "/lib/x86_64-linux-gnu/libthread_db.so.1".
> >
> > --Type <RET> for more, q to quit, c to continue without paging--
> >
> > Core was generated by `lttng-sessiond -vvv --verbose-consumer -b'.
> >
> > Program terminated with signal SIGABRT, Aborted.
> >
> > #0__pthread_kill_implementation(no_tid=0, signo=6,
> > threadid=140614729455104) at ./nptl/pthread_kill.c:44
> >
> > 44./nptl/pthread_kill.c: No such file or directory.
> >
> > [Current thread is 1 (Thread 0x7fe36affd600 (LWP 10479))]
> >
> > (gdb) bt
> >
> > #0__pthread_kill_implementation(no_tid=0, signo=6,
> > threadid=140614729455104) at ./nptl/pthread_kill.c:44
> >
> > #1__pthread_kill_internal(signo=6, threadid=140614729455104) at
> > ./nptl/pthread_kill.c:78
> >
> > #2__GI___pthread_kill(threadid=140614729455104, signo=signo at entry=6) at
> > ./nptl/pthread_kill.c:89
> >
> > #30x00007fe37d842476in __GI_raise(sig=sig at entry=6) at
> > ../sysdeps/posix/raise.c:26
> >
> > #40x00007fe37d8287f3in __GI_abort() at ./stdlib/abort.c:79
> >
> > #50x00007fe37d82871bin __assert_fail_base(fmt=0x7fe37d9dd130 "%s%s%s:%u:
> > %s%sAssertion `%s' failed.\n%n",
> >
> > assertion=0x56371cd9a9ab "buf", file=0x56371cda20e7 "unix.c", line=185,
> > function=<optimized out>) at ./assert/assert.c:92
> >
> > #60x00007fe37d839e96in __GI___assert_fail(assertion=0x56371cd9a9ab
> > "buf", file=0x56371cda20e7 "unix.c", line=185,
> >
> > function=0x56371cdc8830 "lttcomm_recv_unix_sock") at
> ./assert/assert.c:101
> >
> > #70x000056371cd561bein ??()
> >
> > #80x000056371ccea96fin ??()
> >
> > #90x000056371ccef7ebin ??()
> >
> > #10 0x000056371ccf3b4cin ??()
> >
> > #11 0x000056371cce0ab7in ??()
> >
> > #12 0x00007fe37d894ac3in start_thread(arg=<optimized out>) at
> > ./nptl/pthread_create.c:442
> >
> > #13 0x00007fe37d926850in clone3() at
> > ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81
> >
> > (gdb) quit
> >
> > *yyan7 at CCI13SZWP3LWS*:*/var/lib/apport/coredump*$ file
> > /usr/bin/lttng-sessiond
> >
> > /usr/bin/lttng-sessiond: ELF 64-bit LSB pie executable, x86-64, version
> > 1 (SYSV), dynamically linked, interpreter /lib64/ld-linux-x86-64.so.2,
> > BuildID[sha1]=71b82210085b068b86d1252ed4f7403917af7cea, for GNU/Linux
> > 3.2.0, stripped
> >
> > *yyan7 at CCI13SZWP3LWS*:*/var/lib/apport/coredump*$
> >
> >
> > On Fri, Jan 12, 2024 at 2:31 PM Kienan Stewart <kstewart at efficios.com
> > <mailto:kstewart at efficios.com>> wrote:
> >
> > Hi Yonghong,
> >
> > thanks for the additional information. Would you be willing and able
> to
> > share a coredump and/or backtrace of the crash?
> >
> > I was still unable to reproduce the issue using the commands you
> > provided, but am interested in understanding what is happening here.
> >
> > Are there any configuration options other than LTTNG_UST_DEBUG=1 set
> in
> > your environment?
> >
> > Are you using urcu/lttng from packages (if so, which repo), or built
> > from source?
> >
> > The test case I am using now:
> >
> > ```
> > # As root
> > $ lttng-sessiond -b
> >
> > # As a non-root user which is not a member of the tracing group
> > $ export LTTNG_UST_DEBUG=1
> > $ lttng-relayd -v -b
> > $ lttng-sessiond -vvv --verbose-consumer -b
> > $ lttng create
> > $ lttng enable-event -u -a
> > ```
> >
> > thanks,
> > kienan
> >
> > P.S. In the future, could you keep the lttng-dev in CC? thanks!
> >
> > On 1/12/24 10:36, Yonghong Yan wrote:
> > > Hi Kienan,
> > >
> > > Thank you for checking. It might be just my setting problem. I
> will
> > > just send it to you before we are sure it is an issue of lttng
> > >
> > > Below is the output and steps I followed the guideline. Since I
> > started
> > > the relayd and sessiond in the same terminal, the verbose msg are
> > mixed
> > > together. I can regenerate it using two separate terminals. It is
> > a Dell
> > > Precision Tower box and it worked well yesterday. But I rebuilt
> the
> > > system yesterday (because of NVIDIA GPU driver issue), and it
> > then have
> > > this issue.
> > >
> > >
> > > *yyan7 at CCI13SZWP3LWS*:*~*$ uname -a
> > >
> > > Linux CCI13SZWP3LWS 6.5.0-14-generic #14~22.04.1-Ubuntu SMP
> > > PREEMPT_DYNAMIC Mon Nov 20 18:15:30 UTC 2 x86_64 x86_64 x86_64
> > GNU/Linux
> > >
> > > *yyan7 at CCI13SZWP3LWS*:*~*$ cat /etc/lsb-release
> > >
> > > DISTRIB_ID=Ubuntu
> > >
> > > DISTRIB_RELEASE=22.04
> > >
> > > DISTRIB_CODENAME=jammy
> > >
> > > DISTRIB_DESCRIPTION="Ubuntu 22.04.3 LTS"
> > >
> > > *yyan7 at CCI13SZWP3LWS*:*~*$ lttng --version
> > >
> > > lttng (LTTng Trace Control) 2.13.10 - Nordicité
> > >
> > > *yyan7 at CCI13SZWP3LWS*:*~*$ lsmod | grep lttng
> > >
> > > *lttng*_probe_writeback614400
> > >
> > > *lttng*_probe_workqueue204800
> > >
> > > *lttng*_probe_vmscan 450560
> > >
> > > *lttng*_probe_udp122880
> > >
> > > *lttng*_probe_timer327680
> > >
> > > *lttng*_probe_sunrpc 204800
> > >
> > > *lttng*_probe_statedump573440
> > >
> > > *lttng*_probe_sock 163840
> > >
> > > *lttng*_probe_skb163840
> > >
> > > *lttng*_probe_signal 163840
> > >
> > > *lttng*_probe_scsi 204800
> > >
> > > *lttng*_probe_sched450560
> > >
> > > *lttng*_probe_regulator204800
> > >
> > > *lttng*_probe_rcu122880
> > >
> > > *lttng*_probe_printk 122880
> > >
> > > *lttng*_probe_power204800
> > >
> > > *lttng*_probe_net327680
> > >
> > > *lttng*_probe_napi 122880
> > >
> > > *lttng*_probe_module 204800
> > >
> > > *lttng*_probe_kvm368640
> > >
> > > *lttng*_probe_jbd2 327680
> > >
> > > *lttng*_probe_irq163840
> > >
> > > *lttng*_probe_gpio 122880
> > >
> > > *lttng*_probe_block409600
> > >
> > > *lttng*_probe_asoc 368640
> > >
> > > *lttng*_counter_client_percpu_32_modular122880
> > >
> > > *lttng*_counter_client_percpu_64_modular122881
> > >
> > > *lttng*_counter163842
> > >
> >
> *lttng*_counter_client_percpu_64_modular,*lttng*_counter_client_percpu_32_modular
> > >
> > > *lttng*_ring_buffer_event_notifier_client204802
> > >
> > > *lttng*_ring_buffer_metadata_mmap_client204800
> > >
> > > *lttng*_ring_buffer_client_mmap_overwrite245760
> > >
> > > *lttng*_ring_buffer_client_mmap_discard245760
> > >
> > > *lttng*_ring_buffer_metadata_client204800
> > >
> > > *lttng*_ring_buffer_client_overwrite245760
> > >
> > > *lttng*_ring_buffer_client_discard245760
> > >
> > > *lttng*_tracer 303513637
> > >
> >
> *lttng*_probe_udp,*lttng*_probe_scsi,*lttng*_probe_sched,*lttng*_probe_net,*lttng*_probe_vmscan,*lttng*_probe_writeback,*lttng*_probe_power,*lttng*_probe_rcu,*lttng*_probe_module,*lttng*_ring_buffer_client_mmap_overwrite,*lttng*_probe_statedump,*lttng*_ring_buffer_client_discard,*lttng*_probe_printk,*lttng*_probe_sock,*lttng*_probe_asoc,*lttng*_counter_client_percpu_64_modular,*lttng*_probe_irq,*lttng*_ring_buffer_client_mmap_discard,*lttng*_probe_kvm,*lttng*_probe_timer,*lttng*_ring_buffer_event_notifier_client,*lttng*_counter_client_percpu_32_modular,*lttng*_probe_workqueue,*lttng*_probe_jbd2,*lttng*_probe_signal,*lttng*_probe_skb,*lttng*_probe_block,*lttng*_probe_napi,*lttng*_ring_buffer_metadata_client,*lttng*_ring_buffer_metadata_mmap_client,*lttng*_probe_gpio,*lttng*_ring_buffer_client_overwrite,*lttng*_probe_regulator,*lttng*_probe_sunrpc
> > >
> > > *lttng*_statedump 7536641 *lttng*_tracer
> > >
> > > *lttng*_wrapper163847
> > >
> >
> *lttng*_statedump,*lttng*_probe_writeback,*lttng*_ring_buffer_client_mmap_overwrite,*lttng*_ring_buffer_client_discard,*lttng*_tracer,*lttng*_ring_buffer_client_mmap_discard,*lttng*_ring_buffer_client_overwrite
> > >
> > > *lttng*_uprobes163841 *lttng*_tracer
> > >
> > > *lttng*_clock122885
> > >
> >
> *lttng*_ring_buffer_client_mmap_overwrite,*lttng*_ring_buffer_client_discard,*lttng*_tracer,*lttng*_ring_buffer_client_mmap_discard,*lttng*_ring_buffer_client_overwrite
> > >
> > > *lttng*_kprobes163841 *lttng*_tracer
> > >
> > > *lttng*_lib_ring_buffer942088
> > >
> >
> *lttng*_ring_buffer_client_mmap_overwrite,*lttng*_ring_buffer_client_discard,*lttng*_tracer,*lttng*_ring_buffer_client_mmap_discard,*lttng*_ring_buffer_event_notifier_client,*lttng*_ring_buffer_metadata_client,*lttng*_ring_buffer_metadata_mmap_client,*lttng*_ring_buffer_client_overwrite
> > >
> > > *lttng*_kretprobes 163841 *lttng*_tracer
> > >
> > > *yyan7 at CCI13SZWP3LWS*:*~*$ export LTTNG_UST_DEBUG=1
> > >
> > > *yyan7 at CCI13SZWP3LWS*:*~*$ lttng-relayd -v -b
> > >
> > > DBG1 - 10:24:56.244818657 [3495/3495]: File descriptor count
> > limits are
> > > 1024 (soft) and 1048576 (hard) (in set_fd_pool_size() at
> main.c:481)
> > >
> > > DBG1 - 10:24:56.244870031 [3495/3495]: Signal handler set for
> > SIGTERM,
> > > SIGUSR1, SIGPIPE and SIGINT (in set_signal_handler() at
> main.c:872)
> > >
> > > DBG1 - 10:24:56.244877662 [3495/3495]: LTTng-relayd 2.13.10 -
> > Nordicité
> > > (in relayd_config_log() at main.c:206)
> > >
> > > DBG1 - 10:24:56.244885255 [3495/3495]: Clear command allowed (in
> > main()
> > > at main.c:4294)
> > >
> > > DBG1 - 10:24:56.245867168 [3496/3496]: Unlinked file pool created
> > at:
> > > /home/yyan7/lttng-traces//.unlinked (in
> > > lttng_unlinked_file_pool_create() at inode.c:268)
> > >
> > > DBG1 - 10:24:56.245903674 [3496/3496]: File descriptor tracker
> > created
> > > with a limit of 1014 simultaneously-opened FDs (in
> > fd_tracker_create()
> > > at fd-tracker.c:400)
> > >
> > > DBG1 - 10:24:56.245925508 [3496/3496]: Health check time delta in
> > > seconds set to 20 (in health_init() at health.c:62)
> > >
> > > DBG1 - 10:24:56.245998123 [3496/3496]: TCP inet operation timeout
> > set to
> > > 216 sec (in lttcomm_inet_init() at inet.c:545)
> > >
> > > DBG1 - 10:24:56.246177304 [3496/3498]: [thread] Manage health
> check
> > > started (in thread_manage_health() at health-relayd.c:273)
> > >
> > > DBG1 - 10:24:56.246222966 [3496/3499]: [thread] Relay dispatcher
> > started
> > > (in relay_thread_dispatcher() at main.c:1291)
> > >
> > > DBG1 - 10:24:56.246259512 [3496/3499]: Futex n to 1 prepare done
> (in
> > > futex_nto1_prepare() at futex.c:67)
> > >
> > > DBG1 - 10:24:56.246266232 [3496/3496]: epoll set max size is
> > 7225299 (in
> > > compat_epoll_set_max_size() at poll.c:350)
> > >
> > > DBG1 - 10:24:56.246272226 [3496/3499]: Woken up but nothing in
> > the relay
> > > command queue (in relay_thread_dispatcher() at main.c:1318)
> > >
> > > DBG1 - 10:24:56.246224883 [3496/3500]: [thread] Relay worker
> > started (in
> > > relay_thread_worker() at main.c:3913)
> > >
> > > DBG1 - 10:24:56.246332173 [3496/3501]: [thread] Relay listener
> > started
> > > (in relay_thread_listener() at main.c:1089)
> > >
> > > DBG1 - 10:24:56.246489021 [3496/3498]: Health check ready (in
> > > thread_manage_health() at health-relayd.c:364)
> > >
> > > DBG1 - 10:24:56.246530206 [3496/3501]: Listening on Control
> listener
> > > socket 13 (in relay_socket_create() at main.c:1033)
> > >
> > > DBG1 - 10:24:56.246595589 [3496/3501]: Listening on Data listener
> > socket
> > > 14 (in relay_socket_create() at main.c:1033)
> > >
> > > DBG1 - 10:24:56.246623642 [3496/3501]: Listener accepting
> > connections
> > > (in relay_thread_listener() at main.c:1136)
> > >
> > > DBG1 - 10:24:56.246619116 [3496/3502]: [thread] Live viewer relay
> > > dispatcher started (in thread_dispatcher() at live.c:849)
> > >
> > > DBG1 - 10:24:56.246652489 [3496/3502]: Futex n to 1 prepare done
> (in
> > > futex_nto1_prepare() at futex.c:67)
> > >
> > > DBG1 - 10:24:56.246662832 [3496/3502]: Woken up but nothing in the
> > > live-viewer relay command queue (in thread_dispatcher() at
> > live.c:876)
> > >
> > > DBG1 - 10:24:56.246681238 [3496/3503]: [thread] Live viewer relay
> > worker
> > > started (in thread_worker() at live.c:2451)
> > >
> > > DBG1 - 10:24:56.246694646 [3496/3504]: [thread] Relay live
> listener
> > > started (in thread_listener() at live.c:686)
> > >
> > > DBG1 - 10:24:56.246845536 [3496/3504]: Listening on Live listener
> > socket
> > > 16 (in init_socket() at live.c:650)
> > >
> > > DBG1 - 10:24:56.246891901 [3496/3504]: Listener accepting live
> > viewers
> > > connections (in thread_listener() at live.c:720)
> > >
> > > *yyan7 at CCI13SZWP3LWS*:*~*$ lttng-sessiond -vvv
> --verbose-consumer -b
> > >
> > > libringbuffer-clients[3505/3505]: LTT : ltt ring buffer client
> > > "relay-metadata-mmap" init
> > >
> > > (in lttng_ring_buffer_metadata_client_init() at
> > > ../../src/common/ringbuffer-clients/metadata-template.h:364)
> > >
> > > libringbuffer-clients[3505/3505]: LTT : ltt ring buffer client
> > > "relay-overwrite-mmap" init
> > >
> > > (in lttng_ring_buffer_client_overwrite_init() at
> > > ../../src/common/ringbuffer-clients/template.h:826)
> > >
> > > libringbuffer-clients[3505/3505]: LTT : ltt ring buffer client
> > > "relay-overwrite-rt-mmap" init
> > >
> > > (in lttng_ring_buffer_client_overwrite_rt_init() at
> > > ../../src/common/ringbuffer-clients/template.h:826)
> > >
> > > libringbuffer-clients[3505/3505]: LTT : ltt ring buffer client
> > > "relay-discard-mmap" init
> > >
> > > (in lttng_ring_buffer_client_discard_init() at
> > > ../../src/common/ringbuffer-clients/template.h:826)
> > >
> > > libringbuffer-clients[3505/3505]: LTT : ltt ring buffer client
> > > "relay-discard-rt-mmap" init
> > >
> > > (in lttng_ring_buffer_client_discard_rt_init() at
> > > ../../src/common/ringbuffer-clients/template.h:826)
> > >
> > > DBG1 - 10:25:05.693401139 [Main]: [sessiond configuration]
> > >
> > > DBG1 - 10:25:05.693458872 [Main]: version2.13.10
> > >
> > > DBG1 - 10:25:05.693469176 [Main]: verbose: 3
> > >
> > > DBG1 - 10:25:05.693476719 [Main]: verbose consumer:1
> > >
> > > DBG1 - 10:25:05.693486867 [Main]: quiet mode:False
> > >
> > > DBG1 - 10:25:05.693493268 [Main]: agent_tcp_port:[5345, 5354]
> > >
> > > DBG1 - 10:25:05.693501264 [Main]: application socket timeout:5
> > >
> > > DBG1 - 10:25:05.693506511 [Main]: no-kernel: False
> > >
> > > DBG1 - 10:25:05.693511705 [Main]: background:True
> > >
> > > DBG1 - 10:25:05.693517223 [Main]: daemonize: False
> > >
> > > DBG1 - 10:25:05.693522427 [Main]: signal parent on start:False
> > >
> > > DBG1 - 10:25:05.693527446 [Main]: tracing group name:tracing
> > >
> > > DBG1 - 10:25:05.693535560 [Main]: kmod_probe_list: None
> > >
> > > DBG1 - 10:25:05.693545390 [Main]: kmod_extra_probe_list: None
> > >
> > > DBG1 - 10:25:05.693550476 [Main]: rundir:/home/yyan7/.lttng
> > >
> > > DBG1 - 10:25:05.693558977 [Main]: application socket path:
> > > /home/yyan7/.lttng/lttng-ust-sock-8
> > >
> > > DBG1 - 10:25:05.693564632 [Main]: client socket
> > > path:/home/yyan7/.lttng/client-lttng-sessiond
> > >
> > > DBG1 - 10:25:05.693573771 [Main]: wait shm path:
> > /lttng-ust-wait-8-1000
> > >
> > > DBG1 - 10:25:05.693581196 [Main]: health socket
> > > path:/home/yyan7/.lttng/sessiond-health
> > >
> > > DBG1 - 10:25:05.693592417 [Main]: LTTNG_UST_CLOCK_PLUGIN:None
> > >
> > > DBG1 - 10:25:05.693599715 [Main]: pid file path:
> > > /home/yyan7/.lttng/lttng-sessiond.pid
> > >
> > > DBG1 - 10:25:05.693611177 [Main]: lock file
> > > path:/home/yyan7/.lttng/lttng-sessiond.lck
> > >
> > > DBG1 - 10:25:05.693618666 [Main]: session load path: None
> > >
> > > DBG1 - 10:25:05.693625291 [Main]: agent port file
> > > path:/home/yyan7/.lttng/agent.port
> > >
> > > DBG1 - 10:25:05.693632721 [Main]: consumerd32
> > > path:/home/yyan7/.lttng/ustconsumerd32
> > >
> > > DBG1 - 10:25:05.693640982 [Main]: consumerd32 bin path:Unknown
> > >
> > > DBG1 - 10:25:05.693648470 [Main]: consumerd32 lib dir: Unknown
> > >
> > > DBG1 - 10:25:05.693653601 [Main]: consumerd32 err unix sock
> > > path:/home/yyan7/.lttng/ustconsumerd32/error
> > >
> > > DBG1 - 10:25:05.693660355 [Main]: consumerd32 cmd unix sock
> > > path:/home/yyan7/.lttng/ustconsumerd32/command
> > >
> > > DBG1 - 10:25:05.693668191 [Main]: consumerd64
> > > path:/home/yyan7/.lttng/ustconsumerd64
> > >
> > > DBG1 - 10:25:05.693673539 [Main]: consumerd64 bin
> > > path:/usr/lib/x86_64-linux-gnu/lttng/libexec/lttng-consumerd
> > >
> > > DBG1 - 10:25:05.693682080 [Main]: consumerd64 lib dir:
> > > /usr/lib/x86_64-linux-gnu
> > >
> > > DBG1 - 10:25:05.693689246 [Main]: consumerd64 err unix sock
> > > path:/home/yyan7/.lttng/ustconsumerd64/error
> > >
> > > DBG1 - 10:25:05.693697419 [Main]: consumerd64 cmd unix sock
> > > path:/home/yyan7/.lttng/ustconsumerd64/command
> > >
> > > DBG1 - 10:25:05.693706980 [Main]: kconsumerd path:
> > > /home/yyan7/.lttng/kconsumerd
> > >
> > > DBG1 - 10:25:05.693714339 [Main]: kconsumerd err unix sock path:
> > > /home/yyan7/.lttng/kconsumerd/error
> > >
> > > DBG1 - 10:25:05.693724836 [Main]: kconsumerd cmd unix sock path:
> > > /home/yyan7/.lttng/kconsumerd/command
> > >
> > > DBG1 - 10:25:05.693736058 [Main]: Starting lttng-sessiond
> > > {0e76c943-cc93-414c-81d5-259bf7e8d0e4} (in sessiond_uuid_log() at
> > > main.c:1437)
> > >
> > > DBG3 - 10:25:05.693744764 [Main]: Creating LTTng run directory:
> > > /home/yyan7/.lttng (in create_lttng_rundir() at main.c:1069)
> > >
> > > DBG1 - 10:25:05.696358185 [Main]: Resetting run_as worker signal
> > > handlers to default (in reset_sighandler() at runas.c:1377)
> > >
> > > DBG1 - 10:25:05.696480798 [Main]: run_as signal handler set for
> > SIGTERM
> > > and SIGINT (in set_worker_sighandlers() at runas.c:1438)
> > >
> > > DBG1 - 10:25:05.697495897 [Main]: Health check time delta in
> > seconds set
> > > to 20 (in health_init() at health.c:62)
> > >
> > > DBG1 - 10:25:05.697824357 [HT cleanup]: Entering thread entry
> > point (in
> > > launch_thread() at thread.c:65)
> > >
> > > DBG1 - 10:25:05.697915191 [HT cleanup]: startup. (in
> > thread_ht_cleanup()
> > > at ht-cleanup.c:98)
> > >
> > > DBG1 - 10:25:05.697964263 [HT cleanup]: epoll set max size is
> > 7225299
> > > (in compat_epoll_set_max_size() at poll.c:350)
> > >
> > > DBG3 - 10:25:05.698012958 [Main]: Created hashtable size 4 at
> > > 0x5627de049140 of type ULONG (in lttng_ht_new() at
> hashtable.c:152)
> > >
> > > DBG3 - 10:25:05.698041846 [Main]: Created hashtable size 4 at
> > > 0x5627de049470 of type ULONG (in lttng_ht_new() at
> hashtable.c:152)
> > >
> > > DBG3 - 10:25:05.698056225 [Main]: Created hashtable size 4 at
> > > 0x5627de04bcd0 of type ULONG (in lttng_ht_new() at
> hashtable.c:152)
> > >
> > > DBG3 - 10:25:05.698065318 [HT cleanup]: Polling. (in
> > thread_ht_cleanup()
> > > at ht-cleanup.c:122)
> > >
> > > DBG3 - 10:25:05.698087629 [Main]: Created hashtable size 16 at
> > > 0x5627de04cf80 of type U64 (in lttng_ht_new() at hashtable.c:152)
> > >
> > > DBG3 - 10:25:05.698104568 [Main]: Created hashtable size 16 at
> > > 0x5627de04e230 of type U64 (in lttng_ht_new() at hashtable.c:152)
> > >
> > > DBG3 - 10:25:05.698117477 [Main]: Created hashtable size 16 at
> > > 0x5627de04f630 of type U64 (in lttng_ht_new() at hashtable.c:152)
> > >
> > > DBG3 - 10:25:05.698127087 [Main]: Created hashtable size 4 at
> > > 0x5627de050a50 of type ULONG (in lttng_ht_new() at
> hashtable.c:152)
> > >
> > > DBG3 - 10:25:05.698142843 [Main]: Created hashtable size 4 at
> > > 0x5627de051d90 of type U64 (in lttng_ht_new() at hashtable.c:152)
> > >
> > > DBG2 - 10:25:05.698158685 [Main]: Creating consumer directory:
> > > /home/yyan7/.lttng/ustconsumerd64 (in set_consumer_sockets() at
> > main.c:1111)
> > >
> > > DBG2 - 10:25:05.698296819 [Main]: Creating consumer directory:
> > > /home/yyan7/.lttng/ustconsumerd32 (in set_consumer_sockets() at
> > main.c:1111)
> > >
> > > DBG3 - 10:25:05.698395187 [Main]: Created hashtable size 4 at
> > > 0x5627de0530d0 of type U64 (in lttng_ht_new() at hashtable.c:152)
> > >
> > > DBG3 - 10:25:05.698404718 [Main]: Global buffer per UID registry
> > > initialized (in buffer_reg_init_uid_registry() at
> > buffer-registry.c:90)
> > >
> > > DBG3 - 10:25:05.698427501 [Main]: Created hashtable size 4 at
> > > 0x5627de054410 of type U64 (in lttng_ht_new() at hashtable.c:152)
> > >
> > > DBG3 - 10:25:05.698435763 [Main]: Global buffer per PID registry
> > > initialized (in buffer_reg_init_pid_registry() at
> > buffer-registry.c:219)
> > >
> > > DBG1 - 10:25:05.698444533 [Main]: Command subsystem initialized
> (in
> > > cmd_init() at cmd.c:6090)
> > >
> > > DBG1 - 10:25:05.698503908 [Main]: '3506' written in file
> > > /home/yyan7/.lttng/lttng-sessiond.pid (in utils_create_pid_file()
> at
> > > utils.c:257)
> > >
> > > DBG1 - 10:25:05.698588286 [Main]: TCP inet operation timeout set
> > to 216
> > > sec (in lttcomm_inet_init() at inet.c:545)
> > >
> > > DBG1 - 10:25:05.698688270 [Main]: Waiting for health management
> > thread
> > > to be ready (in wait_until_thread_is_ready() at health.c:35)
> > >
> > > DBG1 - 10:25:05.698771494 [Health management]: Entering thread
> entry
> > > point (in launch_thread() at thread.c:65)
> > >
> > > DBG1 - 10:25:05.698803482 [Health management]: [thread] Manage
> > health
> > > check started (in thread_manage_health() at health.c:65)
> > >
> > > DBG1 - 10:25:05.698964797 [Health management]: Marking health
> > management
> > > thread as ready (in mark_thread_as_ready() at health.c:28)
> > >
> > > DBG1 - 10:25:05.698981598 [Health management]: Health check ready
> > (in
> > > thread_manage_health() at health.c:136)
> > >
> > > DBG1 - 10:25:05.698991179 [Main]: Health management thread is
> > ready (in
> > > wait_until_thread_is_ready() at health.c:37)
> > >
> > > DBG1 - 10:25:05.699062770 [Main]: Waiting for notification thread
> > to be
> > > ready (in wait_until_thread_is_ready() at
> notification-thread.c:414)
> > >
> > > DBG1 - 10:25:05.699151645 [Notification]: Entering thread entry
> > point
> > > (in launch_thread() at thread.c:65)
> > >
> > > DBG1 - 10:25:05.699184431 [Notification]: Started notification
> > thread
> > > (in thread_notification() at notification-thread.c:642)
> > >
> > > DBG1 - 10:25:05.699255526 [Notification]: Creating notification
> > channel
> > > UNIX socket at /home/yyan7/.lttng/sessiond-notification (in
> > > notification_channel_socket_create() at notification-thread.c:223)
> > >
> > > DBG1 - 10:25:05.699357295 [Notification]: Notification channel
> UNIX
> > > socket created (fd = 29) (in notification_channel_socket_create()
> at
> > > notification-thread.c:258)
> > >
> > > DBG1 - 10:25:05.699387109 [Notification]: Listening on
> notification
> > > channel socket (in init_thread_state() at
> notification-thread.c:442)
> > >
> > > DBG1 - 10:25:05.699561257 [Notification]: Marking notification
> > thread as
> > > ready (in mark_thread_as_ready() at notification-thread.c:407)
> > >
> > > DBG1 - 10:25:05.699576135 [Notification]: Entering poll wait (in
> > > thread_notification() at notification-thread.c:668)
> > >
> > > DBG1 - 10:25:05.699592002 [Main]: Notification thread is ready (in
> > > wait_until_thread_is_ready() at notification-thread.c:416)
> > >
> > > DBG1 - 10:25:05.699600050 [Action Executor]: Entering thread
> > entry point
> > > (in launch_thread() at thread.c:65)
> > >
> > > DBG1 - 10:25:05.699632561 [Action Executor]: Entering work
> execution
> > > loop (in action_executor_thread() at action-executor.c:761)
> > >
> > > DBG1 - 10:25:05.699643395 [Action Executor]: No work items
> enqueued,
> > > entering wait (in action_executor_thread() at
> action-executor.c:770)
> > >
> > > DBG1 - 10:25:05.699750672 [Timer]: Entering thread entry point (in
> > > launch_thread() at thread.c:65)
> > >
> > > DBG1 - 10:25:05.699770466 [Rotation]: Entering thread entry point
> > (in
> > > launch_thread() at thread.c:65)
> > >
> > > DBG1 - 10:25:05.699793428 [Main]: Created client socket (fd = 35)
> > (in
> > > create_client_sock() at client.c:2435)
> > >
> > > DBG1 - 10:25:05.699796906 [Rotation]: Started rotation thread (in
> > > thread_rotation() at rotation-thread.c:840)
> > >
> > > DBG1 - 10:25:05.699868561 [Main]: Waiting for client thread to be
> > ready
> > > (in wait_thread_status() at client.c:65)
> > >
> > > DBG1 - 10:25:05.699906378 [Client management]: Entering thread
> entry
> > > point (in launch_thread() at thread.c:65)
> > >
> > > DBG1 - 10:25:05.699943442 [Client management]: [thread] Manage
> > client
> > > started (in thread_manage_clients() at client.c:2468)
> > >
> > > DBG1 - 10:25:05.700053570 [Client management]: Marking client
> > thread's
> > > state as running (in set_thread_status() at client.c:58)
> > >
> > > DBG1 - 10:25:05.700067760 [Client management]: Accepting client
> > command
> > > ... (in thread_manage_clients() at client.c:2534)
> > >
> > > DBG1 - 10:25:05.700076510 [Main]: Client thread is ready (in
> > > wait_thread_status() at client.c:68)
> > >
> > > DBG1 - 10:25:05.700180769 [UST registration dispatch]: Entering
> > thread
> > > entry point (in launch_thread() at thread.c:65)
> > >
> > > DBG3 - 10:25:05.700197002 [Main]: Session daemon application
> socket
> > > created (fd = 41)(in create_application_socket() at register.c:71)
> > >
> > > DBG1 - 10:25:05.700203416 [UST registration dispatch]: [thread]
> > Dispatch
> > > UST command started (in thread_dispatch_ust_registration() at
> > > dispatch.c:250)
> > >
> > > DBG1 - 10:25:05.700205198 [Notification]: Poll wait returned (1)
> (in
> > > thread_notification() at notification-thread.c:670)
> > >
> > > DBG1 - 10:25:05.700255843 [Notification]: Handling fd (29)
> > activity (1)
> > > (in thread_notification() at notification-thread.c:694)
> > >
> > > DBG1 - 10:25:05.700269799 [Notification]: Handling new
> notification
> > > channel client connection (in
> > > handle_notification_thread_client_connect() at
> > > notification-thread-events.c:3351)
> > >
> > > DBG1 - 10:25:05.700262016 [Main]: Waiting for application
> > registration
> > > thread to be ready (in wait_thread_status() at register.c:131)
> > >
> > > DBG1 - 10:25:05.700236776 [UST registration dispatch]: Futex n to
> 1
> > > prepare done (in futex_nto1_prepare() at futex.c:67)
> > >
> > > DBG1 - 10:25:05.700308063 [Notification]: Client socket (fd = 42)
> > set as
> > > non-blocking (in socket_set_non_blocking() at
> > > notification-thread-events.c:3319)
> > >
> > > DBG1 - 10:25:05.700319396 [UST registration dispatch]: Woken up
> but
> > > nothing in the UST command queue (in
> > thread_dispatch_ust_registration()
> > > at dispatch.c:279)
> > >
> > > DBG1 - 10:25:05.700326116 [Notification]: Added new notification
> > channel
> > > client socket (42) to poll set (in
> > > handle_notification_thread_client_connect() at
> > > notification-thread-events.c:3404)
> > >
> > > DBG1 - 10:25:05.700372936 [Notification]: Entering poll wait (in
> > > thread_notification() at notification-thread.c:668)
> > >
> > > DBG1 - 10:25:05.700383798 [Notification]: Poll wait returned (1)
> (in
> > > thread_notification() at notification-thread.c:670)
> > >
> > > DBG1 - 10:25:05.700391774 [Notification]: Handling fd (42)
> > activity (1)
> > > (in thread_notification() at notification-thread.c:694)
> > >
> > > DBG1 - 10:25:05.700405519 [Notification]: Entering poll wait (in
> > > thread_notification() at notification-thread.c:668)
> > >
> > > DBG1 - 10:25:05.700416164 [Notification]: Poll wait returned (1)
> (in
> > > thread_notification() at notification-thread.c:670)
> > >
> > > DBG1 - 10:25:05.700424451 [Notification]: Handling fd (42)
> > activity (1)
> > > (in thread_notification() at notification-thread.c:694)
> > >
> > > DBG1 - 10:25:05.700439076 [Notification]: Received handshake from
> > > client: uid = 1000, gid = 1000, protocol version = 1.1, client is
> > > sessiond = true (in client_handle_message_handshake() at
> > > notification-thread-events.c:3879)
> > >
> > > DBG1 - 10:25:05.700450858 [Notification]: Send command reply (0)
> (in
> > > client_send_command_reply() at notification-thread-events.c:3755)
> > >
> > > DBG1 - 10:25:05.700460524 [Notification]: Flushing client (socket
> > fd =
> > > 42) outgoing queue (in client_flush_outgoing_queue() at
> > > notification-thread-events.c:3644)
> > >
> > > DBG1 - 10:25:05.700475786 [Notification]: Entering poll wait (in
> > > thread_notification() at notification-thread.c:668)
> > >
> > > DBG1 - 10:25:05.700505488 [Rotation]: Entering poll wait (in
> > > thread_rotation() at rotation-thread.c:864)
> > >
> > > DBG1 - 10:25:05.700506992 [UST application registration]: Entering
> > > thread entry point (in launch_thread() at thread.c:65)
> > >
> > > DBG1 - 10:25:05.700529647 [UST application registration]: [thread]
> > > Manage application registration started (in
> > > thread_application_registration() at register.c:168)
> > >
> > > DBG1 - 10:25:05.700597995 [UST application registration]: Marking
> > > application registration thread's state as running (in
> > > set_thread_status() at register.c:124)
> > >
> > > DBG1 - 10:25:05.700609984 [UST application registration]:
> Accepting
> > > application registration (in thread_application_registration() at
> > > register.c:207)
> > >
> > > DBG1 - 10:25:05.700616363 [Main]: Application registration thread
> is
> > > ready (in wait_thread_status() at register.c:134)
> > >
> > > DBG1 - 10:25:05.700627641 [Main]: Notifying applications of
> session
> > > daemon state: 1 (in notify_ust_apps() at register.c:91)
> > >
> > > DBG1 - 10:25:05.700659113 [Main]: Wait shared memory file
> descriptor
> > > created successfully: path = '/lttng-ust-wait-8-1000', mmap_size
> > = 4096,
> > > global = false, fd = 45 (in get_wait_shm() at shm.c:133)
> > >
> > > DBG1 - 10:25:05.700688620 [Main]: Futex wait update active 1 (in
> > > futex_wait_update() at futex.c:55)
> > >
> > > DBG1 - 10:25:05.700795964 [UST application management]: Entering
> > thread
> > > entry point (in launch_thread() at thread.c:65)
> > >
> > > DBG1 - 10:25:05.700824549 [UST application management]: [thread]
> > Manage
> > > application started (in thread_application_management() at
> > manage-apps.c:52)
> > >
> > > DBG1 - 10:25:05.700848435 [Application notification]: Entering
> > thread
> > > entry point (in launch_thread() at thread.c:65)
> > >
> > > DBG1 - 10:25:05.700866212 [Application notification]: [ust-thread]
> > > Manage application notify command (in
> > thread_application_notification()
> > > at notify-apps.c:39)
> > >
> > > DBG1 - 10:25:05.700913055 [Main]: Waiting for agent management
> > thread to
> > > be ready (in wait_until_thread_is_ready() at agent-thread.c:348)
> > >
> > > DBG1 - 10:25:05.700936679 [Agent management]: Entering thread
> entry
> > > point (in launch_thread() at thread.c:65)
> > >
> > > DBG3 - 10:25:05.700952021 [Application notification]: [ust-thread]
> > > Manage notify polling (in thread_application_notification() at
> > > notify-apps.c:74)
> > >
> > > DBG1 - 10:25:05.700964639 [UST application management]: Apps
> thread
> > > polling (in thread_application_management() at manage-apps.c:88)
> > >
> > > DBG1 - 10:25:05.700955328 [Agent management]: Manage agent
> > application
> > > registration. (in thread_agent_management() at agent-thread.c:366)
> > >
> > > DBG3 - 10:25:05.701062072 [Agent management]: URI string:
> > > tcp://localhost (in uri_parse() at uri.c:298)
> > >
> > > DBG2 - 10:25:05.701282226 [Agent management]: IP address resolved
> to
> > > 127.0.0.1 (in set_ip_address() at uri.c:155)
> > >
> > > DBG3 - 10:25:05.701292578 [Agent management]: URI dtype: 1,
> > proto: 1,
> > > host: localhost, subdir: , ctrl: 0, data: 0 (in uri_parse() at
> > uri.c:510)
> > >
> > > DBG3 - 10:25:05.701314205 [Agent management]: Trying to bind on
> port
> > > 5345 (in init_tcp_socket() at agent-thread.c:140)
> > >
> > > DBG1 - 10:25:05.701330622 [Agent management]: Failed to bind to
> port
> > > 5345 since it is already in use (in init_tcp_socket() at
> > agent-thread.c:148)
> > >
> > > DBG3 - 10:25:05.701338804 [Agent management]: Trying to bind on
> port
> > > 5346 (in init_tcp_socket() at agent-thread.c:140)
> > >
> > > DBG1 - 10:25:05.701351367 [Agent management]: Listening on TCP
> > port 5346
> > > and socket 54 (in init_tcp_socket() at agent-thread.c:177)
> > >
> > > DBG1 - 10:25:05.701413970 [Agent management]: '5346' written in
> file
> > > /home/yyan7/.lttng/agent.port (in utils_create_pid_file() at
> > utils.c:257)
> > >
> > > DBG1 - 10:25:05.701452432 [Agent management]: Marking agent
> > management
> > > thread as ready (in mark_thread_as_ready() at agent-thread.c:341)
> > >
> > > DBG3 - 10:25:05.701466232 [Agent management]: Manage agent
> > polling (in
> > > thread_agent_management() at agent-thread.c:421)
> > >
> > > DBG1 - 10:25:05.701544565 [Main]: Agent management thread is
> > ready (in
> > > wait_until_thread_is_ready() at agent-thread.c:350)
> > >
> > > libringbuffer-clients[3505/3505]: LTT : ltt ring buffer client
> > > "relay-discard-rt-mmap" exit
> > >
> > > (in lttng_ring_buffer_client_discard_rt_exit() at
> > > ../../src/common/ringbuffer-clients/template.h:833)
> > >
> > > libringbuffer-clients[3505/3505]: LTT : ltt ring buffer client
> > > "relay-discard-mmap" exit
> > >
> > > (in lttng_ring_buffer_client_discard_exit() at
> > > ../../src/common/ringbuffer-clients/template.h:833)
> > >
> > > libringbuffer-clients[3505/3505]: LTT : ltt ring buffer client
> > > "relay-overwrite-rt-mmap" exit
> > >
> > > (in lttng_ring_buffer_client_overwrite_rt_exit() at
> > > ../../src/common/ringbuffer-clients/template.h:833)
> > >
> > > libringbuffer-clients[3505/3505]: LTT : ltt ring buffer client
> > > "relay-overwrite-mmap" exit
> > >
> > > (in lttng_ring_buffer_client_overwrite_exit() at
> > > ../../src/common/ringbuffer-clients/template.h:833)
> > >
> > > libringbuffer-clients[3505/3505]: LTT : ltt ring buffer client
> > > "relay-metadata-mmap" exit
> > >
> > > (in lttng_ring_buffer_metadata_client_exit() at
> > > ../../src/common/ringbuffer-clients/metadata-template.h:371)
> > >
> > > *yyan7 at CCI13SZWP3LWS*:*~*$ ps -ef | grep lttng
> > >
> > > root 760 10 09:40 ?00:00:00 /usr/bin/*lttng*-sessiond
> > >
> > > root 808 7600 09:40 ?00:00:00 /usr/bin/*lttng*-sessiond
> > >
> > > yyan7 3496 10 10:24 ?00:00:00 *lttng*-relayd -v -b
> > >
> > > yyan7 3506 10 10:25 ?00:00:00 *lttng*-sessiond -vvv
> > --verbose-consumer -b
> > >
> > > yyan7 350735060 10:25 ?00:00:00 *lttng*-sessiond -vvv
> > --verbose-consumer -b
> > >
> > > yyan7 352229970 10:25 pts/000:00:00 grep --color=auto *lttng*
> > >
> > > *yyan7 at CCI13SZWP3LWS*:*~*$ lttng create
> > >
> > > DBG1 - 10:25:35.436359096 [Client management]: Wait for client
> > response
> > > (in thread_manage_clients() at client.c:2576)
> > >
> > > DBG1 - 10:25:35.436403534 [Client management]: Receiving data from
> > > client ... (in thread_manage_clients() at client.c:2604)
> > >
> > > DBG1 - 10:25:35.436419086 [Client management]: Incomplete recv()
> > from
> > > client... continuing (in thread_manage_clients() at client.c:2608)
> > >
> > > DBG1 - 10:25:35.436438855 [Client management]: Accepting client
> > command
> > > ... (in thread_manage_clients() at client.c:2534)
> > >
> > > DBG1 - 10:25:35.436458714 [Client management]: Wait for client
> > response
> > > (in thread_manage_clients() at client.c:2576)
> > >
> > > DBG1 - 10:25:35.436480694 [Client management]: Receiving data from
> > > client ... (in thread_manage_clients() at client.c:2604)
> > >
> > > DBG1 - 10:25:35.436493760 [Client management]: Incomplete recv()
> > from
> > > client... continuing (in thread_manage_clients() at client.c:2608)
> > >
> > > DBG1 - 10:25:35.436514391 [Client management]: Accepting client
> > command
> > > ... (in thread_manage_clients() at client.c:2534)
> > >
> > > DBG1 - 10:25:35.436522846 [Client management]: Wait for client
> > response
> > > (in thread_manage_clients() at client.c:2576)
> > >
> > > DBG1 - 10:25:35.436539198 [Client management]: Receiving data from
> > > client ... (in thread_manage_clients() at client.c:2604)
> > >
> > > DBG1 - 10:25:35.436561992 [Client management]: Processing client
> > command
> > > 'LTTNG_CREATE_SESSION_EXT' (49) (in process_client_msg() at
> > client.c:1016)
> > >
> > > DBG3 - 10:25:35.436644534 [Client management]: Created hashtable
> > size 4
> > > at 0x7fd67c0090b0 of type ULONG (in lttng_ht_new() at
> > hashtable.c:152)
> > >
> > > DBG2 - 10:25:35.436670494 [Client management]: Trying to find
> > session by
> > > name auto-20240112-102535 (in session_find_by_name() at
> > session.c:1143)
> > >
> > > DBG1 - 10:25:35.436679003 [Client management]: Generated session
> > name
> > > "auto-20240112-102535" (in session_create() at session.c:1300)
> > >
> > > DBG3 - 10:25:35.436693861 [Client management]: Created hashtable
> > size 4
> > > at 0x7fd67c00a3f0 of type ULONG (in lttng_ht_new() at
> > hashtable.c:152)
> > >
> > > DBG1 - 10:25:35.436702475 [Client management]: Allocating
> > > ltt_sessions_ht_by_id (in ltt_sessions_ht_alloc() at
> session.c:306)
> > >
> > > DBG3 - 10:25:35.436719034 [Client management]: Created hashtable
> > size 4
> > > at 0x7fd67c00b730 of type U64 (in lttng_ht_new() at
> hashtable.c:152)
> > >
> > > DBG1 - 10:25:35.436727024 [Client management]: Allocating
> > > ltt_sessions_ht_by_name (in ltt_sessions_ht_alloc() at
> session.c:314)
> > >
> > > DBG3 - 10:25:35.436739320 [Client management]: Created hashtable
> > size 4
> > > at 0x7fd67c00ca70 of type STRING (in lttng_ht_new() at
> > hashtable.c:152)
> > >
> > > DBG1 - 10:25:35.436750021 [Client management]: Tracing session
> > > auto-20240112-102535 created with ID 0 by uid = 1000, gid = 1000
> (in
> > > session_create() at session.c:1348)
> > >
> > > DBG3 - 10:25:35.436761891 [Client management]: URI string:
> > > file:///home/yyan7/lttng-traces/auto-20240112-102535 (in
> > uri_parse() at
> > > uri.c:298)
> > >
> > > DBG3 - 10:25:35.436786010 [Client management]: URI file
> destination:
> > > /home/yyan7/lttng-traces/auto-20240112-102535 (in uri_parse() at
> > uri.c:335)
> > >
> > > DBG3 - 10:25:35.436794369 [Client management]: URI dtype: 3,
> > proto: 0,
> > > host: , subdir: , ctrl: 0, data: 0 (in uri_parse() at uri.c:510)
> > >
> > > DBG2 - 10:25:35.436815787 [Client management]: Setting trace
> > directory
> > > path from URI to /home/yyan7/lttng-traces/auto-20240112-102535 (in
> > > add_uri_to_consumer() at cmd.c:719)
> > >
> > > DBG1 - 10:25:35.436861339 [Client management]: Sending response
> > (size:
> > > 8262, retcode: Success (10)) (in thread_manage_clients() at
> > client.c:2683)
> > >
> > > DBG1 - 10:25:35.436885647 [Client management]: Accepting client
> > command
> > > ... (in thread_manage_clients() at client.c:2534)
> > >
> > > DBG1 - 10:25:35.437011410 [Client management]: Wait for client
> > response
> > > (in thread_manage_clients() at client.c:2576)
> > >
> > > DBG1 - 10:25:35.437037211 [Client management]: Receiving data from
> > > client ... (in thread_manage_clients() at client.c:2604)
> > >
> > > DBG1 - 10:25:35.437050433 [Client management]: Incomplete recv()
> > from
> > > client... continuing (in thread_manage_clients() at client.c:2608)
> > >
> > > DBG1 - 10:25:35.437065744 [Client management]: Accepting client
> > command
> > > ... (in thread_manage_clients() at client.c:2534)
> > >
> > > DBG1 - 10:25:35.437074955 [Client management]: Wait for client
> > response
> > > (in thread_manage_clients() at client.c:2576)
> > >
> > > DBG1 - 10:25:35.437088320 [Client management]: Receiving data from
> > > client ... (in thread_manage_clients() at client.c:2604)
> > >
> > > DBG1 - 10:25:35.437107173 [Client management]: Processing client
> > command
> > > 'LTTNG_LIST_SESSIONS' (13) (in process_client_msg() at
> client.c:1016)
> > >
> > > DBG1 - 10:25:35.437120952 [Client management]: Counting number of
> > > available session for UID 1000 (in lttng_sessions_count() at
> > client.c:596)
> > >
> > > DBG1 - 10:25:35.437130882 [Client management]: Getting all
> available
> > > session for UID 1000 GID 1000 (in cmd_list_lttng_sessions() at
> > cmd.c:3947)
> > >
> > > DBG1 - 10:25:35.437141977 [Client management]: Sending response
> > (size:
> > > 4409, retcode: Success (10)) (in thread_manage_clients() at
> > client.c:2683)
> > >
> > > DBG1 - 10:25:35.437163179 [Client management]: Accepting client
> > command
> > > ... (in thread_manage_clients() at client.c:2534)
> > >
> > > Session auto-20240112-102535 created.
> > >
> > > Traces will be output to
> > /home/yyan7/lttng-traces/auto-20240112-102535
> > >
> > > *yyan7 at CCI13SZWP3LWS*:*~*$ lttng enable-event -u -all
> > >
> > > Error: Only one domain must be specified.
> > >
> > > *yyan7 at CCI13SZWP3LWS*:*~*$ lttng enable-event -u -a
> > >
> > > DBG1 - 10:26:09.048651842 [Client management]: Wait for client
> > response
> > > (in thread_manage_clients() at client.c:2576)
> > >
> > > DBG1 - 10:26:09.048698882 [Client management]: Receiving data from
> > > client ... (in thread_manage_clients() at client.c:2604)
> > >
> > > DBG1 - 10:26:09.048730037 [Client management]: Processing client
> > command
> > > 'LTTNG_ENABLE_EVENT' (6) (in process_client_msg() at
> client.c:1016)
> > >
> > > DBG1 - 10:26:09.048742929 [Client management]: Getting session
> > > auto-20240112-102535 by name (in process_client_msg() at
> > client.c:1133)
> > >
> > > DBG2 - 10:26:09.048752328 [Client management]: Trying to find
> > session by
> > > name auto-20240112-102535 (in session_find_by_name() at
> > session.c:1143)
> > >
> > > DBG1 - 10:26:09.048762009 [Client management]: Creating UST
> > session (in
> > > create_ust_session() at client.c:510)
> > >
> > > DBG3 - 10:26:09.048777715 [Client management]: Created hashtable
> > size 4
> > > at 0x7fd67c00ffd0 of type STRING (in lttng_ht_new() at
> > hashtable.c:152)
> > >
> > > DBG3 - 10:26:09.048801459 [Client management]: Created hashtable
> > size 4
> > > at 0x7fd67c011310 of type U64 (in lttng_ht_new() at
> hashtable.c:152)
> > >
> > > DBG3 - 10:26:09.048877638 [Client management]: Created hashtable
> > size 4
> > > at 0x7fd67c020120 of type ULONG (in lttng_ht_new() at
> > hashtable.c:152)
> > >
> > > DBG2 - 10:26:09.048886268 [Client management]: UST trace session
> > create
> > > successful (in trace_ust_create_session() at trace-ust.c:324)
> > >
> > > DBG3 - 10:26:09.048894968 [Client management]: Copying tracing
> > session
> > > consumer output in UST session (in copy_session_consumer() at
> > client.c:454)
> > >
> > > DBG3 - 10:26:09.048930287 [Client management]: Created hashtable
> > size 4
> > > at 0x7fd67c0213d0 of type ULONG (in lttng_ht_new() at
> > hashtable.c:152)
> > >
> > > DBG3 - 10:26:09.048944965 [Client management]: Copy session
> consumer
> > > subdir ust (in copy_session_consumer() at client.c:476)
> > >
> > > DBG1 - 10:26:09.048955915 [Client management]: Spawning consumerd
> > (in
> > > spawn_consumerd() at client.c:204)
> > >
> > > DBG3 - 10:26:09.048988740 [HT cleanup]: Returning from poll on 2
> > fds.
> > > (in thread_ht_cleanup() at ht-cleanup.c:125)
> > >
> > > DBG2 - 10:26:09.049819491 [Client management]: Consumer pid 3526
> (in
> > > start_consumerd() at client.c:390)
> > >
> > > DBG2 - 10:26:09.049855514 [Client management]: Spawning consumer
> > control
> > > thread (in start_consumerd() at client.c:393)
> > >
> > > DBG1 - 10:26:09.049986094 [Client management]: Waiting for
> consumer
> > > management thread to be ready (in wait_until_thread_is_ready() at
> > > manage-consumer.c:46)
> > >
> > > DBG1 - 10:26:09.050081839 [Consumer management]: Entering thread
> > entry
> > > point (in launch_thread() at thread.c:65)
> > >
> > > DBG1 - 10:26:09.050074834 [Client management]: Using 64-bit UST
> > consumer
> > > at: /usr/lib/x86_64-linux-gnu/lttng/libexec/lttng-consumerd (in
> > > spawn_consumerd() at client.c:284)
> > >
> > > DBG1 - 10:26:09.050117556 [Consumer management]: [thread] Manage
> > > consumer started (in thread_consumer_management() at
> > manage-consumer.c:65)
> > >
> > > DBG3 - 10:26:09.050103089 [HT cleanup]: Polling. (in
> > thread_ht_cleanup()
> > > at ht-cleanup.c:122)
> > >
> > > libringbuffer-clients[3526/3526]: LTT : ltt ring buffer client
> > > "relay-metadata-mmap" init
> > >
> > > (in lttng_ring_buffer_metadata_client_init() at
> > > ../../src/common/ringbuffer-clients/metadata-template.h:364)
> > >
> > > libringbuffer-clients[3526/3526]: LTT : ltt ring buffer client
> > > "relay-overwrite-mmap" init
> > >
> > > (in lttng_ring_buffer_client_overwrite_init() at
> > > ../../src/common/ringbuffer-clients/template.h:826)
> > >
> > > libringbuffer-clients[3526/3526]: LTT : ltt ring buffer client
> > > "relay-overwrite-rt-mmap" init
> > >
> > > (in lttng_ring_buffer_client_overwrite_rt_init() at
> > > ../../src/common/ringbuffer-clients/template.h:826)
> > >
> > > libringbuffer-clients[3526/3526]: LTT : ltt ring buffer client
> > > "relay-discard-mmap" init
> > >
> > > (in lttng_ring_buffer_client_discard_init() at
> > > ../../src/common/ringbuffer-clients/template.h:826)
> > >
> > > libringbuffer-clients[3526/3526]: LTT : ltt ring buffer client
> > > "relay-discard-rt-mmap" init
> > >
> > > (in lttng_ring_buffer_client_discard_rt_init() at
> > > ../../src/common/ringbuffer-clients/template.h:826)
> > >
> > > DBG1 - 10:26:09.054724418 [3526/3526]: Health check time delta in
> > > seconds set to 20 (in health_init() at health.c:62)
> > >
> > > DBG3 - 10:26:09.054993129 [3526/3526]: Created hashtable size 4 at
> > > 0x561838919540 of type U64 (in lttng_ht_new() at hashtable.c:152)
> > >
> > > DBG3 - 10:26:09.055012947 [3526/3526]: Created hashtable size 4 at
> > > 0x561838919870 of type U64 (in lttng_ht_new() at hashtable.c:152)
> > >
> > > DBG3 - 10:26:09.055026387 [3526/3526]: Created hashtable size 4 at
> > > 0x561838919ba0 of type U64 (in lttng_ht_new() at hashtable.c:152)
> > >
> > > DBG3 - 10:26:09.055038707 [3526/3526]: Created hashtable size 4 at
> > > 0x561838919ed0 of type U64 (in lttng_ht_new() at hashtable.c:152)
> > >
> > > DBG3 - 10:26:09.055052418 [3526/3526]: Created hashtable size 4 at
> > > 0x56183891eb00 of type U64 (in lttng_ht_new() at hashtable.c:152)
> > >
> > > DBG3 - 10:26:09.055070118 [3526/3526]: Created hashtable size 4 at
> > > 0x56183891fe40 of type U64 (in lttng_ht_new() at hashtable.c:152)
> > >
> > > DBG3 - 10:26:09.055079438 [3526/3526]: Created hashtable size 4 at
> > > 0x561838921180 of type U64 (in lttng_ht_new() at hashtable.c:152)
> > >
> > > DBG1 - 10:26:09.055131986 [3526/3526]: TCP inet operation timeout
> > set to
> > > 216 sec (in lttcomm_inet_init() at inet.c:545)
> > >
> > > DBG1 - 10:26:09.055169397 [3526/3526]: Connecting to error socket
> > > /home/yyan7/.lttng/ustconsumerd64/error (in main() at
> > lttng-consumerd.c:477)
> > >
> > > DBG2 - 10:26:09.055307314 [Consumer management]: Receiving code
> from
> > > consumer err_sock (in thread_consumer_management() at
> > manage-consumer.c:162)
> > >
> > > DBG1 - 10:26:09.055374257 [3526/3530]: [thread] Manage health
> check
> > > started (in thread_manage_health() at health-consumerd.c:157)
> > >
> > > DBG1 - 10:26:09.055528236 [3526/3530]: epoll set max size is
> > 7225299 (in
> > > compat_epoll_set_max_size() at poll.c:350)
> > >
> > > DBG1 - 10:26:09.055617358 [3526/3530]: Health check ready (in
> > > thread_manage_health() at health-consumerd.c:237)
> > >
> > > DBG1 - 10:26:09.155778508 [3526/3533]: Thread metadata poll
> > started (in
> > > consumer_thread_metadata_poll() at consumer.c:2344)
> > >
> > > DBG3 - 10:26:09.155827680 [3526/3532]: Created hashtable size 4 at
> > > 0x7fb838000b90 of type U64 (in lttng_ht_new() at hashtable.c:152)
> > >
> > > DBG1 - 10:26:09.155854441 [3526/3532]: Thread channel poll
> > started (in
> > > consumer_thread_channel_poll() at consumer.c:2938)
> > >
> > > DBG1 - 10:26:09.155873849 [3526/3532]: Channel main loop started
> (in
> > > consumer_thread_channel_poll() at consumer.c:2953)
> > >
> > > DBG1 - 10:26:09.155884744 [3526/3532]: Channel poll wait (in
> > > consumer_thread_channel_poll() at consumer.c:2958)
> > >
> > > DBG1 - 10:26:09.155910091 [3526/3533]: Metadata main loop started
> > (in
> > > consumer_thread_metadata_poll() at consumer.c:2360)
> > >
> > > DBG1 - 10:26:09.155915209 [3526/3535]: Creating command socket
> > > /home/yyan7/.lttng/ustconsumerd64/command (in
> > > consumer_thread_sessiond_poll() at consumer.c:3201)
> > >
> > > DBG1 - 10:26:09.155927055 [3526/3533]: Metadata poll wait (in
> > > consumer_thread_metadata_poll() at consumer.c:2366)
> > >
> > > DBG1 - 10:26:09.155902292 [3526/3534]: Updating poll fd array (in
> > > update_poll_array() at consumer.c:1176)
> > >
> > > DBG1 - 10:26:09.155992208 [3526/3534]: polling on 2 fd (in
> > > consumer_thread_data_poll() at consumer.c:2627)
> > >
> > > DBG1 - 10:26:09.156028520 [3526/3535]: Sending ready command to
> > > lttng-sessiond (in consumer_thread_sessiond_poll() at
> > consumer.c:3214)
> > >
> > > DBG1 - 10:26:09.156117370 [3526/3535]: Connection on
> > client_socket (in
> > > consumer_thread_sessiond_poll() at consumer.c:3236)
> > >
> > > DBG1 - 10:26:09.156118051 [Consumer management]: Consumer command
> > socket
> > > ready (fd: 61) (in thread_consumer_management() at
> > manage-consumer.c:204)
> > >
> > > DBG1 - 10:26:09.156134055 [Consumer management]: Consumer metadata
> > > socket ready (fd: 62) (in thread_consumer_management() at
> > > manage-consumer.c:205)
> > >
> > > DBG1 - 10:26:09.156140605 [3526/3535]: Metadata connection on
> > > client_socket (in set_metadata_socket() at consumer.c:3162)
> > >
> > > DBG1 - 10:26:09.156159591 [Consumer management]: Sending consumer
> > > initialization command (in consumer_init() at consumer.c:1791)
> > >
> > > DBG1 - 10:26:09.156197563 [3526/3535]: Incoming command on sock
> (in
> > > consumer_thread_sessiond_poll() at consumer.c:3282)
> > >
> > > DBG1 - 10:26:09.156239708 [3526/3535]: Received session daemon
> UUID:
> > > 0e76c943-cc93-414c-81d5-259bf7e8d0e4 (in
> > lttng_consumer_init_command()
> > > at consumer.c:4711)
> > >
> > > DBG1 - 10:26:09.156260388 [3526/3535]: Received command on sock
> (in
> > > consumer_thread_sessiond_poll() at consumer.c:3298)
> > >
> > > DBG3 - 10:26:09.156271768 [Consumer management]: Sending
> > > SET_CHANNEL_MONITOR_PIPE command to consumer (in
> > consumer_send_pipe() at
> > > consumer.c:1230)
> > >
> > > DBG1 - 10:26:09.156298833 [3526/3535]: Incoming command on sock
> (in
> > > consumer_thread_sessiond_poll() at consumer.c:3282)
> > >
> > > DBG3 - 10:26:09.156339394 [Consumer management]: Sending channel
> > monitor
> > > pipe 16 to consumer on socket 61 (in consumer_send_pipe() at
> > > consumer.c:1236)
> > >
> > > DBG1 - 10:26:09.156373728 [3526/3535]: Received channel monitor
> pipe
> > > (27) (in lttng_ustconsumer_recv_cmd() at ust-consumer.c:2017)
> > >
> > > DBG1 - 10:26:09.156385429 [3526/3535]: Channel monitor pipe set as
> > > non-blocking (in lttng_ustconsumer_recv_cmd() at
> ust-consumer.c:2040)
> > >
> > > DBG1 - 10:26:09.156398125 [3526/3535]: Received command on sock
> (in
> > > consumer_thread_sessiond_poll() at consumer.c:3298)
> > >
> > > DBG2 - 10:26:09.156408026 [Consumer management]: channel monitor
> > pipe
> > > successfully sent (in consumer_send_pipe() at consumer.c:1244)
> > >
> > > DBG1 - 10:26:09.156521209 [Consumer management]: Marking consumer
> > > management thread as ready (in mark_thread_as_ready() at
> > > manage-consumer.c:31)
> > >
> > > DBG1 - 10:26:09.156618144 [Client management]: Consumer management
> > > thread is ready (in wait_until_thread_is_ready() at
> > manage-consumer.c:48)
> > >
> > > DBG3 - 10:26:09.156649336 [Client management]: Consumer socket
> > created
> > > (fd: 61) and added to output (in consumer_create_socket() at
> > consumer.c:351)
> > >
> > > *DBG1 - 10:26:09.156661610 [Client management]: Setting relayd for
> > > session auto-20240112-102535 (in cmd_setup_relayd() at
> cmd.c:1004)*
> > >
> > > *lttng-sessiond: unix.c:185: lttcomm_recv_unix_sock: Assertion
> `buf'
> > > failed.*
> > >
> > > DBG1 - 10:26:10.269878943 [3526/3535]: Incoming command on sock
> (in
> > > consumer_thread_sessiond_poll() at consumer.c:3282)
> > >
> > > DBG1 - 10:26:10.269909824 [3526/3535]: Consumer received
> unexpected
> > > message size 0 (expects 12690) (in lttng_ustconsumer_recv_cmd() at
> > > ust-consumer.c:1401)
> > >
> > > DBG1 - 10:26:10.269918771 [3526/3535]: Communication interrupted
> on
> > > command socket (in consumer_thread_sessiond_poll() at
> > consumer.c:3289)
> > >
> > > DBG1 - 10:26:10.269924634 [3526/3535]: Consumer thread sessiond
> poll
> > > exiting (in consumer_thread_sessiond_poll() at consumer.c:3304)
> > >
> > > Error: Events: No session daemon is available (channel channel0,
> > session
> > > auto-20240112-102535)
> > >
> > > DBG1 - 10:26:10.269945294 [3526/3535]: UST consumer closing all
> > metadata
> > > streams (in lttng_ustconsumer_close_all_metadata() at
> > ust-consumer.c:3278)
> > >
> > > DBG1 - 10:26:10.270034860 [3526/3534]: poll num_rdy : 1 (in
> > > consumer_thread_data_poll() at consumer.c:2634)
> > >
> > > DBG1 - 10:26:10.270051195 [3526/3532]: Channel poll return from
> wait
> > > with 1 fd(s) (in consumer_thread_channel_poll() at
> consumer.c:2961)
> > >
> > > DBG1 - 10:26:10.270085710 [3526/3532]: Channel event caught in
> > thread
> > > (in consumer_thread_channel_poll() at consumer.c:2964)
> > >
> > > DBG1 - 10:26:10.270066746 [3526/3534]: consumer_data_pipe wake up
> > (in
> > > consumer_thread_data_poll() at consumer.c:2664)
> > >
> > > DBG1 - 10:26:10.270051357 [3526/3530]: Health check thread dying
> (in
> > > thread_manage_health() at health-consumerd.c:334)
> > >
> > > DBG1 - 10:26:10.270114085 [3526/3532]: Channel poll wait (in
> > > consumer_thread_channel_poll() at consumer.c:2958)
> > >
> > > DBG1 - 10:26:10.270151938 [3526/3532]: Channel poll return from
> wait
> > > with 0 fd(s) (in consumer_thread_channel_poll() at
> consumer.c:2961)
> > >
> > > DBG1 - 10:26:10.270163529 [3526/3532]: Channel event caught in
> > thread
> > > (in consumer_thread_channel_poll() at consumer.c:2964)
> > >
> > > DBG1 - 10:26:10.270115093 [3526/3534]: Consumer delete flagged
> data
> > > stream (in validate_endpoint_status_data_stream() at
> consumer.c:2274)
> > >
> > > DBG1 - 10:26:10.270187345 [3526/3534]: polling thread exiting (in
> > > consumer_thread_data_poll() at consumer.c:2806)
> > >
> > > DBG1 - 10:26:10.270226737 [3526/3533]: Metadata poll return from
> > wait
> > > with 1 fd(s) (in consumer_thread_metadata_poll() at
> consumer.c:2368)
> > >
> > > DBG1 - 10:26:10.270255651 [3526/3533]: Metadata event caught in
> > thread
> > > (in consumer_thread_metadata_poll() at consumer.c:2371)
> > >
> > > DBG1 - 10:26:10.270264901 [3526/3533]: Metadata thread pipe hung
> > up (in
> > > consumer_thread_metadata_poll() at consumer.c:2426)
> > >
> > > DBG1 - 10:26:10.270270628 [3526/3532]: Channel poll thread
> > exiting (in
> > > consumer_thread_channel_poll() at consumer.c:3140)
> > >
> > > DBG1 - 10:26:10.270284048 [3526/3533]: Metadata poll wait (in
> > > consumer_thread_metadata_poll() at consumer.c:2366)
> > >
> > > DBG1 - 10:26:10.270292833 [3526/3533]: Metadata poll return from
> > wait
> > > with 0 fd(s) (in consumer_thread_metadata_poll() at
> consumer.c:2368)
> > >
> > > DBG1 - 10:26:10.270300375 [3526/3533]: Metadata event caught in
> > thread
> > > (in consumer_thread_metadata_poll() at consumer.c:2371)
> > >
> > > DBG1 - 10:26:10.270310033 [3526/3533]: Metadata poll thread
> > exiting (in
> > > consumer_thread_metadata_poll() at consumer.c:2521)
> > >
> > > DBG1 - 10:26:10.270463392 [3526/3526]: Releasing trace chunk
> > registry to
> > > all trace chunks (in lttng_trace_chunk_registry_put_each_chunk()
> at
> > > trace-chunk.c:2221)
> > >
> > > DBG1 - 10:26:10.270476593 [3526/3526]: Released reference to 0
> trace
> > > chunks in lttng_trace_chunk_registry_put_each_chunk() (in
> > > lttng_trace_chunk_registry_put_each_chunk() at trace-chunk.c:2254)
> > >
> > > DBG1 - 10:26:10.270667263 [3526/3526]: Consumer destroying it.
> > Closing
> > > everything. (in lttng_consumer_destroy() at consumer.c:1546)
> > >
> > > DBG1 - 10:26:10.270812838 [3526/3526]: Destroying run_as worker
> (in
> > > run_as_destroy_worker_no_lock() at runas.c:1576)
> > >
> > > DBG1 - 10:26:10.270818934 [3526/3526]: Closing run_as worker
> > socket (in
> > > run_as_destroy_worker_no_lock() at runas.c:1581)
> > >
> > > *yyan7 at CCI13SZWP3LWS*:*~*$ libringbuffer-clients[3528/3528]: LTT
> > : ltt
> > > ring buffer client "relay-discard-rt-mmap" exit
> > >
> > > (in lttng_ring_buffer_client_discard_rt_exit() at
> > > ../../src/common/ringbuffer-clients/template.h:833)
> > >
> > > libringbuffer-clients[3528/3528]: LTT : ltt ring buffer client
> > > "relay-discard-mmap" exit
> > >
> > > (in lttng_ring_buffer_client_discard_exit() at
> > > ../../src/common/ringbuffer-clients/template.h:833)
> > >
> > > libringbuffer-clients[3528/3528]: LTT : ltt ring buffer client
> > > "relay-overwrite-rt-mmap" exit
> > >
> > > (in lttng_ring_buffer_client_overwrite_rt_exit() at
> > > ../../src/common/ringbuffer-clients/template.h:833)
> > >
> > > libringbuffer-clients[3528/3528]: LTT : ltt ring buffer client
> > > "relay-overwrite-mmap" exit
> > >
> > > (in lttng_ring_buffer_client_overwrite_exit() at
> > > ../../src/common/ringbuffer-clients/template.h:833)
> > >
> > > libringbuffer-clients[3528/3528]: LTT : ltt ring buffer client
> > > "relay-metadata-mmap" exit
> > >
> > > (in lttng_ring_buffer_metadata_client_exit() at
> > > ../../src/common/ringbuffer-clients/metadata-template.h:371)
> > >
> > > DBG1 - 10:26:10.271345058 [3526/3526]: lttng-runas terminated with
> > > status code 0 (in run_as_destroy_worker_no_lock() at runas.c:1601)
> > >
> > > libringbuffer-clients[3526/3526]: LTT : ltt ring buffer client
> > > "relay-discard-rt-mmap" exit
> > >
> > > (in lttng_ring_buffer_client_discard_rt_exit() at
> > > ../../src/common/ringbuffer-clients/template.h:833)
> > >
> > > libringbuffer-clients[3526/3526]: LTT : ltt ring buffer client
> > > "relay-discard-mmap" exit
> > >
> > > (in lttng_ring_buffer_client_discard_exit() at
> > > ../../src/common/ringbuffer-clients/template.h:833)
> > >
> > > libringbuffer-clients[3526/3526]: LTT : ltt ring buffer client
> > > "relay-overwrite-rt-mmap" exit
> > >
> > > (in lttng_ring_buffer_client_overwrite_rt_exit() at
> > > ../../src/common/ringbuffer-clients/template.h:833)
> > >
> > > libringbuffer-clients[3526/3526]: LTT : ltt ring buffer client
> > > "relay-overwrite-mmap" exit
> > >
> > > (in lttng_ring_buffer_client_overwrite_exit() at
> > > ../../src/common/ringbuffer-clients/template.h:833)
> > >
> > > libringbuffer-clients[3526/3526]: LTT : ltt ring buffer client
> > > "relay-metadata-mmap" exit
> > >
> > > (in lttng_ring_buffer_metadata_client_exit() at
> > > ../../src/common/ringbuffer-clients/metadata-template.h:371)
> > >
> > > DBG1 - 10:26:10.271715039 [Run-as worker]: run_as worker exiting
> > (ret =
> > > 0) (in run_as_create_worker_no_lock() at runas.c:1526)
> > >
> > > libringbuffer-clients[3507/3507]: LTT : ltt ring buffer client
> > > "relay-discard-rt-mmap" exit
> > >
> > > (in lttng_ring_buffer_client_discard_rt_exit() at
> > > ../../src/common/ringbuffer-clients/template.h:833)
> > >
> > > libringbuffer-clients[3507/3507]: LTT : ltt ring buffer client
> > > "relay-discard-mmap" exit
> > >
> > > (in lttng_ring_buffer_client_discard_exit() at
> > > ../../src/common/ringbuffer-clients/template.h:833)
> > >
> > > libringbuffer-clients[3507/3507]: LTT : ltt ring buffer client
> > > "relay-overwrite-rt-mmap" exit
> > >
> > > (in lttng_ring_buffer_client_overwrite_rt_exit() at
> > > ../../src/common/ringbuffer-clients/template.h:833)
> > >
> > > libringbuffer-clients[3507/3507]: LTT : ltt ring buffer client
> > > "relay-overwrite-mmap" exit
> > >
> > > (in lttng_ring_buffer_client_overwrite_exit() at
> > > ../../src/common/ringbuffer-clients/template.h:833)
> > >
> > > libringbuffer-clients[3507/3507]: LTT : ltt ring buffer client
> > > "relay-metadata-mmap" exit
> > >
> > > (in lttng_ring_buffer_metadata_client_exit() at
> > > ../../src/common/ringbuffer-clients/metadata-template.h:371)
> > >
> > >
> > > *yyan7 at CCI13SZWP3LWS*:*~*$
> > >
> > >
> > >
> > > On Fri, Jan 12, 2024 at 10:01 AM Kienan Stewart
> > <kstewart at efficios.com <mailto:kstewart at efficios.com>
> > > <mailto:kstewart at efficios.com <mailto:kstewart at efficios.com>>>
> wrote:
> > >
> > > Hi Yonghong,
> > >
> > > in a brief test I'm unable to reproduce the error you see by
> > running
> > > the
> > > following commands on an Ubuntu 22.04 installation with
> > lttng-tools
> > > 2.13.10, lttng-ust 2.13.6, urcu stable-0.12, and babeltrace
> > stable-2.0.
> > > ```
> > > $ uname -r -v
> > > 6.5.0-14-generic #14~22.04.1-Ubuntu SMP PREEMPT_DYNAMIC Mon
> > Nov 20
> > > 18:15:30 UTC 2
> > >
> > > $ lttng-relayd -v -b
> > > $ lttng-sessiond -v -b
> > > $ lttng create
> > > $ lttng enable-event -u --all
> > > ```
> > >
> > > Could you please review the bug reporting guidelines at
> > > https://lttng.org/community/ <https://lttng.org/community/>
> > <https://lttng.org/community/ <https://lttng.org/community/>> and
> > > elaborate on the steps taken to
> > > reproduce the issue?
> > >
> > > thanks,
> > > kienan
> > >
> > > On 1/12/24 08:12, Yonghong Yan via lttng-dev wrote:
> > > > I am not sure whether this is my setting problem or a bug
> > with a
> > > > more recent kernel. lttng-sessiond was killed when I tried
> to
> > > "enable
> > > > event" after a session was created. See below part of the
> > verbose
> > > output
> > > > of the sessiond. It is observed on Ubuntu 22.04, kernel
> > > 6.5.0-14-generic
> > > > #14~22.04.1-Ubuntu SMP PREEMPT_DYNAMIC, lttng (LTTng Trace
> > Control)
> > > > 2.13.10 - Nordicité.
> > > >
> > > >
> > > > The same version of LTTng works on another Ubuntu 22.04
> > machine, but
> > > > with kernel 6.2.0-33-generic. Any suggestion on what I
> > should try?
> > > >
> > > >
> > > > Thank you
> > > >
> > > > Yonghong
> > > >
> > > >
> > > >
> > > > c:1016)
> > > >
> > > > DBG1 - 00:24:25.134138433 [Client management]: Getting
> session
> > > > auto-20240112-002417 by name (in process_client_msg() at
> > > client.c:1133)
> > > >
> > > > DBG1 - 00:24:25.134148894 [Client management]: Creating UST
> > > session (in
> > > > create_ust_session() at client.c:510)
> > > >
> > > > DBG1 - 00:24:25.134267958 [Client management]: Spawning
> > consumerd
> > > (in
> > > > spawn_consumerd() at client.c:204)
> > > >
> > > > DBG1 - 00:24:25.135155823 [Client management]: Waiting for
> > consumer
> > > > management thread to be ready (in
> > wait_until_thread_is_ready() at
> > > > manage-consumer.c:46)
> > > >
> > > > DBG1 - 00:24:25.135247552 [Consumer management]: Entering
> > thread
> > > entry
> > > > point (in launch_thread() at thread.c:65)
> > > >
> > > > DBG1 - 00:24:25.135293542 [Consumer management]: [thread]
> > Manage
> > > > consumer started (in thread_consumer_management() at
> > > manage-consumer.c:65)
> > > >
> > > > DBG1 - 00:24:25.135335776 [Client management]: Using
> > 64-bit UST
> > > consumer
> > > > at:
> > /usr/lib/x86_64-linux-gnu/lttng/libexec/lttng-consumerd (in
> > > > spawn_consumerd() at client.c:284)
> > > >
> > > > DBG1 - 00:24:25.240725883 [Consumer management]: Consumer
> > command
> > > socket
> > > > ready (fd: 61) (in thread_consumer_management() at
> > > manage-consumer.c:204)
> > > >
> > > > DBG1 - 00:24:25.240746802 [Consumer management]: Consumer
> > metadata
> > > > socket ready (fd: 62) (in thread_consumer_management() at
> > > > manage-consumer.c:205)
> > > >
> > > > DBG1 - 00:24:25.240775318 [Consumer management]: Sending
> > consumer
> > > > initialization command (in consumer_init() at
> consumer.c:1791)
> > > >
> > > > DBG1 - 00:24:25.241066762 [Consumer management]: Marking
> > consumer
> > > > management thread as ready (in mark_thread_as_ready() at
> > > > manage-consumer.c:31)
> > > >
> > > > DBG1 - 00:24:25.241100481 [Client management]: Consumer
> > management
> > > > thread is ready (in wait_until_thread_is_ready() at
> > > manage-consumer.c:48)
> > > >
> > > > DBG1 - 00:24:25.241138386 [Client management]: Setting
> > relayd for
> > > > session auto-20240112-002417 (in cmd_setup_relayd() at
> > cmd.c:1004)
> > > >
> > > > lttng-sessiond: unix.c:185: lttcomm_recv_unix_sock:
> Assertion
> > > `buf' failed.
> > > >
> > > > Error: Events: No session daemon is available (channel
> > channel0,
> > > session
> > > > auto-20240112-002417)
> > > >
> > > > [1]+Aborted (core dumped) lttng-sessiond --verbose
> > > >
> > > > DBG1 - 00:24:26.357769106 [Run-as worker]: run_as worker
> > exiting
> > > (ret =
> > > > 0) (in run_as_create_worker_no_lock() at runas.c:1526)
> > > >
> > > >
> > > >
> > > > _______________________________________________
> > > > lttng-dev mailing list
> > > > lttng-dev at lists.lttng.org
> > <mailto:lttng-dev at lists.lttng.org> <mailto:lttng-dev at lists.lttng.org
> > <mailto:lttng-dev at lists.lttng.org>>
> > > > https://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev
> > <https://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev>
> > > <https://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev
> > <https://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev>>
> > >
> >
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.lttng.org/pipermail/lttng-dev/attachments/20240112/cecaa7d0/attachment-0001.htm>
More information about the lttng-dev
mailing list