Hello everyone,
I am reaching out to seek assistance in tracing an instrumented Java
application running within a Docker container from the host side.
In my setup, the LTTng session daemon, running on the host side, indicates
that application registration has been completed (please refer to the
logs). However, when running the command "lttng list --jul," no registered
applications are displayed. Although the application successfully creates
the "LttngLogHandler" object and attaches it to the logger, no traces are
generated.
To allow the application to access the lttng socket file, the host's
/var/run/lttng directory is shared with the container at launch (using the
command "sudo docker run -p 8080:8080 -v /var/run/lttng:/var/run/lttng
sample-image"). I am only interested in collecting userspace Java (--jul)
traces.
I would greatly appreciate any assistance or guidance that you can provide.
Thank you for your time.
Additional details include:
Ubuntu 22.04
Kernel: 5.15.0-60-generic
LTTng session daemon version: 2.13.2
Docker version 20.10.21, build 20.10.21-0ubuntu1~22.04.2
Regards,
Adel Belkhiri
~ ⋙ sudo lttng-sessiond -vvv
DBG1 - 19:35:41.480495205 [Main]: [sessiond configuration]
DBG1 - 19:35:41.480575385 [Main]: version 2.13.2
DBG1 - 19:35:41.480591879 [Main]: verbose: 3
DBG1 - 19:35:41.480604936 [Main]: verbose consumer: 0
DBG1 - 19:35:41.480619311 [Main]: quiet mode: False
DBG1 - 19:35:41.480633197 [Main]: agent_tcp_port: [5345,
5354]
DBG1 - 19:35:41.480645280 [Main]: application socket timeout: 5
DBG1 - 19:35:41.480653543 [Main]: no-kernel: False
DBG1 - 19:35:41.480661830 [Main]: background: False
DBG1 - 19:35:41.480669880 [Main]: daemonize: False
DBG1 - 19:35:41.480677837 [Main]: signal parent on start: False
DBG1 - 19:35:41.480685957 [Main]: tracing group name: tracing
DBG1 - 19:35:41.480693976 [Main]: kmod_probe_list: None
DBG1 - 19:35:41.480702500 [Main]: kmod_extra_probe_list: None
DBG1 - 19:35:41.480710362 [Main]: rundir:
/var/run/lttng
DBG1 - 19:35:41.480718546 [Main]: application socket path:
/var/run/lttng/lttng-ust-sock-8
DBG1 - 19:35:41.480729301 [Main]: client socket path:
/var/run/lttng/client-lttng-sessiond
DBG1 - 19:35:41.480744854 [Main]: wait shm path:
/lttng-ust-wait-8
DBG1 - 19:35:41.480757836 [Main]: health socket path:
/var/run/lttng/sessiond-health
DBG1 - 19:35:41.480770747 [Main]: LTTNG_UST_CLOCK_PLUGIN: None
DBG1 - 19:35:41.480783583 [Main]: pid file path:
/var/run/lttng/lttng-sessiond.pid
DBG1 - 19:35:41.480796563 [Main]: lock file path:
/var/run/lttng/lttng-sessiond.lck
DBG1 - 19:35:41.480809186 [Main]: session load path: None
DBG1 - 19:35:41.480821743 [Main]: agent port file path:
/var/run/lttng/agent.port
DBG1 - 19:35:41.480834927 [Main]: consumerd32 path:
/var/run/lttng/ustconsumerd32
DBG1 - 19:35:41.480847413 [Main]: consumerd32 bin path: Unknown
DBG1 - 19:35:41.480859814 [Main]: consumerd32 lib dir: Unknown
DBG1 - 19:35:41.480871449 [Main]: consumerd32 err unix sock
path:/var/run/lttng/ustconsumerd32/error
DBG1 - 19:35:41.480884853 [Main]: consumerd32 cmd unix sock
path:/var/run/lttng/ustconsumerd32/command
DBG1 - 19:35:41.480896816 [Main]: consumerd64 path:
/var/run/lttng/ustconsumerd64
DBG1 - 19:35:41.480920383 [Main]: consumerd64 bin path:
/usr/local/lib/lttng/libexec/lttng-consumerd
DBG1 - 19:35:41.480929803 [Main]: consumerd64 lib dir:
/usr/local/lib
DBG1 - 19:35:41.480951213 [Main]: consumerd64 err unix sock
path:/var/run/lttng/ustconsumerd64/error
DBG1 - 19:35:41.480961803 [Main]: consumerd64 cmd unix sock
path:/var/run/lttng/ustconsumerd64/command
DBG1 - 19:35:41.480972525 [Main]: kconsumerd path:
/var/run/lttng/kconsumerd
DBG1 - 19:35:41.480982706 [Main]: kconsumerd err unix sock path:
/var/run/lttng/kconsumerd/error
DBG1 - 19:35:41.480992462 [Main]: kconsumerd cmd unix sock path:
/var/run/lttng/kconsumerd/command
DBG1 - 19:35:41.481007885 [Main]: Starting lttng-sessiond
{96210a08-3768-4f37-911a-1061cafbfc61} (in sessiond_uuid_log() at main.c:1436)
DBG3 - 19:35:41.481017551 [Main]: Creating LTTng run directory: /var/run/lttng
(in create_lttng_rundir() at main.c:1068)
DBG1 - 19:35:41.481546344 [Main]: Resetting run_as worker signal handlers to
default (in reset_sighandler() at runas.c:1377)
DBG1 - 19:35:41.481662516 [Main]: run_as signal handler set for SIGTERM and
SIGINT (in set_worker_sighandlers() at runas.c:1438)
DBG1 - 19:35:41.483944649 [Main]: Health check time delta in seconds set to 20
(in health_init() at health.c:62)
DBG1 - 19:35:41.484109882 [HT cleanup]: Entering thread entry point (in
launch_thread() at thread.c:65)
DBG1 - 19:35:41.484137866 [HT cleanup]: startup. (in thread_ht_cleanup() at
ht-cleanup.c:98)
DBG1 - 19:35:41.484180800 [HT cleanup]: epoll set max size is 3607084 (in
compat_epoll_set_max_size() at poll.c:350)
DBG3 - 19:35:41.484187567 [Main]: Created hashtable size 4 at 0x55f40f0b98b0 of
type ULONG (in lttng_ht_new() at hashtable.c:153)
DBG3 - 19:35:41.484228736 [Main]: Created hashtable size 4 at 0x55f40f0b9df0 of
type ULONG (in lttng_ht_new() at hashtable.c:153)
DBG3 - 19:35:41.484246667 [HT cleanup]: Polling. (in thread_ht_cleanup() at
ht-cleanup.c:122)
DBG3 - 19:35:41.484251004 [Main]: Created hashtable size 4 at 0x55f40f0babc0 of
type ULONG (in lttng_ht_new() at hashtable.c:153)
DBG3 - 19:35:41.484294670 [Main]: Created hashtable size 16 at 0x55f40f0bb130
of type U64 (in lttng_ht_new() at hashtable.c:153)
DBG3 - 19:35:41.484309941 [Main]: Created hashtable size 16 at 0x55f40f0bb780
of type U64 (in lttng_ht_new() at hashtable.c:153)
DBG3 - 19:35:41.484325792 [Main]: Created hashtable size 16 at 0x55f40f0bbda0
of type U64 (in lttng_ht_new() at hashtable.c:153)
DBG3 - 19:35:41.484337792 [Main]: Created hashtable size 4 at 0x55f40f0bc3c0 of
type ULONG (in lttng_ht_new() at hashtable.c:153)
DBG3 - 19:35:41.484348281 [Main]: Created hashtable size 4 at 0x55f40f0bc900 of
type U64 (in lttng_ht_new() at hashtable.c:153)
DBG2 - 19:35:41.484356915 [Main]: Creating consumer directory:
/var/run/lttng/kconsumerd (in set_consumer_sockets() at main.c:1110)
DBG1 - 19:35:41.546375851 [Main]: Modprobe successfully
lttng-ring-buffer-client-discard (in modprobe_lttng() at modprobe.c:488)
DBG1 - 19:35:41.549472249 [Main]: Modprobe successfully
lttng-ring-buffer-client-overwrite (in modprobe_lttng() at modprobe.c:488)
DBG1 - 19:35:41.552267354 [Main]: Modprobe successfully
lttng-ring-buffer-metadata-client (in modprobe_lttng() at modprobe.c:488)
DBG1 - 19:35:41.555095758 [Main]: Modprobe successfully
lttng-ring-buffer-client-mmap-discard (in modprobe_lttng() at modprobe.c:488)
DBG1 - 19:35:41.558010764 [Main]: Modprobe successfully
lttng-ring-buffer-client-mmap-overwrite (in modprobe_lttng() at modprobe.c:488)
DBG1 - 19:35:41.561680815 [Main]: Modprobe successfully
lttng-ring-buffer-metadata-mmap-client (in modprobe_lttng() at modprobe.c:488)
DBG1 - 19:35:41.565322606 [Main]: Modprobe successfully
lttng-ring-buffer-event_notifier-client (in modprobe_lttng() at modprobe.c:488)
DBG1 - 19:35:41.568785571 [Main]: Modprobe successfully
lttng-counter-client-percpu-64-modular (in modprobe_lttng() at modprobe.c:488)
DBG1 - 19:35:41.571843669 [Main]: Modprobe successfully
lttng-counter-client-percpu-32-modular (in modprobe_lttng() at modprobe.c:488)
DBG2 - 19:35:41.571873614 [Main]: Kernel tracer version validated (2.13, ABI
2.6) (in kernel_validate_version() at kernel.c:1524)
DBG1 - 19:35:41.577356753 [Main]: Modprobe successfully lttng-probe-asoc (in
modprobe_lttng() at modprobe.c:488)
DBG1 - 19:35:41.582390762 [Main]: Modprobe successfully lttng-probe-block (in
modprobe_lttng() at modprobe.c:488)
DBG1 - 19:35:41.584991241 [Main]: Unable to load optional module
lttng-probe-btrfs; continuing (in modprobe_lttng() at modprobe.c:483)
DBG1 - 19:35:41.588054255 [Main]: Modprobe successfully lttng-probe-compaction
(in modprobe_lttng() at modprobe.c:488)
DBG1 - 19:35:41.590214837 [Main]: Unable to load optional module
lttng-probe-ext3; continuing (in modprobe_lttng() at modprobe.c:483)
DBG1 - 19:35:41.592266900 [Main]: Unable to load optional module
lttng-probe-ext4; continuing (in modprobe_lttng() at modprobe.c:483)
DBG1 - 19:35:41.595589645 [Main]: Modprobe successfully lttng-probe-gpio (in
modprobe_lttng() at modprobe.c:488)
DBG1 - 19:35:41.598764426 [Main]: Modprobe successfully lttng-probe-i2c (in
modprobe_lttng() at modprobe.c:488)
DBG1 - 19:35:41.601733990 [Main]: Modprobe successfully lttng-probe-irq (in
modprobe_lttng() at modprobe.c:488)
DBG1 - 19:35:41.604019046 [Main]: Unable to load optional module
lttng-probe-jbd; continuing (in modprobe_lttng() at modprobe.c:483)
DBG1 - 19:35:41.607889663 [Main]: Modprobe successfully lttng-probe-jbd2 (in
modprobe_lttng() at modprobe.c:488)
DBG1 - 19:35:41.611579597 [Main]: Modprobe successfully lttng-probe-kmem (in
modprobe_lttng() at modprobe.c:488)
DBG1 - 19:35:41.616267719 [Main]: Modprobe successfully lttng-probe-kvm (in
modprobe_lttng() at modprobe.c:488)
DBG1 - 19:35:41.618545068 [Main]: Unable to load optional module
lttng-probe-kvm-x86; continuing (in modprobe_lttng() at modprobe.c:483)
DBG1 - 19:35:41.620589056 [Main]: Unable to load optional module
lttng-probe-kvm-x86-mmu; continuing (in modprobe_lttng() at modprobe.c:483)
DBG1 - 19:35:41.622606429 [Main]: Unable to load optional module
lttng-probe-lock; continuing (in modprobe_lttng() at modprobe.c:483)
DBG1 - 19:35:41.625400430 [Main]: Modprobe successfully lttng-probe-module (in
modprobe_lttng() at modprobe.c:488)
DBG1 - 19:35:41.629370961 [Main]: Modprobe successfully lttng-probe-napi (in
modprobe_lttng() at modprobe.c:488)
DBG1 - 19:35:41.632333031 [Main]: Modprobe successfully lttng-probe-net (in
modprobe_lttng() at modprobe.c:488)
DBG1 - 19:35:41.635211744 [Main]: Modprobe successfully lttng-probe-power (in
modprobe_lttng() at modprobe.c:488)
DBG1 - 19:35:41.638124508 [Main]: Unable to load optional module
lttng-probe-preemptirq; continuing (in modprobe_lttng() at modprobe.c:483)
DBG1 - 19:35:41.641601785 [Main]: Modprobe successfully lttng-probe-printk (in
modprobe_lttng() at modprobe.c:488)
DBG1 - 19:35:41.644219870 [Main]: Unable to load optional module
lttng-probe-random; continuing (in modprobe_lttng() at modprobe.c:483)
DBG1 - 19:35:41.647596579 [Main]: Modprobe successfully lttng-probe-rcu (in
modprobe_lttng() at modprobe.c:488)
DBG1 - 19:35:41.650129482 [Main]: Unable to load optional module
lttng-probe-regmap; continuing (in modprobe_lttng() at modprobe.c:483)
DBG1 - 19:35:41.652721729 [Main]: Modprobe successfully lttng-probe-regulator
(in modprobe_lttng() at modprobe.c:488)
DBG1 - 19:35:41.654983444 [Main]: Unable to load optional module
lttng-probe-rpm; continuing (in modprobe_lttng() at modprobe.c:483)
DBG1 - 19:35:41.657774174 [Main]: Modprobe successfully lttng-probe-sched (in
modprobe_lttng() at modprobe.c:488)
DBG1 - 19:35:41.660757625 [Main]: Modprobe successfully lttng-probe-scsi (in
modprobe_lttng() at modprobe.c:488)
DBG1 - 19:35:41.663721837 [Main]: Modprobe successfully lttng-probe-signal (in
modprobe_lttng() at modprobe.c:488)
DBG1 - 19:35:41.666681930 [Main]: Modprobe successfully lttng-probe-skb (in
modprobe_lttng() at modprobe.c:488)
DBG1 - 19:35:41.670489892 [Main]: Modprobe successfully lttng-probe-sock (in
modprobe_lttng() at modprobe.c:488)
DBG1 - 19:35:41.675314645 [Main]: Modprobe successfully lttng-probe-statedump
(in modprobe_lttng() at modprobe.c:488)
DBG1 - 19:35:41.680347292 [Main]: Modprobe successfully lttng-probe-sunrpc (in
modprobe_lttng() at modprobe.c:488)
DBG1 - 19:35:41.683499644 [Main]: Modprobe successfully lttng-probe-timer (in
modprobe_lttng() at modprobe.c:488)
DBG1 - 19:35:41.686439441 [Main]: Modprobe successfully lttng-probe-udp (in
modprobe_lttng() at modprobe.c:488)
DBG1 - 19:35:41.689640862 [Main]: Modprobe successfully lttng-probe-vmscan (in
modprobe_lttng() at modprobe.c:488)
DBG1 - 19:35:41.692516933 [Main]: Modprobe successfully lttng-probe-v4l2 (in
modprobe_lttng() at modprobe.c:488)
DBG1 - 19:35:41.695482560 [Main]: Modprobe successfully lttng-probe-workqueue
(in modprobe_lttng() at modprobe.c:488)
DBG1 - 19:35:41.698662297 [Main]: Modprobe successfully lttng-probe-writeback
(in modprobe_lttng() at modprobe.c:488)
DBG1 - 19:35:41.702647787 [Main]: Modprobe successfully
lttng-probe-x86-irq-vectors (in modprobe_lttng() at modprobe.c:488)
DBG1 - 19:35:41.706150681 [Main]: Modprobe successfully
lttng-probe-x86-exceptions (in modprobe_lttng() at modprobe.c:488)
DBG1 - 19:35:41.706214924 [Main]: Created kernel event notifier group: fd = 22
(in kernel_create_event_notifier_group() at kernel.c:265)
DBG1 - 19:35:41.706229681 [Main]: Created kernel notifier group notification
file descriptor: fd = 23 (in
kernel_create_event_notifier_group_notification_fd() at kernel.c:2237)
DBG1 - 19:35:41.706261020 [Main]: Created kernel event notifier group error
counter: fd = 24 (in event_notifier_error_accounting_register_kernel() at
event-notifier-error-accounting.c:1010)
DBG1 - 19:35:41.706282899 [Main]: Kernel tracer initialized: kernel tracer fd =
21, event notifier group fd = 22, event notifier group notification fd = 23 (in
init_kernel_tracer() at kernel.c:2007)
DBG3 - 19:35:41.706291680 [Main]: Syscall init system call table (in
syscall_init_table() at lttng-syscall.c:46)
DBG1 - 19:35:41.706609924 [Main]: Reallocating syscall table from 256 to 512
entries (in syscall_init_table() at lttng-syscall.c:91)
DBG1 - 19:35:41.707054401 [Main]: Reallocating syscall table from 512 to 1024
entries (in syscall_init_table() at lttng-syscall.c:91)
DBG2 - 19:35:41.707273004 [Main]: Creating consumer directory:
/var/run/lttng/ustconsumerd64 (in set_consumer_sockets() at main.c:1110)
DBG2 - 19:35:41.707334804 [Main]: Creating consumer directory:
/var/run/lttng/ustconsumerd32 (in set_consumer_sockets() at main.c:1110)
DBG3 - 19:35:41.707403093 [Main]: Created hashtable size 4 at 0x55f40f0bdc50 of
type U64 (in lttng_ht_new() at hashtable.c:153)
DBG3 - 19:35:41.707409888 [Main]: Global buffer per UID registry initialized
(in buffer_reg_init_uid_registry() at buffer-registry.c:90)
DBG3 - 19:35:41.707417638 [Main]: Created hashtable size 4 at 0x55f40f0bf440 of
type U64 (in lttng_ht_new() at hashtable.c:153)
DBG3 - 19:35:41.707423209 [Main]: Global buffer per PID registry initialized
(in buffer_reg_init_pid_registry() at buffer-registry.c:219)
DBG1 - 19:35:41.707429322 [Main]: Command subsystem initialized (in cmd_init()
at cmd.c:5896)
DBG1 - 19:35:41.707453597 [Main]: Pid 1502923 written in file
/var/run/lttng/lttng-sessiond.pid (in utils_create_pid_file() at utils.c:619)
DBG1 - 19:35:41.707480117 [Main]: TCP inet operation timeout set to 216 sec (in
lttcomm_inet_init() at inet.c:545)
DBG1 - 19:35:41.707525701 [Main]: Waiting for health management thread to be
ready (in wait_until_thread_is_ready() at health.c:35)
DBG1 - 19:35:41.707537239 [Health management]: Entering thread entry point (in
launch_thread() at thread.c:65)
DBG1 - 19:35:41.707548395 [Health management]: [thread] Manage health check
started (in thread_manage_health() at health.c:65)
DBG1 - 19:35:41.707630913 [Health management]: Marking health management thread
as ready (in mark_thread_as_ready() at health.c:28)
DBG1 - 19:35:41.707638954 [Health management]: Health check ready (in
thread_manage_health() at health.c:136)
DBG1 - 19:35:41.707645084 [Main]: Health management thread is ready (in
wait_until_thread_is_ready() at health.c:37)
DBG1 - 19:35:41.707688912 [Main]: Waiting for notification thread to be ready
(in wait_until_thread_is_ready() at notification-thread.c:412)
DBG1 - 19:35:41.707700910 [Notification]: Entering thread entry point (in
launch_thread() at thread.c:65)
DBG1 - 19:35:41.707711592 [Notification]: Started notification thread (in
thread_notification() at notification-thread.c:640)
DBG1 - 19:35:41.707731724 [Notification]: Creating notification channel UNIX
socket at /var/run/lttng/sessiond-notification (in
notification_channel_socket_create() at notification-thread.c:221)
DBG1 - 19:35:41.707789761 [Notification]: Notification channel UNIX socket
created (fd = 39) (in notification_channel_socket_create() at
notification-thread.c:256)
DBG1 - 19:35:41.707807364 [Notification]: Listening on notification channel
socket (in init_thread_state() at notification-thread.c:440)
DBG1 - 19:35:41.707859000 [Notification]: Marking notification thread as ready
(in mark_thread_as_ready() at notification-thread.c:405)
DBG1 - 19:35:41.707867074 [Notification]: Entering poll wait (in
thread_notification() at notification-thread.c:666)
DBG1 - 19:35:41.707868016 [Action Executor]: Entering thread entry point (in
launch_thread() at thread.c:65)
DBG1 - 19:35:41.707881827 [Action Executor]: Entering work execution loop (in
action_executor_thread() at action-executor.c:752)
DBG1 - 19:35:41.707889235 [Action Executor]: No work items enqueued, entering
wait (in action_executor_thread() at action-executor.c:761)
DBG1 - 19:35:41.707900012 [Main]: Notification thread is ready (in
wait_until_thread_is_ready() at notification-thread.c:414)
DBG1 - 19:35:41.707945723 [Timer]: Entering thread entry point (in
launch_thread() at thread.c:65)
DBG1 - 19:35:41.707978857 [Rotation]: Entering thread entry point (in
launch_thread() at thread.c:65)
DBG1 - 19:35:41.707990684 [Rotation]: Started rotation thread (in
thread_rotation() at rotation-thread.c:770)
DBG1 - 19:35:41.707994338 [Main]: Created client socket (fd = 45) (in
create_client_sock() at client.c:2547)
DBG1 - 19:35:41.708038957 [Main]: Waiting for client thread to be ready (in
wait_thread_status() at client.c:64)
DBG1 - 19:35:41.708049525 [Client management]: Entering thread entry point (in
launch_thread() at thread.c:65)
DBG1 - 19:35:41.708085123 [Notification]: Poll wait returned (1) (in
thread_notification() at notification-thread.c:668)
DBG1 - 19:35:41.708099121 [Notification]: Handling fd (39) activity (1) (in
thread_notification() at notification-thread.c:692)
DBG1 - 19:35:41.708105847 [Notification]: Handling new notification channel
client connection (in handle_notification_thread_client_connect() at
notification-thread-events.c:3323)
DBG1 - 19:35:41.708122220 [Notification]: Client socket (fd = 48) set as
non-blocking (in socket_set_non_blocking() at notification-thread-events.c:3291)
DBG1 - 19:35:41.708125990 [Client management]: [thread] Manage client started
(in thread_manage_clients() at client.c:2581)
DBG1 - 19:35:41.708137021 [Notification]: Added new notification channel client
socket (48) to poll set (in handle_notification_thread_client_connect() at
notification-thread-events.c:3376)
DBG1 - 19:35:41.708145153 [Notification]: Entering poll wait (in
thread_notification() at notification-thread.c:666)
DBG1 - 19:35:41.708151857 [Notification]: Poll wait returned (1) (in
thread_notification() at notification-thread.c:668)
DBG1 - 19:35:41.708157607 [Notification]: Handling fd (48) activity (1) (in
thread_notification() at notification-thread.c:692)
DBG1 - 19:35:41.708169927 [Notification]: Entering poll wait (in
thread_notification() at notification-thread.c:666)
DBG1 - 19:35:41.708172583 [Client management]: Marking client thread's state as
running (in set_thread_status() at client.c:57)
DBG1 - 19:35:41.708185271 [Client management]: Accepting client command ... (in
thread_manage_clients() at client.c:2647)
DBG1 - 19:35:41.708176050 [Notification]: Poll wait returned (1) (in
thread_notification() at notification-thread.c:668)
DBG1 - 19:35:41.708203912 [Notification]: Handling fd (48) activity (1) (in
thread_notification() at notification-thread.c:692)
DBG1 - 19:35:41.708187860 [Main]: Client thread is ready (in
wait_thread_status() at client.c:67)
DBG1 - 19:35:41.708222536 [Notification]: Received handshake from client: uid =
0, gid = 0, protocol version = 1.1, client is sessiond = true (in
client_handle_message_handshake() at notification-thread-events.c:3824)
DBG1 - 19:35:41.708249182 [Notification]: Send command reply (0) (in
client_send_command_reply() at notification-thread-events.c:3700)
DBG1 - 19:35:41.708271149 [Main]: All permissions are set (in set_permissions()
at main.c:1056)
DBG1 - 19:35:41.708273153 [Notification]: Flushing client (socket fd = 48)
outgoing queue (in client_flush_outgoing_queue() at
notification-thread-events.c:3577)
DBG1 - 19:35:41.708332358 [Rotation]: Entering poll wait (in thread_rotation()
at rotation-thread.c:794)
DBG1 - 19:35:41.708340162 [Notification]: Entering poll wait (in
thread_notification() at notification-thread.c:666)
DBG3 - 19:35:41.708339690 [Main]: Session daemon application socket created (fd
= 52) (in create_application_socket() at register.c:72)
DBG1 - 19:35:41.708354379 [UST registration dispatch]: Entering thread entry
point (in launch_thread() at thread.c:65)
DBG1 - 19:35:41.708372724 [UST registration dispatch]: [thread] Dispatch UST
command started (in thread_dispatch_ust_registration() at dispatch.c:250)
DBG1 - 19:35:41.708380665 [UST registration dispatch]: Futex n to 1 prepare
done (in futex_nto1_prepare() at futex.c:67)
DBG1 - 19:35:41.708389702 [UST registration dispatch]: Woken up but nothing in
the UST command queue (in thread_dispatch_ust_registration() at dispatch.c:279)
DBG1 - 19:35:41.708402601 [Main]: Waiting for application registration thread
to be ready (in wait_thread_status() at register.c:133)
DBG1 - 19:35:41.708457819 [UST application registration]: Entering thread entry
point (in launch_thread() at thread.c:65)
DBG1 - 19:35:41.708476247 [UST application registration]: [thread] Manage
application registration started (in thread_application_registration() at
register.c:170)
DBG1 - 19:35:41.708533194 [UST application registration]: Marking application
registration thread's state as running (in set_thread_status() at
register.c:126)
DBG1 - 19:35:41.708545078 [Main]: Application registration thread is ready (in
wait_thread_status() at register.c:136)
DBG1 - 19:35:41.708550831 [Main]: Notifying applications of session daemon
state: 1 (in notify_ust_apps() at register.c:93)
DBG1 - 19:35:41.708570129 [Main]: Wait shared memory file descriptor created
successfully: path = '/lttng-ust-wait-8', mmap_size = 4096, global = true, fd =
54 (in get_wait_shm() at shm.c:138)
DBG1 - 19:35:41.708586165 [Main]: Futex wait update active 1 (in
futex_wait_update() at futex.c:55)
DBG1 - 19:35:41.708642009 [UST application management]: Entering thread entry
point (in launch_thread() at thread.c:65)
DBG1 - 19:35:41.708651378 [UST application management]: [thread] Manage
application started (in thread_application_management() at manage-apps.c:52)
DBG1 - 19:35:41.708689348 [Application notification]: Entering thread entry
point (in launch_thread() at thread.c:65)
DBG1 - 19:35:41.708701012 [Main]: Waiting for agent management thread to be
ready (in wait_until_thread_is_ready() at agent-thread.c:348)
DBG1 - 19:35:41.708718739 [Agent management]: Entering thread entry point (in
launch_thread() at thread.c:65)
DBG1 - 19:35:41.708732284 [Agent management]: Manage agent application
registration. (in thread_agent_management() at agent-thread.c:366)
DBG3 - 19:35:41.708758918 [Agent management]: URI string: tcp://localhost (in
uri_parse() at uri.c:298)
DBG1 - 19:35:41.708701844 [Application notification]: [ust-thread] Manage
application notify command (in thread_application_notification() at
notify-apps.c:39)
DBG1 - 19:35:41.708848669 [UST application management]: Apps thread polling (in
thread_application_management() at manage-apps.c:88)
DBG3 - 19:35:41.708862067 [Application notification]: [ust-thread] Manage
notify polling (in thread_application_notification() at notify-apps.c:74)
DBG1 - 19:35:41.708895438 [UST application registration]: Accepting application
registration (in thread_application_registration() at register.c:209)
DBG2 - 19:35:41.708900120 [Agent management]: IP address resolved to 127.0.0.1
(in set_ip_address() at uri.c:155)
DBG3 - 19:35:41.708955356 [Agent management]: URI dtype: 1, proto: 1, host:
localhost, subdir: , ctrl: 0, data: 0 (in uri_parse() at uri.c:510)
DBG3 - 19:35:41.708979853 [Agent management]: Trying to bind on port 5345 (in
init_tcp_socket() at agent-thread.c:140)
DBG1 - 19:35:41.709000361 [Agent management]: Listening on TCP port 5345 and
socket 63 (in init_tcp_socket() at agent-thread.c:177)
DBG1 - 19:35:41.738889333 [Agent management]: Pid 5345 written in file
/var/run/lttng/agent.port (in utils_create_pid_file() at utils.c:619)
DBG1 - 19:35:41.738930061 [Agent management]: Marking agent management thread
as ready (in mark_thread_as_ready() at agent-thread.c:341)
DBG3 - 19:35:41.738985438 [Agent management]: Manage agent polling (in
thread_agent_management() at agent-thread.c:421)
DBG1 - 19:35:41.739007620 [Main]: Agent management thread is ready (in
wait_until_thread_is_ready() at agent-thread.c:350)
DBG1 - 19:35:41.739314948 [Main]: Beginning of waiter wait period (in
lttng_waiter_wait() at waiter.c:46)
DBG1 - 19:35:41.739361275 [Notification]: Poll wait returned (1) (in
thread_notification() at notification-thread.c:668)
DBG1 - 19:35:41.739621086 [Notification]: Handling fd (37) activity (1) (in
thread_notification() at notification-thread.c:692)
DBG1 - 19:35:41.739737968 [Notification]: Received `ADD_TRACER_EVENT_SOURCE`
command (in handle_notification_thread_command() at
notification-thread-events.c:3134)
DBG1 - 19:35:41.739390352 [Kernel management]: Entering thread entry point (in
launch_thread() at thread.c:65)
DBG3 - 19:35:41.739769765 [Notification]: Adding tracer event source fd to poll
set: tracer_event_source_fd = 23, domain = 'kernel' (in
handle_notification_thread_command_add_tracer_event_source() at
notification-thread-events.c:2037)
DBG1 - 19:35:41.739858048 [Kernel management]: [thread] Thread manage kernel
started (in thread_kernel_management() at manage-kernel.c:173)
DBG1 - 19:35:41.739871954 [Notification]: Entering poll wait (in
thread_notification() at notification-thread.c:666)
DBG1 - 19:35:41.739911750 [Main]: End of waiter wait period (in
lttng_waiter_wait() at waiter.c:89)
DBG1 - 19:35:41.739981251 [Kernel management]: Updating kernel poll set (in
update_kernel_poll() at manage-kernel.c:37)
DBG1 - 19:35:41.740006093 [Kernel management]: Thread kernel polling (in
thread_kernel_management() at manage-kernel.c:227)
----------
DBG1 - 19:36:12.280194102 [UST application registration]: UST registration
received with pid:1503211 ppid:0 uid:0 gid:0 sock:68 name:http-nio-8080-e
(version 9.0) (in thread_application_registration() at register.c:313)
DBG1 - 19:36:12.280223954 [UST application registration]: Futex n to 1 wake
done (in futex_nto1_wake() at futex.c:112)
DBG1 - 19:36:12.280232437 [UST registration dispatch]: Futex n to 1 wait done
(in futex_nto1_wait() at futex.c:95)
DBG1 - 19:36:12.280242081 [UST registration dispatch]: Futex n to 1 prepare
done (in futex_nto1_prepare() at futex.c:67)
DBG1 - 19:36:12.280234593 [UST application registration]: Accepting application
registration (in thread_application_registration() at register.c:209)
DBG1 - 19:36:12.280280437 [UST application registration]: UST registration
received with pid:1503211 ppid:0 uid:0 gid:0 sock:69 name:http-nio-8080-e
(version 9.0) (in thread_application_registration() at register.c:313)
DBG1 - 19:36:12.280291589 [UST application registration]: Futex n to 1 wake
done (in futex_nto1_wake() at futex.c:112)
DBG1 - 19:36:12.280297424 [UST application registration]: Accepting application
registration (in thread_application_registration() at register.c:209)
DBG1 - 19:36:12.280250240 [UST registration dispatch]: Dispatching UST
registration pid:1503211 ppid:0 uid:0 gid:0 sock:68 name:http-nio-8080-e
(version 9.0) (in thread_dispatch_ust_registration() at dispatch.c:286)
DBG3 - 19:36:12.280333506 [UST registration dispatch]: UST app creating
application for socket 68 (in ust_app_create() at ust-app.c:3953)
DBG3 - 19:36:12.280355291 [UST registration dispatch]: Created hashtable size 4
at 0x7f4180000da0 of type U64 (in lttng_ht_new() at hashtable.c:153)
DBG3 - 19:36:12.280362965 [UST registration dispatch]: Created hashtable size 4
at 0x7f41800012e0 of type ULONG (in lttng_ht_new() at hashtable.c:153)
DBG3 - 19:36:12.280370732 [UST registration dispatch]: Created hashtable size 4
at 0x7f4180001820 of type ULONG (in lttng_ht_new() at hashtable.c:153)
DBG3 - 19:36:12.280378679 [UST registration dispatch]: Created hashtable size 4
at 0x7f4180001d60 of type U64 (in lttng_ht_new() at hashtable.c:153)
DBG1 - 19:36:12.280396256 [UST registration dispatch]: Dispatching UST
registration pid:1503211 ppid:0 uid:0 gid:0 sock:69 name:http-nio-8080-e
(version 9.0) (in thread_dispatch_ust_registration() at dispatch.c:286)
DBG3 - 19:36:12.280402866 [UST registration dispatch]: UST app notify socket 69
is set (in thread_dispatch_ust_registration() at dispatch.c:353)
DBG1 - 19:36:12.280411347 [UST registration dispatch]: App registered with
pid:1503211 ppid:0 uid:0 gid:0 sock =68 name:http-nio-8080-e notify_sock =69
(version 9.0) (in ust_app_add() at ust-app.c:4070)
DBG1 - 19:36:12.280551786 [UST registration dispatch]: Beginning of waiter wait
period (in lttng_waiter_wait() at waiter.c:46)
DBG1 - 19:36:12.280558463 [Notification]: Poll wait returned (1) (in
thread_notification() at notification-thread.c:668)
DBG1 - 19:36:12.280568183 [Notification]: Handling fd (37) activity (1) (in
thread_notification() at notification-thread.c:692)
DBG1 - 19:36:12.280577154 [Notification]: Received `ADD_TRACER_EVENT_SOURCE`
command (in handle_notification_thread_command() at
notification-thread-events.c:3134)
DBG3 - 19:36:12.280583549 [Notification]: Adding tracer event source fd to poll
set: tracer_event_source_fd = 70, domain = 'ust' (in
handle_notification_thread_command_add_tracer_event_source() at
notification-thread-events.c:2037)
DBG1 - 19:36:12.280596669 [Notification]: Entering poll wait (in
thread_notification() at notification-thread.c:666)
DBG1 - 19:36:12.280597142 [UST registration dispatch]: End of waiter wait
period (in lttng_waiter_wait() at waiter.c:89)
DBG2 - 19:36:12.281513794 [UST registration dispatch]: UST application global
event notifier rules update: app = 'http-nio-8080-e', pid = 1503211) (in
ust_app_global_update_event_notifier_rules() at ust-app.c:6123)
DBG1 - 19:36:12.281533038 [UST registration dispatch]: Beginning of waiter wait
period (in lttng_waiter_wait() at waiter.c:46)
DBG3 - 19:36:12.281516457 [Application notification]: [ust-thread] Manage
notify return from poll on 2 fds (in thread_application_notification() at
notify-apps.c:80)
DBG3 - 19:36:12.281596258 [Application notification]: UST thread notify added
sock 69 to pollset (in thread_application_notification() at notify-apps.c:134)
DBG3 - 19:36:12.281601977 [Application notification]: [ust-thread] Manage
notify polling (in thread_application_notification() at notify-apps.c:74)
DBG1 - 19:36:12.281612738 [Notification]: Poll wait returned (1) (in
thread_notification() at notification-thread.c:668)
DBG1 - 19:36:12.281618271 [Notification]: Handling fd (37) activity (1) (in
thread_notification() at notification-thread.c:692)
DBG1 - 19:36:12.281625316 [Notification]: Received `LIST_TRIGGERS` command (in
handle_notification_thread_command() at notification-thread-events.c:3134)
DBG1 - 19:36:12.281634347 [Notification]: Entering poll wait (in
thread_notification() at notification-thread.c:666)
DBG1 - 19:36:12.281641599 [UST registration dispatch]: End of waiter wait
period (in lttng_waiter_wait() at waiter.c:89)
DBG1 - 19:36:12.281704004 [UST registration dispatch]: Woken up but nothing in
the UST command queue (in thread_dispatch_ust_registration() at dispatch.c:279)
DBG1 - 19:36:12.281709432 [UST application management]: Apps thread return from
poll on 2 fds (in thread_application_management() at manage-apps.c:94)
DBG1 - 19:36:12.281728188 [UST application management]: Apps with sock 68 added
to poll set (in thread_application_management() at manage-apps.c:145)
DBG1 - 19:36:12.281736995 [UST application management]: Apps thread polling (in
thread_application_management() at manage-apps.c:88)
DBG1 - 19:36:12.281712650 [UST registration dispatch]: Futex n to 1 wait done
(in futex_nto1_wait() at futex.c:95)
DBG1 - 19:36:12.281747647 [UST registration dispatch]: Futex n to 1 prepare
done (in futex_nto1_prepare() at futex.c:67)
DBG1 - 19:36:12.281752439 [UST registration dispatch]: Woken up but nothing in
the UST command queue (in thread_dispatch_ust_registration() at dispatch.c:279)
_______________________________________________
lttng-dev mailing list
lttng-dev@lists.lttng.org
https://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev
