[lttng-dev] Tracing a docker containerized java application from the host
Adel Belkhiri
adel.belkhiri at gmail.com
Wed Mar 15 20:03:20 EDT 2023
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
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.lttng.org/pipermail/lttng-dev/attachments/20230315/76910b3a/attachment-0001.htm>
-------------- next part --------------
~ ⋙ 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)
More information about the lttng-dev
mailing list