Hi Kienan, I just figured out what I did wrong. After I rebuilt the system the day before and installed lttng-modules-dkms from Ubuntu officially, the building of kernel modules failed (I can send you the crash and make.log for you to look at). I then added Ubuntu: LTTng Stable 2.13 PPA, and installation passed. With that, what installed are mix/mismatch of kms and binary of the partially installed kms from Ubuntu official and from stable 2.13 ppa. That caused the problem. I now removed everything and reinstalled everything from stable 2.13 ppa, everything works. Thank you for helping me through this. Best, Yonghong On Fri, Jan 12, 2024 at 10:04 PM Yonghong Yan wrote: > 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@CCI13SZWP3LWS*:*/var/lib/apport/coredump*$ export DEBUGINFOD_URLS=" > https://debuginfod.ubuntu.com" > > *yyan7@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: > > . > > Find the GDB manual and other documentation resources online at: > > . > > > 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 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@entry=6) > at ./nptl/pthread_kill.c:89 > > #3 0x00007fe37d842476 in __GI_raise (sig=sig@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=) 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=) 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@entry=6) > at ./nptl/pthread_kill.c:89 > > #3 0x00007fe37d842476 in __GI_raise (sig=sig@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=) 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=) 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 > 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@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@CCI13SZWP3LWS*:*/var/log*$ cd /var/lib/apport/coredump >> > >> > *yyan7@CCI13SZWP3LWS*:*/var/lib/apport/coredump*$ ls >> > >> > >> core._usr_bin_lttng-sessiond.1000.8f22faa6-512c-49ca-9089-8b3f0801da8d.10470.2023109 >> > >> > *yyan7@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@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@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 >> > > >> > >> > 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: >> > >> > > > >. >> > >> > Find the GDB manual and other documentation resources online at: >> > >> > > > >. >> > >> > >> > 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 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@entry=6) >> at >> > ./nptl/pthread_kill.c:89 >> > >> > #30x00007fe37d842476in __GI_raise(sig=sig@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=) 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=) at >> > ./nptl/pthread_create.c:442 >> > >> > #13 0x00007fe37d926850in clone3() at >> > ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81 >> > >> > (gdb) quit >> > >> > *yyan7@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@CCI13SZWP3LWS*:*/var/lib/apport/coredump*$ >> > >> > >> > On Fri, Jan 12, 2024 at 2:31 PM Kienan Stewart > > > 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@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@CCI13SZWP3LWS*:*~*$ cat /etc/lsb-release >> > > >> > > DISTRIB_ID=Ubuntu >> > > >> > > DISTRIB_RELEASE=22.04 >> > > >> > > DISTRIB_CODENAME=jammy >> > > >> > > DISTRIB_DESCRIPTION="Ubuntu 22.04.3 LTS" >> > > >> > > *yyan7@CCI13SZWP3LWS*:*~*$ lttng --version >> > > >> > > lttng (LTTng Trace Control) 2.13.10 - Nordicité >> > > >> > > *yyan7@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@CCI13SZWP3LWS*:*~*$ export LTTNG_UST_DEBUG=1 >> > > >> > > *yyan7@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@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@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@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@CCI13SZWP3LWS*:*~*$ lttng enable-event -u -all >> > > >> > > Error: Only one domain must be specified. >> > > >> > > *yyan7@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@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@CCI13SZWP3LWS*:*~*$ >> > > >> > > >> > > >> > > On Fri, Jan 12, 2024 at 10:01 AM Kienan Stewart >> > >> > > >> >> 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/ >> > > 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@lists.lttng.org >> > > lttng-dev@lists.lttng.org >> > > >> > > > >> https://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev >> > >> > > > > > >> > > >> > >> >