~ ⋙ 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)