[lttng-dev] LTTng sessiond daemon Assertion `buf' failed and killed
Kienan Stewart
kstewart at efficios.com
Fri Jan 12 14:31:28 EST 2024
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>> 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/> 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>
> > https://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev
> <https://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev>
>
More information about the lttng-dev
mailing list