Bug #1419
closedLTTng-modules can not work
0%
Description
Hello everyone!
my ARM manchine can not list kernel events:- uname -mrspvio
Linux 4.14.61-rt37 #1 SMP PREEMPT RT Tue Nov 12 18:24:47 CST 2024 aarch64 unknown unknown GNU/Linux - lsmod
Module Size Used by Tainted: G
lttng_tracer 2895872 0
lttng_statedump 32768 1 lttng_tracer
lttng_wrapper 16384 2 lttng_tracer,lttng_statedump
lttng_clock 16384 1 lttng_tracer
lttng_lib_ring_buffer 69632 1 lttng_tracer
xrp_hw_semidrive 16384 0
lm75 20480 0
sr9900 49152 0
ecdh_generic 24576 0
crypto_engine 16384 0
pvrsrvkm 1454080 0
yt6801 143360 0
dtbocfg 16384 0
lt8912 16384 0 - lttng list -k
Error: lttng_ctl_ask_sessiond_fds_varlen:607
Error: lttng_ctl_ask_sessiond_fds_varlen -33
Error: Unable to list kernel events: Kernel tracer not available
#
Error is in lttng-ctl.c:lttng_ctl_ask_sessiond_fds_varlen:line 607 recv_data_sessiond buf is wrong.
Please help me to solve this problem! Thanks.
Updated by Kienan Stewart about 1 month ago · Edited
Hi Ai Chen,
which versions of lttng-modules and lttng-tools are you using?
Is there any relevant output in dmesg / the kernel log, and when running `lttng-sessiond` with `-vvv --verbose-consumer`?
thanks,
kienan
Updated by Kienan Stewart about 1 month ago
Hi Ai Chen,
I have a couple more questions about your setup in order to clarify a suspicion that there is a protocol mis-match between the `lttng` client and `lttng-sessiond`.
- What is the version of lttng from `lttng --version`, and which version is shown when starting the sessiond in verbose mode (`lttng-sessiond -vvv`)?
- Are you running lttng (or the application that's using liblttng-ctl) and lttng-sessiond in the same container or host-OS?
- Could you the output of the following commands: `ldd $(which lttng)` and `ldd $(which lttng-sessiond)`.
thanks,
kienan
Updated by Ai Chen about 1 month ago
Hi Kienan,
Here is some information I can provide according to your requirements:- lttng --version
lttng (LTTng Trace Control) 2.13.8 - Nordicite
- lttng-sessiond -vvv
DBG1 - 09:17:58.708608486 [Main]: [sessiond configuration]
DBG1 - 09:17:58.708750152 [Main]: version 2.13.8
DBG1 - 09:17:58.708773486 [Main]: verbose: 3
DBG1 - 09:17:58.708791819 [Main]: verbose consumer: 0
DBG1 - 09:17:58.708802819 [Main]: quiet mode: False
DBG1 - 09:17:58.708813152 [Main]: agent_tcp_port: [5345, 5354]
DBG1 - 09:17:58.708825819 [Main]: application socket timeout: 5
DBG1 - 09:17:58.708835819 [Main]: no-kernel: False
DBG1 - 09:17:58.708846486 [Main]: background: False
DBG1 - 09:17:58.708856486 [Main]: daemonize: False
DBG1 - 09:17:58.708866152 [Main]: signal parent on start: False
DBG1 - 09:17:58.708881152 [Main]: tracing group name: tracing
DBG1 - 09:17:58.708900486 [Main]: kmod_probe_list: None
DBG1 - 09:17:58.708915486 [Main]: kmod_extra_probe_list: None
DBG1 - 09:17:58.708925486 [Main]: rundir: /run/lttng
DBG1 - 09:17:58.708936486 [Main]: application socket path: /run/lttng/lttng-ust-sock-8
DBG1 - 09:17:58.708946486 [Main]: client socket path: /run/lttng/client-lttng-sessiond
DBG1 - 09:17:58.708956819 [Main]: wait shm path: /lttng-ust-wait-8
DBG1 - 09:17:58.708966152 [Main]: health socket path: /run/lttng/sessiond-health
DBG1 - 09:17:58.708976486 [Main]: LTTNG_UST_CLOCK_PLUGIN: None
DBG1 - 09:17:58.708988152 [Main]: pid file path: /run/lttng/lttng-sessiond.pid
DBG1 - 09:17:58.708998486 [Main]: lock file path: /run/lttng/lttng-sessiond.lck
DBG1 - 09:17:58.709008486 [Main]: session load path: None
DBG1 - 09:17:58.709018486 [Main]: agent port file path: /run/lttng/agent.port
DBG1 - 09:17:58.709028152 [Main]: consumerd32 path: /run/lttng/ustconsumerd32
DBG1 - 09:17:58.709038486 [Main]: consumerd32 bin path: Unknown
DBG1 - 09:17:58.709053486 [Main]: consumerd32 lib dir: Unknown
DBG1 - 09:17:58.709071819 [Main]: consumerd32 err unix sock path:/run/lttng/ustconsumerd32/error
DBG1 - 09:17:58.709086486 [Main]: consumerd32 cmd unix sock path:/run/lttng/ustconsumerd32/command
DBG1 - 09:17:58.709112152 [Main]: consumerd64 path: /run/lttng/ustconsumerd64
DBG1 - 09:17:58.709127152 [Main]: consumerd64 bin path: /usr/lib/lttng/libexec/lttng-consumerd
DBG1 - 09:17:58.709138486 [Main]: consumerd64 lib dir: /usr/lib
DBG1 - 09:17:58.709148486 [Main]: consumerd64 err unix sock path:/run/lttng/ustconsumerd64/error
DBG1 - 09:17:58.709158486 [Main]: consumerd64 cmd unix sock path:/run/lttng/ustconsumerd64/command
DBG1 - 09:17:58.709168486 [Main]: kconsumerd path: /run/lttng/kconsumerd
DBG1 - 09:17:58.709178486 [Main]: kconsumerd err unix sock path: /run/lttng/kconsumerd/error
DBG1 - 09:17:58.709188152 [Main]: kconsumerd cmd unix sock path: /run/lttng/kconsumerd/command
DBG1 - 09:17:58.709278152 [Main]: Starting lttng-sessiond {bf588050-7133-4918-b91b-ba617367d5ab} (in sessiond_uuid_log() at main.c:1437)
DBG3 - 09:17:58.709299486 [Main]: Creating LTTng run directory: /run/lttng (in create_lttng_rundir() at main.c:1069)
DBG1 - 09:17:58.710141486 [Main]: Resetting run_as worker signal handlers to default (in reset_sighandler() at runas.c:1377)
DBG1 - 09:17:58.710510486 [Main]: run_as signal handler set for SIGTERM and SIGINT (in set_worker_sighandlers() at runas.c:1438)
DBG1 - 09:17:58.712293152 [Main]: Health check time delta in seconds set to 20 (in health_init() at health.c:62)
DBG1 - 09:17:58.712631486 [HT cleanup]: Entering thread entry point (in launch_thread() at thread.c:65)
DBG1 - 09:17:58.712665152 [HT cleanup]: startup. (in thread_ht_cleanup() at ht-cleanup.c:98)
DBG1 - 09:17:58.712771486 [HT cleanup]: epoll set max size is 585216 (in compat_epoll_set_max_size() at poll.c:350)
DBG3 - 09:17:58.712859152 [Main]: Created hashtable size 16 at 0x1b65370 of type U64 (in lttng_ht_new() at hashtable.c:152)
DBG3 - 09:17:58.712878486 [HT cleanup]: Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)
DBG3 - 09:17:58.712891486 [Main]: Created hashtable size 16 at 0x1b658c0 of type U64 (in lttng_ht_new() at hashtable.c:152)
DBG3 - 09:17:58.712951486 [Main]: Created hashtable size 16 at 0x1b65f20 of type U64 (in lttng_ht_new() at hashtable.c:152)
DBG3 - 09:17:58.712972152 [Main]: Created hashtable size 4 at 0x1b66440 of type ULONG (in lttng_ht_new() at hashtable.c:152)
DBG3 - 09:17:58.712997486 [Main]: Created hashtable size 4 at 0x1b66880 of type U64 (in lttng_ht_new() at hashtable.c:152)
DBG2 - 09:17:58.713010486 [Main]: Creating consumer directory: /run/lttng/kconsumerd (in set_consumer_sockets() at main.c:1111)
Warning: No tracing group detected
Error: Failed to load kmod library resources
Warning: No kernel tracer available
DBG2 - 09:17:58.714427486 [Main]: Creating consumer directory: /run/lttng/ustconsumerd64 (in set_consumer_sockets() at main.c:1111)
DBG2 - 09:17:58.714561152 [Main]: Creating consumer directory: /run/lttng/ustconsumerd32 (in set_consumer_sockets() at main.c:1111)
DBG3 - 09:17:58.714738819 [Main]: Created hashtable size 4 at 0x1b67830 of type U64 (in lttng_ht_new() at hashtable.c:152)
DBG3 - 09:17:58.714760486 [Main]: Global buffer per UID registry initialized (in buffer_reg_init_uid_registry() at buffer-registry.c:90)
DBG3 - 09:17:58.714776152 [Main]: Created hashtable size 4 at 0x1b68120 of type U64 (in lttng_ht_new() at hashtable.c:152)
DBG3 - 09:17:58.714792819 [Main]: Global buffer per PID registry initialized (in buffer_reg_init_pid_registry() at buffer-registry.c:219)
DBG1 - 09:17:58.714807152 [Main]: Command subsystem initialized (in cmd_init() at cmd.c:6064)
DBG1 - 09:17:58.714857819 [Main]: '10546' written in file /run/lttng/lttng-sessiond.pid (in utils_create_pid_file() at utils.c:257)
DBG1 - 09:17:58.715022152 [Main]: TCP inet operation timeout set to 216 sec (in lttcomm_inet_init() at inet.c:545)
DBG1 - 09:17:58.715137486 [Main]: Waiting for health management thread to be ready (in wait_until_thread_is_ready() at health.c:35)
DBG1 - 09:17:58.715160486 [Health management]: Entering thread entry point (in launch_thread() at thread.c:65)
DBG1 - 09:17:58.715193819 [Health management]: [thread] Manage health check started (in thread_manage_health() at health.c:65)
DBG1 - 09:17:58.715457819 [Health management]: Marking health management thread as ready (in mark_thread_as_ready() at health.c:28)
DBG1 - 09:17:58.715488486 [Health management]: Health check ready (in thread_manage_health() at health.c:136)
DBG1 - 09:17:58.715493486 [Main]: Health management thread is ready (in wait_until_thread_is_ready() at health.c:37)
DBG1 - 09:17:58.715763486 [Main]: Waiting for notification thread to be ready (in wait_until_thread_is_ready() at notification-thread.c:414)
DBG1 - 09:17:58.715781152 [Notification]: Entering thread entry point (in launch_thread() at thread.c:65)
DBG1 - 09:17:58.715808152 [Notification]: Started notification thread (in thread_notification() at notification-thread.c:642)
DBG1 - 09:17:58.715851152 [Notification]: Creating notification channel UNIX socket at /run/lttng/sessiond-notification (in notification_channel_socket_create() at notification-thread.c:223)
DBG1 - 09:17:58.715968486 [Notification]: Notification channel UNIX socket created (fd = 34) (in notification_channel_socket_create() at notification-thread.c:258)
DBG1 - 09:17:58.716014152 [Notification]: Listening on notification channel socket (in init_thread_state() at notification-thread.c:442)
DBG1 - 09:17:58.716109819 [Notification]: Marking notification thread as ready (in mark_thread_as_ready() at notification-thread.c:407)
DBG1 - 09:17:58.716136152 [Notification]: Entering poll wait (in thread_notification() at notification-thread.c:668)
DBG1 - 09:17:58.716141486 [Main]: Notification thread is ready (in wait_until_thread_is_ready() at notification-thread.c:416)
DBG1 - 09:17:58.716242486 [Action Executor]: Entering thread entry point (in launch_thread() at thread.c:65)
DBG1 - 09:17:58.716251819 [Timer]: Entering thread entry point (in launch_thread() at thread.c:65)
DBG1 - 09:17:58.716346486 [Rotation]: Entering thread entry point (in launch_thread() at thread.c:65)
DBG1 - 09:17:58.716446819 [Main]: Created client socket (fd = 40) (in create_client_sock() at client.c:2428)
DBG1 - 09:17:58.716572486 [Rotation]: Started rotation thread (in thread_rotation() at rotation-thread.c:789)
DBG1 - 09:17:58.716645152 [Main]: Waiting for client thread to be ready (in wait_thread_status() at client.c:65)
DBG1 - 09:17:58.716769819 [Action Executor]: Entering work execution loop (in action_executor_thread() at action-executor.c:761)
DBG1 - 09:17:58.716783819 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.c:670)
DBG1 - 09:17:58.717030152 [Notification]: Handling fd (34) activity (1) (in thread_notification() at notification-thread.c:694)
DBG1 - 09:17:58.717049152 [Notification]: Handling new notification channel client connection (in handle_notification_thread_client_connect() at notification-thread-events.c:3351)
DBG1 - 09:17:58.717092152 [Notification]: Client socket (fd = 43) set as non-blocking (in socket_set_non_blocking() at notification-thread-events.c:3319)
DBG1 - 09:17:58.717122819 [Notification]: Added new notification channel client socket (43) to poll set (in handle_notification_thread_client_connect() at notification-thread-events.c:3404)
DBG1 - 09:17:58.717151152 [Notification]: Entering poll wait (in thread_notification() at notification-thread.c:668)
DBG1 - 09:17:58.717171486 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.c:670)
DBG1 - 09:17:58.717182152 [Notification]: Handling fd (43) activity (1) (in thread_notification() at notification-thread.c:694)
DBG1 - 09:17:58.717207152 [Notification]: Entering poll wait (in thread_notification() at notification-thread.c:668)
DBG1 - 09:17:58.717224152 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.c:670)
DBG1 - 09:17:58.717234486 [Notification]: Handling fd (43) activity (1) (in thread_notification() at notification-thread.c:694)
DBG1 - 09:17:58.717280819 [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:3879)
DBG1 - 09:17:58.717320819 [Notification]: Send command reply (0) (in client_send_command_reply() at notification-thread-events.c:3755)
DBG1 - 09:17:58.717358819 [Notification]: Flushing client (socket fd = 43) outgoing queue (in client_flush_outgoing_queue() at notification-thread-events.c:3644)
DBG1 - 09:17:58.717519486 [Notification]: Entering poll wait (in thread_notification() at notification-thread.c:668)
DBG1 - 09:17:58.716885152 [Client management]: Entering thread entry point (in launch_thread() at thread.c:65)
DBG1 - 09:17:58.717579819 [Rotation]: Entering poll wait (in thread_rotation() at rotation-thread.c:813)
DBG1 - 09:17:58.717794819 [Client management]: [thread] Manage client started (in thread_manage_clients() at client.c:2461)
DBG1 - 09:17:58.717009152 [Action Executor]: No work items enqueued, entering wait (in action_executor_thread() at action-executor.c:770)
DBG1 - 09:17:58.717901486 [Client management]: Marking client thread's state as running (in set_thread_status() at client.c:58)
DBG1 - 09:17:58.718099819 [Client management]: Accepting client command ... (in thread_manage_clients() at client.c:2527)
DBG1 - 09:17:58.718100152 [Main]: Client thread is ready (in wait_thread_status() at client.c:68)
DBG1 - 09:17:58.718305486 [Main]: All permissions are set (in set_permissions() at main.c:1057)
DBG1 - 09:17:58.718503486 [UST registration dispatch]: Entering thread entry point (in launch_thread() at thread.c:65)
DBG3 - 09:17:58.718508819 [Main]: Session daemon application socket created (fd = 47) (in create_application_socket() at register.c:71)
DBG1 - 09:17:58.718754486 [Main]: Waiting for application registration thread to be ready (in wait_thread_status() at register.c:131)
DBG1 - 09:17:58.718773152 [UST application registration]: Entering thread entry point (in launch_thread() at thread.c:65)
DBG1 - 09:17:58.718806486 [UST application registration]: [thread] Manage application registration started (in thread_application_registration() at register.c:168)
DBG1 - 09:17:58.718860819 [UST application registration]: Marking application registration thread's state as running (in set_thread_status() at register.c:124)
DBG1 - 09:17:58.718889152 [UST application registration]: Accepting application registration (in thread_application_registration() at register.c:207)
DBG1 - 09:17:58.718892152 [Main]: Application registration thread is ready (in wait_thread_status() at register.c:134)
DBG1 - 09:17:58.718922486 [Main]: Notifying applications of session daemon state: 1 (in notify_ust_apps() at register.c:91)
DBG1 - 09:17:58.718680152 [UST registration dispatch]: [thread] Dispatch UST command started (in thread_dispatch_ust_registration() at dispatch.c:250)
DBG1 - 09:17:58.719049819 [Main]: Wait shared memory file descriptor created successfully: path = '/lttng-ust-wait-8', mmap_size = 4096, global = true, fd = 49 (in get_wait_shm() at shm.c:133)
DBG1 - 09:17:58.719256486 [Main]: Futex wait update active 1 (in futex_wait_update() at futex.c:55)
DBG1 - 09:17:58.719191819 [UST registration dispatch]: Futex n to 1 prepare done (in futex_nto1_prepare() at futex.c:67)
DBG1 - 09:17:58.719470486 [UST application management]: Entering thread entry point (in launch_thread() at thread.c:65)
DBG1 - 09:17:58.719596486 [UST application management]: [thread] Manage application started (in thread_application_management() at manage-apps.c:52)
DBG1 - 09:17:58.719760486 [UST registration dispatch]: Woken up but nothing in the UST command queue (in thread_dispatch_ust_registration() at dispatch.c:279)
DBG1 - 09:17:58.719834152 [UST application management]: Apps thread polling (in thread_application_management() at manage-apps.c:88)
DBG1 - 09:17:58.720055819 [Kernel management]: Entering thread entry point (in launch_thread() at thread.c:65)
DBG1 - 09:17:58.720284152 [Kernel management]: [thread] Thread manage kernel started (in thread_kernel_management() at manage-kernel.c:173)
DBG1 - 09:17:58.720554152 [Kernel management]: Updating kernel poll set (in update_kernel_poll() at manage-kernel.c:37)
DBG1 - 09:17:58.720778152 [Kernel management]: Thread kernel polling (in thread_kernel_management() at manage-kernel.c:227)
----It will get stuck here.(I don't know why)----
^CDBG1 - 09:18:23.249577155 [Main]: SIGINT caught (in sighandler() at main.c:1179)
DBG1 - 09:18:23.249633822 [Main]: Terminating all threads (in stop_threads() at main.c:177)
DBG1 - 09:18:23.249586489 [Run-as worker]: run_as worker received signal SIGINT (in worker_sighandler() at runas.c:1407)
DBG1 - 09:18:23.249758822 [Main]: Shutting down "Client management" thread (in _lttng_thread_shutdown() at thread.c:153)
DBG1 - 09:18:23.249914822 [Client management]: Client thread dying (in thread_manage_clients() at client.c:2722)
DBG1 - 09:18:23.249952155 [Client management]: Thread entry point has returned (in launch_thread() at thread.c:67)
DBG1 - 09:18:23.250046822 [Main]: Joined thread "Client management" (in _lttng_thread_shutdown() at thread.c:168)
DBG1 - 09:18:23.250099155 [Main]: Initiating destruction of all sessions (in destroy_all_sessions_and_wait() at main.c:1321)
DBG1 - 09:18:23.250185155 [Main]: Waiting for the destruction of all sessions to complete (in destroy_all_sessions_and_wait() at main.c:1349)
DBG1 - 09:18:23.250198489 [Main]: Destruction of all sessions completed (in destroy_all_sessions_and_wait() at main.c:1351)
DBG1 - 09:18:23.250213822 [Main]: Unregistering all triggers (in unregister_all_triggers() at main.c:1364)
DBG1 - 09:18:23.250237489 [Main]: Beginning of waiter wait period (in lttng_waiter_wait() at waiter.c:46)
DBG1 - 09:18:23.250250822 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.c:670)
DBG1 - 09:18:23.250270489 [Notification]: Handling fd (33) activity (1) (in thread_notification() at notification-thread.c:694)
DBG1 - 09:18:23.250288155 [Notification]: Received `LIST_TRIGGERS` command (in handle_notification_thread_command() at notification-thread-events.c:3162)
DBG1 - 09:18:23.250333489 [Notification]: Entering poll wait (in thread_notification() at notification-thread.c:668)
DBG1 - 09:18:23.250335489 [Main]: End of waiter wait period (in lttng_waiter_wait() at waiter.c:99)
DBG1 - 09:18:23.250364155 [Main]: Shutting down "UST application registration" thread (in _lttng_thread_shutdown() at thread.c:153)
DBG1 - 09:18:23.250567489 [UST application registration]: Notifying applications of session daemon state: 0 (in notify_ust_apps() at register.c:91)
DBG1 - 09:18:23.250670155 [UST application registration]: Wait shared memory file descriptor created successfully: path = '/lttng-ust-wait-8', mmap_size = 4096, global = true, fd = 38 (in get_wait_shm() at shm.c:133)
DBG1 - 09:18:23.250735489 [UST application registration]: Futex wait update active 0 (in futex_wait_update() at futex.c:55)
DBG1 - 09:18:23.250816489 [UST application registration]: UST Registration thread cleanup complete (in thread_application_registration() at register.c:364)
DBG1 - 09:18:23.250836155 [UST application registration]: Thread entry point has returned (in launch_thread() at thread.c:67)
DBG1 - 09:18:23.250892155 [Main]: Joined thread "UST application registration" (in _lttng_thread_shutdown() at thread.c:168)
DBG1 - 09:18:23.250936822 [Main]: Shutting down "Kernel management" thread (in _lttng_thread_shutdown() at thread.c:153)
DBG1 - 09:18:23.250992489 [Kernel management]: Thread kernel return from poll on 2 fds (in thread_kernel_management() at manage-kernel.c:233)
DBG1 - 09:18:23.251032155 [Kernel management]: Kernel thread dying (in thread_kernel_management() at manage-kernel.c:309)
DBG1 - 09:18:23.251044155 [Kernel management]: Thread entry point has returned (in launch_thread() at thread.c:67)
DBG1 - 09:18:23.251089822 [Main]: Joined thread "Kernel management" (in _lttng_thread_shutdown() at thread.c:168)
DBG1 - 09:18:23.251112155 [Main]: Shutting down "UST application management" thread (in _lttng_thread_shutdown() at thread.c:153)
DBG1 - 09:18:23.251158155 [UST application management]: Apps thread return from poll on 2 fds (in thread_application_management() at manage-apps.c:94)
DBG1 - 09:18:23.251213822 [UST application management]: Application communication apps thread cleanup complete (in thread_application_management() at manage-apps.c:194)
DBG1 - 09:18:23.251228155 [UST application management]: Thread entry point has returned (in launch_thread() at thread.c:67)
DBG1 - 09:18:23.251266489 [Main]: Joined thread "UST application management" (in _lttng_thread_shutdown() at thread.c:168)
DBG1 - 09:18:23.251288155 [Main]: Shutting down "UST registration dispatch" thread (in _lttng_thread_shutdown() at thread.c:153)
DBG1 - 09:18:23.251319155 [Main]: Futex n to 1 wake done (in futex_nto1_wake() at futex.c:121)
DBG1 - 09:18:23.251365155 [UST registration dispatch]: Futex n to 1 wait done (in futex_nto1_wait() at futex.c:104)
DBG1 - 09:18:23.251425822 [UST registration dispatch]: Futex n to 1 prepare done (in futex_nto1_prepare() at futex.c:67)
DBG1 - 09:18:23.251440822 [UST registration dispatch]: Dispatch thread dying (in thread_dispatch_ust_registration() at dispatch.c:486)
DBG1 - 09:18:23.251459822 [UST registration dispatch]: Thread entry point has returned (in launch_thread() at thread.c:67)
DBG1 - 09:18:23.251565489 [Main]: Joined thread "UST registration dispatch" (in _lttng_thread_shutdown() at thread.c:168)
DBG1 - 09:18:23.251590489 [Main]: Shutting down "Rotation" thread (in _lttng_thread_shutdown() at thread.c:153)
DBG1 - 09:18:23.251635822 [Rotation]: Poll wait returned (1) (in thread_rotation() at rotation-thread.c:815)
DBG1 - 09:18:23.251664489 [Rotation]: Handling fd (36) activity (1) (in thread_rotation() at rotation-thread.c:833)
DBG1 - 09:18:23.251683155 [Rotation]: Quit pipe activity (in thread_rotation() at rotation-thread.c:873)
DBG1 - 09:18:23.251693822 [Rotation]: Thread exit (in thread_rotation() at rotation-thread.c:881)
DBG1 - 09:18:23.251780155 [Rotation]: Thread entry point has returned (in launch_thread() at thread.c:67)
DBG1 - 09:18:23.251848489 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.c:670)
DBG1 - 09:18:23.251871489 [Notification]: Handling fd (43) activity (8209) (in thread_notification() at notification-thread.c:694)
DBG1 - 09:18:23.251890489 [Notification]: Closing client connection (socket fd = 43) (in handle_notification_thread_client_disconnect() at notification-thread-events.c:3470)
DBG1 - 09:18:23.252017822 [Main]: Joined thread "Rotation" (in _lttng_thread_shutdown() at thread.c:168)
DBG1 - 09:18:23.252038489 [Main]: Shutting down "Timer" thread (in _lttng_thread_shutdown() at thread.c:153)
DBG1 - 09:18:23.252089822 [Notification]: Entering poll wait (in thread_notification() at notification-thread.c:668)
DBG1 - 09:18:23.252134489 [Timer]: Thread exit (in thread_timer() at timer.c:402)
DBG1 - 09:18:23.252154155 [Timer]: Thread entry point has returned (in launch_thread() at thread.c:67)
DBG1 - 09:18:23.252220155 [Main]: Joined thread "Timer" (in _lttng_thread_shutdown() at thread.c:168)
DBG1 - 09:18:23.252240822 [Main]: Shutting down "Health management" thread (in _lttng_thread_shutdown() at thread.c:153)
DBG1 - 09:18:23.252279822 [Health management]: Health check thread dying (in thread_manage_health() at health.c:231)
DBG1 - 09:18:23.252365155 [Health management]: Thread entry point has returned (in launch_thread() at thread.c:67)
DBG1 - 09:18:23.252528822 [Main]: Joined thread "Health management" (in _lttng_thread_shutdown() at thread.c:168)
DBG1 - 09:18:23.262682822 [Main]: Cleanup sessiond (in sessiond_cleanup() at main.c:282)
DBG1 - 09:18:23.262866822 [Main]: Removing sessiond and consumerd content of directory /run/lttng (in sessiond_cleanup() at main.c:298)
DBG1 - 09:18:23.262887489 [Main]: Removing /run/lttng/lttng-sessiond.pid (in sessiond_cleanup() at main.c:302)
DBG1 - 09:18:23.262915822 [Main]: Removing /run/lttng/agent.port (in sessiond_cleanup() at main.c:305)
DBG1 - 09:18:23.262934822 [Main]: Removing /run/lttng/kconsumerd/error (in sessiond_cleanup() at main.c:309)
DBG1 - 09:18:23.262963489 [Main]: Removing directory /run/lttng/kconsumerd (in sessiond_cleanup() at main.c:312)
DBG1 - 09:18:23.263003155 [Main]: Removing /run/lttng/ustconsumerd32/error (in sessiond_cleanup() at main.c:316)
DBG1 - 09:18:23.263030822 [Main]: Removing directory /run/lttng/ustconsumerd32 (in sessiond_cleanup() at main.c:319)
DBG1 - 09:18:23.263105822 [Main]: Removing /run/lttng/ustconsumerd64/error (in sessiond_cleanup() at main.c:323)
DBG1 - 09:18:23.263134489 [Main]: Removing directory /run/lttng/ustconsumerd64 (in sessiond_cleanup() at main.c:326)
DBG1 - 09:18:23.263155155 [Main]: Cleaning up all per-event notifier domain agents (in sessiond_cleanup() at main.c:331)
DBG1 - 09:18:23.263264822 [Main]: Cleaning up all agent apps (in sessiond_cleanup() at main.c:334)
DBG1 - 09:18:23.263338155 [Main]: Closing all UST sockets (in sessiond_cleanup() at main.c:336)
DBG3 - 09:18:23.263358489 [Main]: Buffer registry destroy all registry (in buffer_reg_destroy_registries() at buffer-registry.c:743)
DBG3 - 09:18:23.263470155 [HT cleanup]: Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:125)
DBG3 - 09:18:23.263584155 [HT cleanup]: Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)
DBG3 - 09:18:23.263607822 [HT cleanup]: Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:125)
DBG2 - 09:18:23.263632489 [Main]: Closing kernel event notifier group notification file descriptor (in cleanup_kernel_tracer() at kernel.c:2073)
DBG3 - 09:18:23.263698489 [HT cleanup]: Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)
DBG2 - 09:18:23.263711822 [Main]: Closing kernel event notifier group file descriptor (in cleanup_kernel_tracer() at kernel.c:2097)
DBG1 - 09:18:23.263653155 [Notification]: Poll wait returned (3) (in thread_notification() at notification-thread.c:670)
DBG2 - 09:18:23.263732155 [Main]: Closing kernel fd (in cleanup_kernel_tracer() at kernel.c:2109)
DBG1 - 09:18:23.263749822 [Notification]: Handling fd (11) activity (16) (in thread_notification() at notification-thread.c:694)
DBG1 - 09:18:23.263787822 [Notification]: Handling fd (13) activity (16) (in thread_notification() at notification-thread.c:694)
DBG1 - 09:18:23.263801489 [Notification]: Handling fd (17) activity (16) (in thread_notification() at notification-thread.c:694)
DBG1 - 09:18:23.263820155 [Notification]: Entering poll wait (in thread_notification() at notification-thread.c:668)
DBG1 - 09:18:23.273888155 [Main]: Shutting down "Notification" thread (in _lttng_thread_shutdown() at thread.c:153)
DBG1 - 09:18:23.273930489 [Main]: Beginning of waiter wait period (in lttng_waiter_wait() at waiter.c:46)
DBG1 - 09:18:23.273942155 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.c:670)
DBG1 - 09:18:23.273962489 [Notification]: Handling fd (33) activity (1) (in thread_notification() at notification-thread.c:694)
DBG1 - 09:18:23.273979489 [Notification]: Received `QUIT` command (in handle_notification_thread_command() at notification-thread-events.c:3162)
DBG1 - 09:18:23.274008822 [Notification]: Closing all client connections (in handle_notification_thread_client_disconnect_all() at notification-thread-events.c:3495)
DBG1 - 09:18:23.274011822 [Main]: End of waiter wait period (in lttng_waiter_wait() at waiter.c:99)
DBG1 - 09:18:23.274354155 [Notification]: Destroying notification channel socket (in notification_channel_socket_destroy() at notification-thread.c:201)
DBG1 - 09:18:23.274619155 [Notification]: Shutting down "Action Executor" thread (in _lttng_thread_shutdown() at thread.c:153)
DBG1 - 09:18:23.274709155 [Action Executor]: Woke-up from wait (in action_executor_thread() at action-executor.c:773)
DBG1 - 09:18:23.274736489 [Action Executor]: Left work execution loop (in action_executor_thread() at action-executor.c:827)
DBG1 - 09:18:23.274750822 [Action Executor]: Thread entry point has returned (in launch_thread() at thread.c:67)
DBG1 - 09:18:23.274860822 [Notification]: Joined thread "Action Executor" (in _lttng_thread_shutdown() at thread.c:168)
DBG1 - 09:18:23.274910489 [Notification]: Thread entry point has returned (in launch_thread() at thread.c:67)
DBG1 - 09:18:23.275005155 [Main]: Joined thread "Notification" (in _lttng_thread_shutdown() at thread.c:168)
DBG1 - 09:18:23.275224822 [Main]: Unloading kernel modules (in main() at main.c:1999)
Error: Failed to load kmod library resources
DBG1 - 09:18:23.286777489 [Main]: Shutting down "HT cleanup" thread (in _lttng_thread_shutdown() at thread.c:153)
DBG3 - 09:18:23.286853155 [HT cleanup]: Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:125)
DBG1 - 09:18:23.286888822 [HT cleanup]: [ht-cleanup] quit. (in thread_ht_cleanup() at ht-cleanup.c:206)
DBG1 - 09:18:23.286928489 [HT cleanup]: [ht-cleanup] Thread terminates. (in thread_ht_cleanup() at ht-cleanup.c:217)
DBG1 - 09:18:23.286944155 [HT cleanup]: Thread entry point has returned (in launch_thread() at thread.c:67)
DBG1 - 09:18:23.287049822 [Main]: Joined thread "HT cleanup" (in _lttng_thread_shutdown() at thread.c:168)
DBG1 - 09:18:23.287338155 [Main]: Cleaning up options (in sessiond_cleanup_options() at main.c:362)
DBG1 - 09:18:23.287364489 [Main]: Destroying run_as worker (in run_as_destroy_worker_no_lock() at runas.c:1576)
DBG1 - 09:18:23.287406155 [Main]: Closing run_as worker socket (in run_as_destroy_worker_no_lock() at runas.c:1581)
DBG1 - 09:18:23.287581489 [Run-as worker]: run_as worker exiting (ret = 0) (in run_as_create_worker_no_lock() at runas.c:1526)
DBG1 - 09:18:23.288611155 [Main]: lttng-runas terminated with status code 0 (in run_as_destroy_worker_no_lock() at runas.c:1601)
- lttng --version
lttng (LTTng Trace Control) 2.13.8 - Nordicit¨¦ - ldd $(which lttng)
linux-vdso.so.1 (0x0000ffff8c498000)
liblttng-ctl.so.0 => /usr/lib64/liblttng-ctl.so.0 (0x0000ffff8c3c1000)
libxml2.so.2 => /usr/lib64/libxml2.so.2 (0x0000ffff8c283000)
libdl.so.2 => /lib64/libdl.so.2 (0x0000ffff8c26f000)
libz.so.1 => /usr/lib64/libz.so.1 (0x0000ffff8c24b000)
liblzma.so.5 => /usr/lib64/liblzma.so.5 (0x0000ffff8c21a000)
libpthread.so.0 => /lib64/libpthread.so.0 (0x0000ffff8c1e9000)
libm.so.6 => /lib64/libm.so.6 (0x0000ffff8c13f000)
libpopt.so.0 => /usr/lib64/libpopt.so.0 (0x0000ffff8c124000)
librt.so.1 => /lib64/librt.so.1 (0x0000ffff8c10c000)
libc.so.6 => /lib64/libc.so.6 (0x0000ffff8bf9d000)
/lib/ld-linux-aarch64.so.1 (0x0000ffff8c468000) - ldd $(lttng-sessiond)
Warning: No tracing group detected
Error: Failed to load kmod library resources
Warning: No kernel tracer available
---- It will get stuck here----
^CError: Failed to load kmod library resources
And I'm running all of this in the same manchine.
thanks,
Ai Chen
Updated by Ai Chen about 1 month ago
Hi Kienan,
OH, SORRY!The last is wrong, because I forget modprobe lttng-tracer. Please take a look at this one.
- cd /lib/modu
- dmesg | grep -i LTTng
[267529.416227] LTTng: Loaded modules v2.14.0-pre (O-Beer) - v2.13.0-rc1-465-g0e6f8768 - lttng --version
lttng (LTTng Trace Control) 2.13.8 - Nordicit¨¦ - lttng-sessiond -vvv
DBG1 - 09:31:00.856091246 [Main]: [sessiond configuration]
DBG1 - 09:31:00.856232246 [Main]: version 2.13.8
DBG1 - 09:31:00.856260246 [Main]: verbose: 3
DBG1 - 09:31:00.856275246 [Main]: verbose consumer: 0
DBG1 - 09:31:00.856296246 [Main]: quiet mode: False
DBG1 - 09:31:00.856311912 [Main]: agent_tcp_port: [5345, 5354]
DBG1 - 09:31:00.856327579 [Main]: application socket timeout: 5
DBG1 - 09:31:00.856351246 [Main]: no-kernel: False
DBG1 - 09:31:00.856366246 [Main]: background: False
DBG1 - 09:31:00.856408246 [Main]: daemonize: False
DBG1 - 09:31:00.856419579 [Main]: signal parent on start: False
DBG1 - 09:31:00.856429912 [Main]: tracing group name: tracing
DBG1 - 09:31:00.856445912 [Main]: kmod_probe_list: None
DBG1 - 09:31:00.856460912 [Main]: kmod_extra_probe_list: None
DBG1 - 09:31:00.856471246 [Main]: rundir: /run/lttng
DBG1 - 09:31:00.856481246 [Main]: application socket path: /run/lttng/lttng-ust-sock-8
DBG1 - 09:31:00.856491246 [Main]: client socket path: /run/lttng/client-lttng-sessiond
DBG1 - 09:31:00.856501579 [Main]: wait shm path: /lttng-ust-wait-8
DBG1 - 09:31:00.856511246 [Main]: health socket path: /run/lttng/sessiond-health
DBG1 - 09:31:00.856521912 [Main]: LTTNG_UST_CLOCK_PLUGIN: None
DBG1 - 09:31:00.856531912 [Main]: pid file path: /run/lttng/lttng-sessiond.pid
DBG1 - 09:31:00.856541912 [Main]: lock file path: /run/lttng/lttng-sessiond.lck
DBG1 - 09:31:00.856552579 [Main]: session load path: None
DBG1 - 09:31:00.856562912 [Main]: agent port file path: /run/lttng/agent.port
DBG1 - 09:31:00.856572912 [Main]: consumerd32 path: /run/lttng/ustconsumerd32
DBG1 - 09:31:00.856586579 [Main]: consumerd32 bin path: Unknown
DBG1 - 09:31:00.856601579 [Main]: consumerd32 lib dir: Unknown
DBG1 - 09:31:00.856612246 [Main]: consumerd32 err unix sock path:/run/lttng/ustconsumerd32/error
DBG1 - 09:31:00.856622246 [Main]: consumerd32 cmd unix sock path:/run/lttng/ustconsumerd32/command
DBG1 - 09:31:00.856632579 [Main]: consumerd64 path: /run/lttng/ustconsumerd64
DBG1 - 09:31:00.856646579 [Main]: consumerd64 bin path: /usr/lib/lttng/libexec/lttng-consumerd
DBG1 - 09:31:00.856666579 [Main]: consumerd64 lib dir: /usr/lib
DBG1 - 09:31:00.856681579 [Main]: consumerd64 err unix sock path:/run/lttng/ustconsumerd64/error
DBG1 - 09:31:00.856696246 [Main]: consumerd64 cmd unix sock path:/run/lttng/ustconsumerd64/command
DBG1 - 09:31:00.856711246 [Main]: kconsumerd path: /run/lttng/kconsumerd
DBG1 - 09:31:00.856726246 [Main]: kconsumerd err unix sock path: /run/lttng/kconsumerd/error
DBG1 - 09:31:00.856740579 [Main]: kconsumerd cmd unix sock path: /run/lttng/kconsumerd/command
DBG1 - 09:31:00.856762912 [Main]: Starting lttng-sessiond {8a0c8a28-21e6-4ecc-aa10-12393c4333bf} (in sessiond_uuid_log() at main.c:1437)
DBG3 - 09:31:00.856777912 [Main]: Creating LTTng run directory: /run/lttng (in create_lttng_rundir() at main.c:1069)
DBG1 - 09:31:00.857693246 [Main]: Resetting run_as worker signal handlers to default (in reset_sighandler() at runas.c:1377)
DBG1 - 09:31:00.857985579 [Main]: run_as signal handler set for SIGTERM and SIGINT (in set_worker_sighandlers() at runas.c:1438)
DBG1 - 09:31:00.859797579 [Main]: Health check time delta in seconds set to 20 (in health_init() at health.c:62)
DBG1 - 09:31:00.860540246 [HT cleanup]: Entering thread entry point (in launch_thread() at thread.c:65)
DBG1 - 09:31:00.860574579 [HT cleanup]: startup. (in thread_ht_cleanup() at ht-cleanup.c:98)
DBG1 - 09:31:00.860684246 [HT cleanup]: epoll set max size is 585216 (in compat_epoll_set_max_size() at poll.c:350)
DBG3 - 09:31:00.860776246 [Main]: Created hashtable size 16 at 0x3e292370 of type U64 (in lttng_ht_new() at hashtable.c:152)
DBG3 - 09:31:00.860808912 [Main]: Created hashtable size 16 at 0x3e2928c0 of type U64 (in lttng_ht_new() at hashtable.c:152)
DBG3 - 09:31:00.860817912 [HT cleanup]: Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)
DBG3 - 09:31:00.860837579 [Main]: Created hashtable size 16 at 0x3e292f20 of type U64 (in lttng_ht_new() at hashtable.c:152)
DBG3 - 09:31:00.860861579 [Main]: Created hashtable size 4 at 0x3e293440 of type ULONG (in lttng_ht_new() at hashtable.c:152)
DBG3 - 09:31:00.860880912 [Main]: Created hashtable size 4 at 0x3e293880 of type U64 (in lttng_ht_new() at hashtable.c:152)
DBG2 - 09:31:00.860893579 [Main]: Creating consumer directory: /run/lttng/kconsumerd (in set_consumer_sockets() at main.c:1111)
Warning: No tracing group detected
Error: Failed to load kmod library resources
Warning: No kernel tracer available
DBG2 - 09:31:00.862264579 [Main]: Creating consumer directory: /run/lttng/ustconsumerd64 (in set_consumer_sockets() at main.c:1111)
DBG2 - 09:31:00.862421246 [Main]: Creating consumer directory: /run/lttng/ustconsumerd32 (in set_consumer_sockets() at main.c:1111)
DBG3 - 09:31:00.862573246 [Main]: Created hashtable size 4 at 0x3e294830 of type U64 (in lttng_ht_new() at hashtable.c:152)
DBG3 - 09:31:00.862629246 [Main]: Global buffer per UID registry initialized (in buffer_reg_init_uid_registry() at buffer-registry.c:90)
DBG3 - 09:31:00.862650912 [Main]: Created hashtable size 4 at 0x3e295120 of type U64 (in lttng_ht_new() at hashtable.c:152)
DBG3 - 09:31:00.862662579 [Main]: Global buffer per PID registry initialized (in buffer_reg_init_pid_registry() at buffer-registry.c:219)
DBG1 - 09:31:00.862681579 [Main]: Command subsystem initialized (in cmd_init() at cmd.c:6064)
DBG1 - 09:31:00.862727912 [Main]: '10582' written in file /run/lttng/lttng-sessiond.pid (in utils_create_pid_file() at utils.c:257)
DBG1 - 09:31:00.862915579 [Main]: TCP inet operation timeout set to 216 sec (in lttcomm_inet_init() at inet.c:545)
DBG1 - 09:31:00.863039579 [Main]: Waiting for health management thread to be ready (in wait_until_thread_is_ready() at health.c:35)
DBG1 - 09:31:00.863059579 [Health management]: Entering thread entry point (in launch_thread() at thread.c:65)
DBG1 - 09:31:00.863092246 [Health management]: [thread] Manage health check started (in thread_manage_health() at health.c:65)
DBG1 - 09:31:00.863323246 [Health management]: Marking health management thread as ready (in mark_thread_as_ready() at health.c:28)
DBG1 - 09:31:00.863354579 [Health management]: Health check ready (in thread_manage_health() at health.c:136)
DBG1 - 09:31:00.863359912 [Main]: Health management thread is ready (in wait_until_thread_is_ready() at health.c:37)
DBG1 - 09:31:00.863585246 [Main]: Waiting for notification thread to be ready (in wait_until_thread_is_ready() at notification-thread.c:414)
DBG1 - 09:31:00.863607246 [Notification]: Entering thread entry point (in launch_thread() at thread.c:65)
DBG1 - 09:31:00.863631579 [Notification]: Started notification thread (in thread_notification() at notification-thread.c:642)
DBG1 - 09:31:00.863674246 [Notification]: Creating notification channel UNIX socket at /run/lttng/sessiond-notification (in notification_channel_socket_create() at notification-thread.c:223)
DBG1 - 09:31:00.863785579 [Notification]: Notification channel UNIX socket created (fd = 34) (in notification_channel_socket_create() at notification-thread.c:258)
DBG1 - 09:31:00.863823912 [Notification]: Listening on notification channel socket (in init_thread_state() at notification-thread.c:442)
DBG1 - 09:31:00.863916579 [Notification]: Marking notification thread as ready (in mark_thread_as_ready() at notification-thread.c:407)
DBG1 - 09:31:00.863937246 [Notification]: Entering poll wait (in thread_notification() at notification-thread.c:668)
DBG1 - 09:31:00.863939579 [Action Executor]: Entering thread entry point (in launch_thread() at thread.c:65)
DBG1 - 09:31:00.864010246 [Action Executor]: Entering work execution loop (in action_executor_thread() at action-executor.c:761)
DBG1 - 09:31:00.864012912 [Main]: Notification thread is ready (in wait_until_thread_is_ready() at notification-thread.c:416)
DBG1 - 09:31:00.864025579 [Action Executor]: No work items enqueued, entering wait (in action_executor_thread() at action-executor.c:770)
DBG1 - 09:31:00.864114246 [Timer]: Entering thread entry point (in launch_thread() at thread.c:65)
DBG1 - 09:31:00.864220579 [Rotation]: Entering thread entry point (in launch_thread() at thread.c:65)
DBG1 - 09:31:00.864228912 [Main]: Created client socket (fd = 40) (in create_client_sock() at client.c:2428)
DBG1 - 09:31:00.864255579 [Rotation]: Started rotation thread (in thread_rotation() at rotation-thread.c:789)
DBG1 - 09:31:00.864321579 [Main]: Waiting for client thread to be ready (in wait_thread_status() at client.c:65)
DBG1 - 09:31:00.864512912 [Client management]: Entering thread entry point (in launch_thread() at thread.c:65)
DBG1 - 09:31:00.864584579 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.c:670)
DBG1 - 09:31:00.864716912 [Notification]: Handling fd (34) activity (1) (in thread_notification() at notification-thread.c:694)
DBG1 - 09:31:00.864817246 [Notification]: Handling new notification channel client connection (in handle_notification_thread_client_connect() at notification-thread-events.c:3351)
DBG1 - 09:31:00.864868246 [Notification]: Client socket (fd = 43) set as non-blocking (in socket_set_non_blocking() at notification-thread-events.c:3319)
DBG1 - 09:31:00.864900246 [Notification]: Added new notification channel client socket (43) to poll set (in handle_notification_thread_client_connect() at notification-thread-events.c:3404)
DBG1 - 09:31:00.864961579 [Notification]: Entering poll wait (in thread_notification() at notification-thread.c:668)
DBG1 - 09:31:00.864984246 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.c:670)
DBG1 - 09:31:00.864994579 [Notification]: Handling fd (43) activity (1) (in thread_notification() at notification-thread.c:694)
DBG1 - 09:31:00.865019246 [Notification]: Entering poll wait (in thread_notification() at notification-thread.c:668)
DBG1 - 09:31:00.865059912 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.c:670)
DBG1 - 09:31:00.865098912 [Notification]: Handling fd (43) activity (1) (in thread_notification() at notification-thread.c:694)
DBG1 - 09:31:00.865148579 [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:3879)
DBG1 - 09:31:00.865185579 [Notification]: Send command reply (0) (in client_send_command_reply() at notification-thread-events.c:3755)
DBG1 - 09:31:00.865233579 [Notification]: Flushing client (socket fd = 43) outgoing queue (in client_flush_outgoing_queue() at notification-thread-events.c:3644)
DBG1 - 09:31:00.865275912 [Notification]: Entering poll wait (in thread_notification() at notification-thread.c:668)
DBG1 - 09:31:00.864704912 [Client management]: [thread] Manage client started (in thread_manage_clients() at client.c:2461)
DBG1 - 09:31:00.865480246 [Client management]: Marking client thread's state as running (in set_thread_status() at client.c:58)
DBG1 - 09:31:00.865520246 [Client management]: Accepting client command ... (in thread_manage_clients() at client.c:2527)
DBG1 - 09:31:00.865542912 [Main]: Client thread is ready (in wait_thread_status() at client.c:68)
DBG1 - 09:31:00.865636912 [Rotation]: Entering poll wait (in thread_rotation() at rotation-thread.c:813)
DBG1 - 09:31:00.865850579 [Main]: All permissions are set (in set_permissions() at main.c:1057)
DBG1 - 09:31:00.865950912 [UST registration dispatch]: Entering thread entry point (in launch_thread() at thread.c:65)
DBG3 - 09:31:00.866052579 [Main]: Session daemon application socket created (fd = 47) (in create_application_socket() at register.c:71)
DBG1 - 09:31:00.866077912 [UST registration dispatch]: [thread] Dispatch UST command started (in thread_dispatch_ust_registration() at dispatch.c:250)
DBG1 - 09:31:00.866151912 [Main]: Waiting for application registration thread to be ready (in wait_thread_status() at register.c:131)
DBG1 - 09:31:00.866169912 [UST application registration]: Entering thread entry point (in launch_thread() at thread.c:65)
DBG1 - 09:31:00.866403912 [UST application registration]: [thread] Manage application registration started (in thread_application_registration() at register.c:168)
DBG1 - 09:31:00.866458579 [UST application registration]: Marking application registration thread's state as running (in set_thread_status() at register.c:124)
DBG1 - 09:31:00.866482579 [UST application registration]: Accepting application registration (in thread_application_registration() at register.c:207)
DBG1 - 09:31:00.866486912 [Main]: Application registration thread is ready (in wait_thread_status() at register.c:134)
DBG1 - 09:31:00.866504912 [Main]: Notifying applications of session daemon state: 1 (in notify_ust_apps() at register.c:91)
DBG1 - 09:31:00.866635246 [Main]: Wait shared memory file descriptor created successfully: path = '/lttng-ust-wait-8', mmap_size = 4096, global = true, fd = 49 (in get_wait_shm() at shm.c:133)
DBG1 - 09:31:00.866691579 [Main]: Futex wait update active 1 (in futex_wait_update() at futex.c:55)
DBG1 - 09:31:00.866270246 [UST registration dispatch]: Futex n to 1 prepare done (in futex_nto1_prepare() at futex.c:67)
DBG1 - 09:31:00.866811246 [UST application management]: Entering thread entry point (in launch_thread() at thread.c:65)
DBG1 - 09:31:00.866906579 [UST registration dispatch]: Woken up but nothing in the UST command queue (in thread_dispatch_ust_registration() at dispatch.c:279)
DBG1 - 09:31:00.866915579 [UST application management]: [thread] Manage application started (in thread_application_management() at manage-apps.c:52)
DBG1 - 09:31:00.866937579 [Kernel management]: Entering thread entry point (in launch_thread() at thread.c:65)
DBG1 - 09:31:00.867216579 [UST application management]: Apps thread polling (in thread_application_management() at manage-apps.c:88)
DBG1 - 09:31:00.867262912 [Kernel management]: [thread] Thread manage kernel started (in thread_kernel_management() at manage-kernel.c:173)
DBG1 - 09:31:00.867331246 [Kernel management]: Updating kernel poll set (in update_kernel_poll() at manage-kernel.c:37)
DBG1 - 09:31:00.867451579 [Kernel management]: Thread kernel polling (in thread_kernel_management() at manage-kernel.c:227)
^CDBG1 - 09:31:15.469038247 [Main]: SIGINT caught (in sighandler() at main.c:1179)
DBG1 - 09:31:15.469041247 [Run-as worker]: run_as worker received signal SIGINT (in worker_sighandler() at runas.c:1407)
DBG1 - 09:31:15.469152581 [Main]: Terminating all threads (in stop_threads() at main.c:177)
DBG1 - 09:31:15.469262914 [Main]: Shutting down "Client management" thread (in _lttng_thread_shutdown() at thread.c:153)
DBG1 - 09:31:15.469445247 [Client management]: Client thread dying (in thread_manage_clients() at client.c:2722)
DBG1 - 09:31:15.469484247 [Client management]: Thread entry point has returned (in launch_thread() at thread.c:67)
DBG1 - 09:31:15.469592581 [Main]: Joined thread "Client management" (in _lttng_thread_shutdown() at thread.c:168)
DBG1 - 09:31:15.469707914 [Main]: Initiating destruction of all sessions (in destroy_all_sessions_and_wait() at main.c:1321)
DBG1 - 09:31:15.469728914 [Main]: Waiting for the destruction of all sessions to complete (in destroy_all_sessions_and_wait() at main.c:1349)
DBG1 - 09:31:15.469745581 [Main]: Destruction of all sessions completed (in destroy_all_sessions_and_wait() at main.c:1351)
DBG1 - 09:31:15.469756581 [Main]: Unregistering all triggers (in unregister_all_triggers() at main.c:1364)
DBG1 - 09:31:15.469788914 [Main]: Beginning of waiter wait period (in lttng_waiter_wait() at waiter.c:46)
DBG1 - 09:31:15.469832581 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.c:670)
DBG1 - 09:31:15.469859914 [Notification]: Handling fd (33) activity (1) (in thread_notification() at notification-thread.c:694)
DBG1 - 09:31:15.469882914 [Notification]: Received `LIST_TRIGGERS` command (in handle_notification_thread_command() at notification-thread-events.c:3162)
DBG1 - 09:31:15.469922914 [Notification]: Entering poll wait (in thread_notification() at notification-thread.c:668)
DBG1 - 09:31:15.469925247 [Main]: End of waiter wait period (in lttng_waiter_wait() at waiter.c:99)
DBG1 - 09:31:15.469967581 [Main]: Shutting down "UST application registration" thread (in _lttng_thread_shutdown() at thread.c:153)
DBG1 - 09:31:15.470027914 [UST application registration]: Notifying applications of session daemon state: 0 (in notify_ust_apps() at register.c:91)
DBG1 - 09:31:15.470167581 [UST application registration]: Wait shared memory file descriptor created successfully: path = '/lttng-ust-wait-8', mmap_size = 4096, global = true, fd = 38 (in get_wait_shm() at shm.c:133)
DBG1 - 09:31:15.470233581 [UST application registration]: Futex wait update active 0 (in futex_wait_update() at futex.c:55)
DBG1 - 09:31:15.470429914 [UST application registration]: UST Registration thread cleanup complete (in thread_application_registration() at register.c:364)
DBG1 - 09:31:15.470452914 [UST application registration]: Thread entry point has returned (in launch_thread() at thread.c:67)
DBG1 - 09:31:15.470510247 [Main]: Joined thread "UST application registration" (in _lttng_thread_shutdown() at thread.c:168)
DBG1 - 09:31:15.470566247 [Main]: Shutting down "Kernel management" thread (in _lttng_thread_shutdown() at thread.c:153)
DBG1 - 09:31:15.470660247 [Kernel management]: Thread kernel return from poll on 2 fds (in thread_kernel_management() at manage-kernel.c:233)
DBG1 - 09:31:15.470698914 [Kernel management]: Kernel thread dying (in thread_kernel_management() at manage-kernel.c:309)
DBG1 - 09:31:15.470715581 [Kernel management]: Thread entry point has returned (in launch_thread() at thread.c:67)
DBG1 - 09:31:15.470766914 [Main]: Joined thread "Kernel management" (in _lttng_thread_shutdown() at thread.c:168)
DBG1 - 09:31:15.470786914 [Main]: Shutting down "UST application management" thread (in _lttng_thread_shutdown() at thread.c:153)
DBG1 - 09:31:15.470830581 [UST application management]: Apps thread return from poll on 2 fds (in thread_application_management() at manage-apps.c:94)
DBG1 - 09:31:15.470865581 [UST application management]: Application communication apps thread cleanup complete (in thread_application_management() at manage-apps.c:194)
DBG1 - 09:31:15.470905247 [UST application management]: Thread entry point has returned (in launch_thread() at thread.c:67)
DBG1 - 09:31:15.471023247 [Main]: Joined thread "UST application management" (in _lttng_thread_shutdown() at thread.c:168)
DBG1 - 09:31:15.471061914 [Main]: Shutting down "UST registration dispatch" thread (in _lttng_thread_shutdown() at thread.c:153)
DBG1 - 09:31:15.471083914 [Main]: Futex n to 1 wake done (in futex_nto1_wake() at futex.c:121)
DBG1 - 09:31:15.471095581 [UST registration dispatch]: Futex n to 1 wait done (in futex_nto1_wait() at futex.c:104)
DBG1 - 09:31:15.471124247 [UST registration dispatch]: Futex n to 1 prepare done (in futex_nto1_prepare() at futex.c:67)
DBG1 - 09:31:15.471143247 [UST registration dispatch]: Dispatch thread dying (in thread_dispatch_ust_registration() at dispatch.c:486)
DBG1 - 09:31:15.471159914 [UST registration dispatch]: Thread entry point has returned (in launch_thread() at thread.c:67)
DBG1 - 09:31:15.471276914 [Main]: Joined thread "UST registration dispatch" (in _lttng_thread_shutdown() at thread.c:168)
DBG1 - 09:31:15.471299581 [Main]: Shutting down "Rotation" thread (in _lttng_thread_shutdown() at thread.c:153)
DBG1 - 09:31:15.471340581 [Rotation]: Poll wait returned (1) (in thread_rotation() at rotation-thread.c:815)
DBG1 - 09:31:15.471365581 [Rotation]: Handling fd (36) activity (1) (in thread_rotation() at rotation-thread.c:833)
DBG1 - 09:31:15.471476247 [Rotation]: Quit pipe activity (in thread_rotation() at rotation-thread.c:873)
DBG1 - 09:31:15.471492247 [Rotation]: Thread exit (in thread_rotation() at rotation-thread.c:881)
DBG1 - 09:31:15.471580247 [Rotation]: Thread entry point has returned (in launch_thread() at thread.c:67)
DBG1 - 09:31:15.471647247 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.c:670)
DBG1 - 09:31:15.471667581 [Notification]: Handling fd (43) activity (8209) (in thread_notification() at notification-thread.c:694)
DBG1 - 09:31:15.471680581 [Notification]: Closing client connection (socket fd = 43) (in handle_notification_thread_client_disconnect() at notification-thread-events.c:3470)
DBG1 - 09:31:15.471717247 [Main]: Joined thread "Rotation" (in _lttng_thread_shutdown() at thread.c:168)
DBG1 - 09:31:15.471734914 [Main]: Shutting down "Timer" thread (in _lttng_thread_shutdown() at thread.c:153)
DBG1 - 09:31:15.471793914 [Timer]: Thread exit (in thread_timer() at timer.c:402)
DBG1 - 09:31:15.471820247 [Timer]: Thread entry point has returned (in launch_thread() at thread.c:67)
DBG1 - 09:31:15.471851247 [Notification]: Entering poll wait (in thread_notification() at notification-thread.c:668)
DBG1 - 09:31:15.471999581 [Main]: Joined thread "Timer" (in _lttng_thread_shutdown() at thread.c:168)
DBG1 - 09:31:15.472016581 [Main]: Shutting down "Health management" thread (in _lttng_thread_shutdown() at thread.c:153)
DBG1 - 09:31:15.472056581 [Health management]: Health check thread dying (in thread_manage_health() at health.c:231)
DBG1 - 09:31:15.472154247 [Health management]: Thread entry point has returned (in launch_thread() at thread.c:67)
DBG1 - 09:31:15.472229247 [Main]: Joined thread "Health management" (in _lttng_thread_shutdown() at thread.c:168)
DBG1 - 09:31:15.482411914 [Main]: Cleanup sessiond (in sessiond_cleanup() at main.c:282)
DBG1 - 09:31:15.482594247 [Main]: Removing sessiond and consumerd content of directory /run/lttng (in sessiond_cleanup() at main.c:298)
DBG1 - 09:31:15.482644914 [Main]: Removing /run/lttng/lttng-sessiond.pid (in sessiond_cleanup() at main.c:302)
DBG1 - 09:31:15.482676914 [Main]: Removing /run/lttng/agent.port (in sessiond_cleanup() at main.c:305)
DBG1 - 09:31:15.482703247 [Main]: Removing /run/lttng/kconsumerd/error (in sessiond_cleanup() at main.c:309)
DBG1 - 09:31:15.482738247 [Main]: Removing directory /run/lttng/kconsumerd (in sessiond_cleanup() at main.c:312)
DBG1 - 09:31:15.482775581 [Main]: Removing /run/lttng/ustconsumerd32/error (in sessiond_cleanup() at main.c:316)
DBG1 - 09:31:15.482803581 [Main]: Removing directory /run/lttng/ustconsumerd32 (in sessiond_cleanup() at main.c:319)
DBG1 - 09:31:15.482828247 [Main]: Removing /run/lttng/ustconsumerd64/error (in sessiond_cleanup() at main.c:323)
DBG1 - 09:31:15.482850914 [Main]: Removing directory /run/lttng/ustconsumerd64 (in sessiond_cleanup() at main.c:326)
DBG1 - 09:31:15.482875247 [Main]: Cleaning up all per-event notifier domain agents (in sessiond_cleanup() at main.c:331)
DBG1 - 09:31:15.482977914 [Main]: Cleaning up all agent apps (in sessiond_cleanup() at main.c:334)
DBG1 - 09:31:15.483026581 [Main]: Closing all UST sockets (in sessiond_cleanup() at main.c:336)
DBG3 - 09:31:15.483044247 [Main]: Buffer registry destroy all registry (in buffer_reg_destroy_registries() at buffer-registry.c:743)
DBG3 - 09:31:15.483095581 [HT cleanup]: Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:125)
DBG3 - 09:31:15.483155914 [HT cleanup]: Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)
DBG3 - 09:31:15.483174581 [HT cleanup]: Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:125)
DBG1 - 09:31:15.483230247 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.c:670)
DBG2 - 09:31:15.483236581 [Main]: Closing kernel event notifier group notification file descriptor (in cleanup_kernel_tracer() at kernel.c:2073)
DBG1 - 09:31:15.483247247 [Notification]: Handling fd (11) activity (16) (in thread_notification() at notification-thread.c:694)
DBG2 - 09:31:15.483258247 [Main]: Closing kernel event notifier group file descriptor (in cleanup_kernel_tracer() at kernel.c:2097)
DBG2 - 09:31:15.483273247 [Main]: Closing kernel fd (in cleanup_kernel_tracer() at kernel.c:2109)
DBG1 - 09:31:15.483281581 [Notification]: Entering poll wait (in thread_notification() at notification-thread.c:668)
DBG1 - 09:31:15.483296247 [Notification]: Poll wait returned (2) (in thread_notification() at notification-thread.c:670)
DBG1 - 09:31:15.483306247 [Notification]: Handling fd (13) activity (16) (in thread_notification() at notification-thread.c:694)
DBG1 - 09:31:15.483328247 [Notification]: Handling fd (17) activity (16) (in thread_notification() at notification-thread.c:694)
DBG1 - 09:31:15.483345914 [Notification]: Entering poll wait (in thread_notification() at notification-thread.c:668)
DBG3 - 09:31:15.483574247 [HT cleanup]: Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)
DBG1 - 09:31:15.493426914 [Main]: Shutting down "Notification" thread (in _lttng_thread_shutdown() at thread.c:153)
DBG1 - 09:31:15.493477581 [Main]: Beginning of waiter wait period (in lttng_waiter_wait() at waiter.c:46)
DBG1 - 09:31:15.493488914 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.c:670)
DBG1 - 09:31:15.493522581 [Notification]: Handling fd (33) activity (1) (in thread_notification() at notification-thread.c:694)
DBG1 - 09:31:15.493545247 [Notification]: Received `QUIT` command (in handle_notification_thread_command() at notification-thread-events.c:3162)
DBG1 - 09:31:15.493570247 [Notification]: Closing all client connections (in handle_notification_thread_client_disconnect_all() at notification-thread-events.c:3495)
DBG1 - 09:31:15.493571581 [Main]: End of waiter wait period (in lttng_waiter_wait() at waiter.c:99)
DBG1 - 09:31:15.493979247 [Notification]: Destroying notification channel socket (in notification_channel_socket_destroy() at notification-thread.c:201)
DBG1 - 09:31:15.494081581 [Notification]: Shutting down "Action Executor" thread (in _lttng_thread_shutdown() at thread.c:153)
DBG1 - 09:31:15.494136247 [Action Executor]: Woke-up from wait (in action_executor_thread() at action-executor.c:773)
DBG1 - 09:31:15.494177581 [Action Executor]: Left work execution loop (in action_executor_thread() at action-executor.c:827)
DBG1 - 09:31:15.494200247 [Action Executor]: Thread entry point has returned (in launch_thread() at thread.c:67)
DBG1 - 09:31:15.494360581 [Notification]: Joined thread "Action Executor" (in _lttng_thread_shutdown() at thread.c:168)
DBG1 - 09:31:15.494612247 [Notification]: Thread entry point has returned (in launch_thread() at thread.c:67)
DBG1 - 09:31:15.494711914 [Main]: Joined thread "Notification" (in _lttng_thread_shutdown() at thread.c:168)
DBG1 - 09:31:15.494920247 [Main]: Unloading kernel modules (in main() at main.c:1999)
Error: Failed to load kmod library resources
DBG1 - 09:31:15.506462247 [Main]: Shutting down "HT cleanup" thread (in _lttng_thread_shutdown() at thread.c:153)
DBG3 - 09:31:15.506661247 [HT cleanup]: Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:125)
DBG1 - 09:31:15.506692581 [HT cleanup]: [ht-cleanup] quit. (in thread_ht_cleanup() at ht-cleanup.c:206)
DBG1 - 09:31:15.506726581 [HT cleanup]: [ht-cleanup] Thread terminates. (in thread_ht_cleanup() at ht-cleanup.c:217)
DBG1 - 09:31:15.506740914 [HT cleanup]: Thread entry point has returned (in launch_thread() at thread.c:67)
DBG1 - 09:31:15.506847914 [Main]: Joined thread "HT cleanup" (in _lttng_thread_shutdown() at thread.c:168)
DBG1 - 09:31:15.507092914 [Main]: Cleaning up options (in sessiond_cleanup_options() at main.c:362)
DBG1 - 09:31:15.507118247 [Main]: Destroying run_as worker (in run_as_destroy_worker_no_lock() at runas.c:1576)
DBG1 - 09:31:15.507135247 [Main]: Closing run_as worker socket (in run_as_destroy_worker_no_lock() at runas.c:1581)
DBG1 - 09:31:15.507259247 [Run-as worker]: run_as worker exiting (ret = 0) (in run_as_create_worker_no_lock() at runas.c:1526)
DBG1 - 09:31:15.508243914 [Main]: lttng-runas terminated with status code 0 (in run_as_destroy_worker_no_lock() at runas.c:1601)
Updated by Ai Chen about 1 month ago
Ai Chen wrote in #note-5:
Hi Kienan,
OH, SORRY!
The last is wrong, because I forget modprobe lttng-tracer. Please take a look at this one.
- cd /lib/modules/4.14.61-rt/
- modprobe lttng-tracer
- lsmod
Module Size Used by Tainted: G
lttng_tracer 2895872 0
lttng_statedump 32768 1 lttng_tracer
lttng_wrapper 16384 2 lttng_tracer,lttng_statedump
lttng_clock 16384 1 lttng_tracer
lttng_lib_ring_buffer 69632 1 lttng_tracer
xrp_hw_semidrive 16384 0
lm75 20480 0
sr9900 49152 0
ecdh_generic 24576 0
crypto_engine 16384 0
pvrsrvkm 1454080 0
yt6801 143360 0
dtbocfg 16384 0
lt8912 16384 0
- dmesg | grep -i LTTng
[267529.416227] LTTng: Loaded modules v2.14.0-pre (O-Beer) - v2.13.0-rc1-465-g0e6f8768- lttng --version
lttng (LTTng Trace Control) 2.13.8 - Nordicit¨¦- lttng-sessiond -vvv
DBG1 - 09:31:00.856091246 [Main]: [sessiond configuration]
DBG1 - 09:31:00.856232246 [Main]: version 2.13.8
DBG1 - 09:31:00.856260246 [Main]: verbose: 3
DBG1 - 09:31:00.856275246 [Main]: verbose consumer: 0
DBG1 - 09:31:00.856296246 [Main]: quiet mode: False
DBG1 - 09:31:00.856311912 [Main]: agent_tcp_port: [5345, 5354]
DBG1 - 09:31:00.856327579 [Main]: application socket timeout: 5
DBG1 - 09:31:00.856351246 [Main]: no-kernel: False
DBG1 - 09:31:00.856366246 [Main]: background: False
DBG1 - 09:31:00.856408246 [Main]: daemonize: False
DBG1 - 09:31:00.856419579 [Main]: signal parent on start: False
DBG1 - 09:31:00.856429912 [Main]: tracing group name: tracing
DBG1 - 09:31:00.856445912 [Main]: kmod_probe_list: None
DBG1 - 09:31:00.856460912 [Main]: kmod_extra_probe_list: None
DBG1 - 09:31:00.856471246 [Main]: rundir: /run/lttng
DBG1 - 09:31:00.856481246 [Main]: application socket path: /run/lttng/lttng-ust-sock-8
DBG1 - 09:31:00.856491246 [Main]: client socket path: /run/lttng/client-lttng-sessiond
DBG1 - 09:31:00.856501579 [Main]: wait shm path: /lttng-ust-wait-8
DBG1 - 09:31:00.856511246 [Main]: health socket path: /run/lttng/sessiond-health
DBG1 - 09:31:00.856521912 [Main]: LTTNG_UST_CLOCK_PLUGIN: None
DBG1 - 09:31:00.856531912 [Main]: pid file path: /run/lttng/lttng-sessiond.pid
DBG1 - 09:31:00.856541912 [Main]: lock file path: /run/lttng/lttng-sessiond.lck
DBG1 - 09:31:00.856552579 [Main]: session load path: None
DBG1 - 09:31:00.856562912 [Main]: agent port file path: /run/lttng/agent.port
DBG1 - 09:31:00.856572912 [Main]: consumerd32 path: /run/lttng/ustconsumerd32
DBG1 - 09:31:00.856586579 [Main]: consumerd32 bin path: Unknown
DBG1 - 09:31:00.856601579 [Main]: consumerd32 lib dir: Unknown
DBG1 - 09:31:00.856612246 [Main]: consumerd32 err unix sock path:/run/lttng/ustconsumerd32/error
DBG1 - 09:31:00.856622246 [Main]: consumerd32 cmd unix sock path:/run/lttng/ustconsumerd32/command
DBG1 - 09:31:00.856632579 [Main]: consumerd64 path: /run/lttng/ustconsumerd64
DBG1 - 09:31:00.856646579 [Main]: consumerd64 bin path: /usr/lib/lttng/libexec/lttng-consumerd
DBG1 - 09:31:00.856666579 [Main]: consumerd64 lib dir: /usr/lib
DBG1 - 09:31:00.856681579 [Main]: consumerd64 err unix sock path:/run/lttng/ustconsumerd64/error
DBG1 - 09:31:00.856696246 [Main]: consumerd64 cmd unix sock path:/run/lttng/ustconsumerd64/command
DBG1 - 09:31:00.856711246 [Main]: kconsumerd path: /run/lttng/kconsumerd
DBG1 - 09:31:00.856726246 [Main]: kconsumerd err unix sock path: /run/lttng/kconsumerd/error
DBG1 - 09:31:00.856740579 [Main]: kconsumerd cmd unix sock path: /run/lttng/kconsumerd/command
DBG1 - 09:31:00.856762912 [Main]: Starting lttng-sessiond {8a0c8a28-21e6-4ecc-aa10-12393c4333bf} (in sessiond_uuid_log() at main.c:1437)
DBG3 - 09:31:00.856777912 [Main]: Creating LTTng run directory: /run/lttng (in create_lttng_rundir() at main.c:1069)
DBG1 - 09:31:00.857693246 [Main]: Resetting run_as worker signal handlers to default (in reset_sighandler() at runas.c:1377)
DBG1 - 09:31:00.857985579 [Main]: run_as signal handler set for SIGTERM and SIGINT (in set_worker_sighandlers() at runas.c:1438)
DBG1 - 09:31:00.859797579 [Main]: Health check time delta in seconds set to 20 (in health_init() at health.c:62)
DBG1 - 09:31:00.860540246 [HT cleanup]: Entering thread entry point (in launch_thread() at thread.c:65)
DBG1 - 09:31:00.860574579 [HT cleanup]: startup. (in thread_ht_cleanup() at ht-cleanup.c:98)
DBG1 - 09:31:00.860684246 [HT cleanup]: epoll set max size is 585216 (in compat_epoll_set_max_size() at poll.c:350)
DBG3 - 09:31:00.860776246 [Main]: Created hashtable size 16 at 0x3e292370 of type U64 (in lttng_ht_new() at hashtable.c:152)
DBG3 - 09:31:00.860808912 [Main]: Created hashtable size 16 at 0x3e2928c0 of type U64 (in lttng_ht_new() at hashtable.c:152)
DBG3 - 09:31:00.860817912 [HT cleanup]: Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)
DBG3 - 09:31:00.860837579 [Main]: Created hashtable size 16 at 0x3e292f20 of type U64 (in lttng_ht_new() at hashtable.c:152)
DBG3 - 09:31:00.860861579 [Main]: Created hashtable size 4 at 0x3e293440 of type ULONG (in lttng_ht_new() at hashtable.c:152)
DBG3 - 09:31:00.860880912 [Main]: Created hashtable size 4 at 0x3e293880 of type U64 (in lttng_ht_new() at hashtable.c:152)
DBG2 - 09:31:00.860893579 [Main]: Creating consumer directory: /run/lttng/kconsumerd (in set_consumer_sockets() at main.c:1111)
Warning: No tracing group detected
Error: Failed to load kmod library resources
Warning: No kernel tracer available
DBG2 - 09:31:00.862264579 [Main]: Creating consumer directory: /run/lttng/ustconsumerd64 (in set_consumer_sockets() at main.c:1111)
DBG2 - 09:31:00.862421246 [Main]: Creating consumer directory: /run/lttng/ustconsumerd32 (in set_consumer_sockets() at main.c:1111)
DBG3 - 09:31:00.862573246 [Main]: Created hashtable size 4 at 0x3e294830 of type U64 (in lttng_ht_new() at hashtable.c:152)
DBG3 - 09:31:00.862629246 [Main]: Global buffer per UID registry initialized (in buffer_reg_init_uid_registry() at buffer-registry.c:90)
DBG3 - 09:31:00.862650912 [Main]: Created hashtable size 4 at 0x3e295120 of type U64 (in lttng_ht_new() at hashtable.c:152)
DBG3 - 09:31:00.862662579 [Main]: Global buffer per PID registry initialized (in buffer_reg_init_pid_registry() at buffer-registry.c:219)
DBG1 - 09:31:00.862681579 [Main]: Command subsystem initialized (in cmd_init() at cmd.c:6064)
DBG1 - 09:31:00.862727912 [Main]: '10582' written in file /run/lttng/lttng-sessiond.pid (in utils_create_pid_file() at utils.c:257)
DBG1 - 09:31:00.862915579 [Main]: TCP inet operation timeout set to 216 sec (in lttcomm_inet_init() at inet.c:545)
DBG1 - 09:31:00.863039579 [Main]: Waiting for health management thread to be ready (in wait_until_thread_is_ready() at health.c:35)
DBG1 - 09:31:00.863059579 [Health management]: Entering thread entry point (in launch_thread() at thread.c:65)
DBG1 - 09:31:00.863092246 [Health management]: [thread] Manage health check started (in thread_manage_health() at health.c:65)
DBG1 - 09:31:00.863323246 [Health management]: Marking health management thread as ready (in mark_thread_as_ready() at health.c:28)
DBG1 - 09:31:00.863354579 [Health management]: Health check ready (in thread_manage_health() at health.c:136)
DBG1 - 09:31:00.863359912 [Main]: Health management thread is ready (in wait_until_thread_is_ready() at health.c:37)
DBG1 - 09:31:00.863585246 [Main]: Waiting for notification thread to be ready (in wait_until_thread_is_ready() at notification-thread.c:414)
DBG1 - 09:31:00.863607246 [Notification]: Entering thread entry point (in launch_thread() at thread.c:65)
DBG1 - 09:31:00.863631579 [Notification]: Started notification thread (in thread_notification() at notification-thread.c:642)
DBG1 - 09:31:00.863674246 [Notification]: Creating notification channel UNIX socket at /run/lttng/sessiond-notification (in notification_channel_socket_create() at notification-thread.c:223)
DBG1 - 09:31:00.863785579 [Notification]: Notification channel UNIX socket created (fd = 34) (in notification_channel_socket_create() at notification-thread.c:258)
DBG1 - 09:31:00.863823912 [Notification]: Listening on notification channel socket (in init_thread_state() at notification-thread.c:442)
DBG1 - 09:31:00.863916579 [Notification]: Marking notification thread as ready (in mark_thread_as_ready() at notification-thread.c:407)
DBG1 - 09:31:00.863937246 [Notification]: Entering poll wait (in thread_notification() at notification-thread.c:668)
DBG1 - 09:31:00.863939579 [Action Executor]: Entering thread entry point (in launch_thread() at thread.c:65)
DBG1 - 09:31:00.864010246 [Action Executor]: Entering work execution loop (in action_executor_thread() at action-executor.c:761)
DBG1 - 09:31:00.864012912 [Main]: Notification thread is ready (in wait_until_thread_is_ready() at notification-thread.c:416)
DBG1 - 09:31:00.864025579 [Action Executor]: No work items enqueued, entering wait (in action_executor_thread() at action-executor.c:770)
DBG1 - 09:31:00.864114246 [Timer]: Entering thread entry point (in launch_thread() at thread.c:65)
DBG1 - 09:31:00.864220579 [Rotation]: Entering thread entry point (in launch_thread() at thread.c:65)
DBG1 - 09:31:00.864228912 [Main]: Created client socket (fd = 40) (in create_client_sock() at client.c:2428)
DBG1 - 09:31:00.864255579 [Rotation]: Started rotation thread (in thread_rotation() at rotation-thread.c:789)
DBG1 - 09:31:00.864321579 [Main]: Waiting for client thread to be ready (in wait_thread_status() at client.c:65)
DBG1 - 09:31:00.864512912 [Client management]: Entering thread entry point (in launch_thread() at thread.c:65)
DBG1 - 09:31:00.864584579 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.c:670)
DBG1 - 09:31:00.864716912 [Notification]: Handling fd (34) activity (1) (in thread_notification() at notification-thread.c:694)
DBG1 - 09:31:00.864817246 [Notification]: Handling new notification channel client connection (in handle_notification_thread_client_connect() at notification-thread-events.c:3351)
DBG1 - 09:31:00.864868246 [Notification]: Client socket (fd = 43) set as non-blocking (in socket_set_non_blocking() at notification-thread-events.c:3319)
DBG1 - 09:31:00.864900246 [Notification]: Added new notification channel client socket (43) to poll set (in handle_notification_thread_client_connect() at notification-thread-events.c:3404)
DBG1 - 09:31:00.864961579 [Notification]: Entering poll wait (in thread_notification() at notification-thread.c:668)
DBG1 - 09:31:00.864984246 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.c:670)
DBG1 - 09:31:00.864994579 [Notification]: Handling fd (43) activity (1) (in thread_notification() at notification-thread.c:694)
DBG1 - 09:31:00.865019246 [Notification]: Entering poll wait (in thread_notification() at notification-thread.c:668)
DBG1 - 09:31:00.865059912 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.c:670)
DBG1 - 09:31:00.865098912 [Notification]: Handling fd (43) activity (1) (in thread_notification() at notification-thread.c:694)
DBG1 - 09:31:00.865148579 [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:3879)
DBG1 - 09:31:00.865185579 [Notification]: Send command reply (0) (in client_send_command_reply() at notification-thread-events.c:3755)
DBG1 - 09:31:00.865233579 [Notification]: Flushing client (socket fd = 43) outgoing queue (in client_flush_outgoing_queue() at notification-thread-events.c:3644)
DBG1 - 09:31:00.865275912 [Notification]: Entering poll wait (in thread_notification() at notification-thread.c:668)
DBG1 - 09:31:00.864704912 [Client management]: [thread] Manage client started (in thread_manage_clients() at client.c:2461)
DBG1 - 09:31:00.865480246 [Client management]: Marking client thread's state as running (in set_thread_status() at client.c:58)
DBG1 - 09:31:00.865520246 [Client management]: Accepting client command ... (in thread_manage_clients() at client.c:2527)
DBG1 - 09:31:00.865542912 [Main]: Client thread is ready (in wait_thread_status() at client.c:68)
DBG1 - 09:31:00.865636912 [Rotation]: Entering poll wait (in thread_rotation() at rotation-thread.c:813)
DBG1 - 09:31:00.865850579 [Main]: All permissions are set (in set_permissions() at main.c:1057)
DBG1 - 09:31:00.865950912 [UST registration dispatch]: Entering thread entry point (in launch_thread() at thread.c:65)
DBG3 - 09:31:00.866052579 [Main]: Session daemon application socket created (fd = 47) (in create_application_socket() at register.c:71)
DBG1 - 09:31:00.866077912 [UST registration dispatch]: [thread] Dispatch UST command started (in thread_dispatch_ust_registration() at dispatch.c:250)
DBG1 - 09:31:00.866151912 [Main]: Waiting for application registration thread to be ready (in wait_thread_status() at register.c:131)
DBG1 - 09:31:00.866169912 [UST application registration]: Entering thread entry point (in launch_thread() at thread.c:65)
DBG1 - 09:31:00.866403912 [UST application registration]: [thread] Manage application registration started (in thread_application_registration() at register.c:168)
DBG1 - 09:31:00.866458579 [UST application registration]: Marking application registration thread's state as running (in set_thread_status() at register.c:124)
DBG1 - 09:31:00.866482579 [UST application registration]: Accepting application registration (in thread_application_registration() at register.c:207)
DBG1 - 09:31:00.866486912 [Main]: Application registration thread is ready (in wait_thread_status() at register.c:134)
DBG1 - 09:31:00.866504912 [Main]: Notifying applications of session daemon state: 1 (in notify_ust_apps() at register.c:91)
DBG1 - 09:31:00.866635246 [Main]: Wait shared memory file descriptor created successfully: path = '/lttng-ust-wait-8', mmap_size = 4096, global = true, fd = 49 (in get_wait_shm() at shm.c:133)
DBG1 - 09:31:00.866691579 [Main]: Futex wait update active 1 (in futex_wait_update() at futex.c:55)
DBG1 - 09:31:00.866270246 [UST registration dispatch]: Futex n to 1 prepare done (in futex_nto1_prepare() at futex.c:67)
DBG1 - 09:31:00.866811246 [UST application management]: Entering thread entry point (in launch_thread() at thread.c:65)
DBG1 - 09:31:00.866906579 [UST registration dispatch]: Woken up but nothing in the UST command queue (in thread_dispatch_ust_registration() at dispatch.c:279)
DBG1 - 09:31:00.866915579 [UST application management]: [thread] Manage application started (in thread_application_management() at manage-apps.c:52)
DBG1 - 09:31:00.866937579 [Kernel management]: Entering thread entry point (in launch_thread() at thread.c:65)
DBG1 - 09:31:00.867216579 [UST application management]: Apps thread polling (in thread_application_management() at manage-apps.c:88)
DBG1 - 09:31:00.867262912 [Kernel management]: [thread] Thread manage kernel started (in thread_kernel_management() at manage-kernel.c:173)
DBG1 - 09:31:00.867331246 [Kernel management]: Updating kernel poll set (in update_kernel_poll() at manage-kernel.c:37)
DBG1 - 09:31:00.867451579 [Kernel management]: Thread kernel polling (in thread_kernel_management() at manage-kernel.c:227)
---- ---- It will get stuck here---- ----
^CDBG1 - 09:31:15.469038247 [Main]: SIGINT caught (in sighandler() at main.c:1179)
DBG1 - 09:31:15.469041247 [Run-as worker]: run_as worker received signal SIGINT (in worker_sighandler() at runas.c:1407)
DBG1 - 09:31:15.469152581 [Main]: Terminating all threads (in stop_threads() at main.c:177)
DBG1 - 09:31:15.469262914 [Main]: Shutting down "Client management" thread (in _lttng_thread_shutdown() at thread.c:153)
DBG1 - 09:31:15.469445247 [Client management]: Client thread dying (in thread_manage_clients() at client.c:2722)
DBG1 - 09:31:15.469484247 [Client management]: Thread entry point has returned (in launch_thread() at thread.c:67)
DBG1 - 09:31:15.469592581 [Main]: Joined thread "Client management" (in _lttng_thread_shutdown() at thread.c:168)
DBG1 - 09:31:15.469707914 [Main]: Initiating destruction of all sessions (in destroy_all_sessions_and_wait() at main.c:1321)
DBG1 - 09:31:15.469728914 [Main]: Waiting for the destruction of all sessions to complete (in destroy_all_sessions_and_wait() at main.c:1349)
DBG1 - 09:31:15.469745581 [Main]: Destruction of all sessions completed (in destroy_all_sessions_and_wait() at main.c:1351)
DBG1 - 09:31:15.469756581 [Main]: Unregistering all triggers (in unregister_all_triggers() at main.c:1364)
DBG1 - 09:31:15.469788914 [Main]: Beginning of waiter wait period (in lttng_waiter_wait() at waiter.c:46)
DBG1 - 09:31:15.469832581 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.c:670)
DBG1 - 09:31:15.469859914 [Notification]: Handling fd (33) activity (1) (in thread_notification() at notification-thread.c:694)
DBG1 - 09:31:15.469882914 [Notification]: Received `LIST_TRIGGERS` command (in handle_notification_thread_command() at notification-thread-events.c:3162)
DBG1 - 09:31:15.469922914 [Notification]: Entering poll wait (in thread_notification() at notification-thread.c:668)
DBG1 - 09:31:15.469925247 [Main]: End of waiter wait period (in lttng_waiter_wait() at waiter.c:99)
DBG1 - 09:31:15.469967581 [Main]: Shutting down "UST application registration" thread (in _lttng_thread_shutdown() at thread.c:153)
DBG1 - 09:31:15.470027914 [UST application registration]: Notifying applications of session daemon state: 0 (in notify_ust_apps() at register.c:91)
DBG1 - 09:31:15.470167581 [UST application registration]: Wait shared memory file descriptor created successfully: path = '/lttng-ust-wait-8', mmap_size = 4096, global = true, fd = 38 (in get_wait_shm() at shm.c:133)
DBG1 - 09:31:15.470233581 [UST application registration]: Futex wait update active 0 (in futex_wait_update() at futex.c:55)
DBG1 - 09:31:15.470429914 [UST application registration]: UST Registration thread cleanup complete (in thread_application_registration() at register.c:364)
DBG1 - 09:31:15.470452914 [UST application registration]: Thread entry point has returned (in launch_thread() at thread.c:67)
DBG1 - 09:31:15.470510247 [Main]: Joined thread "UST application registration" (in _lttng_thread_shutdown() at thread.c:168)
DBG1 - 09:31:15.470566247 [Main]: Shutting down "Kernel management" thread (in _lttng_thread_shutdown() at thread.c:153)
DBG1 - 09:31:15.470660247 [Kernel management]: Thread kernel return from poll on 2 fds (in thread_kernel_management() at manage-kernel.c:233)
DBG1 - 09:31:15.470698914 [Kernel management]: Kernel thread dying (in thread_kernel_management() at manage-kernel.c:309)
DBG1 - 09:31:15.470715581 [Kernel management]: Thread entry point has returned (in launch_thread() at thread.c:67)
DBG1 - 09:31:15.470766914 [Main]: Joined thread "Kernel management" (in _lttng_thread_shutdown() at thread.c:168)
DBG1 - 09:31:15.470786914 [Main]: Shutting down "UST application management" thread (in _lttng_thread_shutdown() at thread.c:153)
DBG1 - 09:31:15.470830581 [UST application management]: Apps thread return from poll on 2 fds (in thread_application_management() at manage-apps.c:94)
DBG1 - 09:31:15.470865581 [UST application management]: Application communication apps thread cleanup complete (in thread_application_management() at manage-apps.c:194)
DBG1 - 09:31:15.470905247 [UST application management]: Thread entry point has returned (in launch_thread() at thread.c:67)
DBG1 - 09:31:15.471023247 [Main]: Joined thread "UST application management" (in _lttng_thread_shutdown() at thread.c:168)
DBG1 - 09:31:15.471061914 [Main]: Shutting down "UST registration dispatch" thread (in _lttng_thread_shutdown() at thread.c:153)
DBG1 - 09:31:15.471083914 [Main]: Futex n to 1 wake done (in futex_nto1_wake() at futex.c:121)
DBG1 - 09:31:15.471095581 [UST registration dispatch]: Futex n to 1 wait done (in futex_nto1_wait() at futex.c:104)
DBG1 - 09:31:15.471124247 [UST registration dispatch]: Futex n to 1 prepare done (in futex_nto1_prepare() at futex.c:67)
DBG1 - 09:31:15.471143247 [UST registration dispatch]: Dispatch thread dying (in thread_dispatch_ust_registration() at dispatch.c:486)
DBG1 - 09:31:15.471159914 [UST registration dispatch]: Thread entry point has returned (in launch_thread() at thread.c:67)
DBG1 - 09:31:15.471276914 [Main]: Joined thread "UST registration dispatch" (in _lttng_thread_shutdown() at thread.c:168)
DBG1 - 09:31:15.471299581 [Main]: Shutting down "Rotation" thread (in _lttng_thread_shutdown() at thread.c:153)
DBG1 - 09:31:15.471340581 [Rotation]: Poll wait returned (1) (in thread_rotation() at rotation-thread.c:815)
DBG1 - 09:31:15.471365581 [Rotation]: Handling fd (36) activity (1) (in thread_rotation() at rotation-thread.c:833)
DBG1 - 09:31:15.471476247 [Rotation]: Quit pipe activity (in thread_rotation() at rotation-thread.c:873)
DBG1 - 09:31:15.471492247 [Rotation]: Thread exit (in thread_rotation() at rotation-thread.c:881)
DBG1 - 09:31:15.471580247 [Rotation]: Thread entry point has returned (in launch_thread() at thread.c:67)
DBG1 - 09:31:15.471647247 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.c:670)
DBG1 - 09:31:15.471667581 [Notification]: Handling fd (43) activity (8209) (in thread_notification() at notification-thread.c:694)
DBG1 - 09:31:15.471680581 [Notification]: Closing client connection (socket fd = 43) (in handle_notification_thread_client_disconnect() at notification-thread-events.c:3470)
DBG1 - 09:31:15.471717247 [Main]: Joined thread "Rotation" (in _lttng_thread_shutdown() at thread.c:168)
DBG1 - 09:31:15.471734914 [Main]: Shutting down "Timer" thread (in _lttng_thread_shutdown() at thread.c:153)
DBG1 - 09:31:15.471793914 [Timer]: Thread exit (in thread_timer() at timer.c:402)
DBG1 - 09:31:15.471820247 [Timer]: Thread entry point has returned (in launch_thread() at thread.c:67)
DBG1 - 09:31:15.471851247 [Notification]: Entering poll wait (in thread_notification() at notification-thread.c:668)
DBG1 - 09:31:15.471999581 [Main]: Joined thread "Timer" (in _lttng_thread_shutdown() at thread.c:168)
DBG1 - 09:31:15.472016581 [Main]: Shutting down "Health management" thread (in _lttng_thread_shutdown() at thread.c:153)
DBG1 - 09:31:15.472056581 [Health management]: Health check thread dying (in thread_manage_health() at health.c:231)
DBG1 - 09:31:15.472154247 [Health management]: Thread entry point has returned (in launch_thread() at thread.c:67)
DBG1 - 09:31:15.472229247 [Main]: Joined thread "Health management" (in _lttng_thread_shutdown() at thread.c:168)
DBG1 - 09:31:15.482411914 [Main]: Cleanup sessiond (in sessiond_cleanup() at main.c:282)
DBG1 - 09:31:15.482594247 [Main]: Removing sessiond and consumerd content of directory /run/lttng (in sessiond_cleanup() at main.c:298)
DBG1 - 09:31:15.482644914 [Main]: Removing /run/lttng/lttng-sessiond.pid (in sessiond_cleanup() at main.c:302)
DBG1 - 09:31:15.482676914 [Main]: Removing /run/lttng/agent.port (in sessiond_cleanup() at main.c:305)
DBG1 - 09:31:15.482703247 [Main]: Removing /run/lttng/kconsumerd/error (in sessiond_cleanup() at main.c:309)
DBG1 - 09:31:15.482738247 [Main]: Removing directory /run/lttng/kconsumerd (in sessiond_cleanup() at main.c:312)
DBG1 - 09:31:15.482775581 [Main]: Removing /run/lttng/ustconsumerd32/error (in sessiond_cleanup() at main.c:316)
DBG1 - 09:31:15.482803581 [Main]: Removing directory /run/lttng/ustconsumerd32 (in sessiond_cleanup() at main.c:319)
DBG1 - 09:31:15.482828247 [Main]: Removing /run/lttng/ustconsumerd64/error (in sessiond_cleanup() at main.c:323)
DBG1 - 09:31:15.482850914 [Main]: Removing directory /run/lttng/ustconsumerd64 (in sessiond_cleanup() at main.c:326)
DBG1 - 09:31:15.482875247 [Main]: Cleaning up all per-event notifier domain agents (in sessiond_cleanup() at main.c:331)
DBG1 - 09:31:15.482977914 [Main]: Cleaning up all agent apps (in sessiond_cleanup() at main.c:334)
DBG1 - 09:31:15.483026581 [Main]: Closing all UST sockets (in sessiond_cleanup() at main.c:336)
DBG3 - 09:31:15.483044247 [Main]: Buffer registry destroy all registry (in buffer_reg_destroy_registries() at buffer-registry.c:743)
DBG3 - 09:31:15.483095581 [HT cleanup]: Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:125)
DBG3 - 09:31:15.483155914 [HT cleanup]: Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)
DBG3 - 09:31:15.483174581 [HT cleanup]: Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:125)
DBG1 - 09:31:15.483230247 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.c:670)
DBG2 - 09:31:15.483236581 [Main]: Closing kernel event notifier group notification file descriptor (in cleanup_kernel_tracer() at kernel.c:2073)
DBG1 - 09:31:15.483247247 [Notification]: Handling fd (11) activity (16) (in thread_notification() at notification-thread.c:694)
DBG2 - 09:31:15.483258247 [Main]: Closing kernel event notifier group file descriptor (in cleanup_kernel_tracer() at kernel.c:2097)
DBG2 - 09:31:15.483273247 [Main]: Closing kernel fd (in cleanup_kernel_tracer() at kernel.c:2109)
DBG1 - 09:31:15.483281581 [Notification]: Entering poll wait (in thread_notification() at notification-thread.c:668)
DBG1 - 09:31:15.483296247 [Notification]: Poll wait returned (2) (in thread_notification() at notification-thread.c:670)
DBG1 - 09:31:15.483306247 [Notification]: Handling fd (13) activity (16) (in thread_notification() at notification-thread.c:694)
DBG1 - 09:31:15.483328247 [Notification]: Handling fd (17) activity (16) (in thread_notification() at notification-thread.c:694)
DBG1 - 09:31:15.483345914 [Notification]: Entering poll wait (in thread_notification() at notification-thread.c:668)
DBG3 - 09:31:15.483574247 [HT cleanup]: Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)
DBG1 - 09:31:15.493426914 [Main]: Shutting down "Notification" thread (in _lttng_thread_shutdown() at thread.c:153)
DBG1 - 09:31:15.493477581 [Main]: Beginning of waiter wait period (in lttng_waiter_wait() at waiter.c:46)
DBG1 - 09:31:15.493488914 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.c:670)
DBG1 - 09:31:15.493522581 [Notification]: Handling fd (33) activity (1) (in thread_notification() at notification-thread.c:694)
DBG1 - 09:31:15.493545247 [Notification]: Received `QUIT` command (in handle_notification_thread_command() at notification-thread-events.c:3162)
DBG1 - 09:31:15.493570247 [Notification]: Closing all client connections (in handle_notification_thread_client_disconnect_all() at notification-thread-events.c:3495)
DBG1 - 09:31:15.493571581 [Main]: End of waiter wait period (in lttng_waiter_wait() at waiter.c:99)
DBG1 - 09:31:15.493979247 [Notification]: Destroying notification channel socket (in notification_channel_socket_destroy() at notification-thread.c:201)
DBG1 - 09:31:15.494081581 [Notification]: Shutting down "Action Executor" thread (in _lttng_thread_shutdown() at thread.c:153)
DBG1 - 09:31:15.494136247 [Action Executor]: Woke-up from wait (in action_executor_thread() at action-executor.c:773)
DBG1 - 09:31:15.494177581 [Action Executor]: Left work execution loop (in action_executor_thread() at action-executor.c:827)
DBG1 - 09:31:15.494200247 [Action Executor]: Thread entry point has returned (in launch_thread() at thread.c:67)
DBG1 - 09:31:15.494360581 [Notification]: Joined thread "Action Executor" (in _lttng_thread_shutdown() at thread.c:168)
DBG1 - 09:31:15.494612247 [Notification]: Thread entry point has returned (in launch_thread() at thread.c:67)
DBG1 - 09:31:15.494711914 [Main]: Joined thread "Notification" (in _lttng_thread_shutdown() at thread.c:168)
DBG1 - 09:31:15.494920247 [Main]: Unloading kernel modules (in main() at main.c:1999)
Error: Failed to load kmod library resources
DBG1 - 09:31:15.506462247 [Main]: Shutting down "HT cleanup" thread (in _lttng_thread_shutdown() at thread.c:153)
DBG3 - 09:31:15.506661247 [HT cleanup]: Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:125)
DBG1 - 09:31:15.506692581 [HT cleanup]: [ht-cleanup] quit. (in thread_ht_cleanup() at ht-cleanup.c:206)
DBG1 - 09:31:15.506726581 [HT cleanup]: [ht-cleanup] Thread terminates. (in thread_ht_cleanup() at ht-cleanup.c:217)
DBG1 - 09:31:15.506740914 [HT cleanup]: Thread entry point has returned (in launch_thread() at thread.c:67)
DBG1 - 09:31:15.506847914 [Main]: Joined thread "HT cleanup" (in _lttng_thread_shutdown() at thread.c:168)
DBG1 - 09:31:15.507092914 [Main]: Cleaning up options (in sessiond_cleanup_options() at main.c:362)
DBG1 - 09:31:15.507118247 [Main]: Destroying run_as worker (in run_as_destroy_worker_no_lock() at runas.c:1576)
DBG1 - 09:31:15.507135247 [Main]: Closing run_as worker socket (in run_as_destroy_worker_no_lock() at runas.c:1581)
DBG1 - 09:31:15.507259247 [Run-as worker]: run_as worker exiting (ret = 0) (in run_as_create_worker_no_lock() at runas.c:1526)
DBG1 - 09:31:15.508243914 [Main]: lttng-runas terminated with status code 0 (in run_as_destroy_worker_no_lock() at runas.c:1601)
thanks,
Ai Chen
Updated by Ai Chen about 1 month ago
---boot---
- dmesg | grep -i LTTng
[ 0.376783] LTTng: Loaded modules v2.14.0-pre (O-Beer) - v2.13.0-rc1-465-g0e6f8768
[ 0.376784] LTTng: Experimental bitwise enum enabled. - lttng create mykernel
Session mykernel created.
Traces will be output to /root/lttng-traces/mykernel-20230212-101813 - lttng status
Recording session mykernel: [inactive]
Trace output: /root/lttng-traces/mykernel-20230212-101813
- lttng list -k
Error: lttng_ctl_ask_sessiond_fds_varlen:607
Error: Unable to list kernel events: Kernel tracer not available
- lttng-sessiond -vvv
DBG1 - 10:18:28.788488703 [Main]: [sessiond configuration]
DBG1 - 10:18:28.791144703 [Main]: version 2.13.8
DBG1 - 10:18:28.791160036 [Main]: verbose: 3
DBG1 - 10:18:28.791170703 [Main]: verbose consumer: 0
DBG1 - 10:18:28.791181036 [Main]: quiet mode: False
DBG1 - 10:18:28.791191369 [Main]: agent_tcp_port: [5345, 5354]
DBG1 - 10:18:28.791202369 [Main]: application socket timeout: 5
DBG1 - 10:18:28.791218703 [Main]: no-kernel: False
DBG1 - 10:18:28.791235036 [Main]: background: False
DBG1 - 10:18:28.791246369 [Main]: daemonize: False
DBG1 - 10:18:28.791256036 [Main]: signal parent on start: False
DBG1 - 10:18:28.791266036 [Main]: tracing group name: tracing
DBG1 - 10:18:28.791276369 [Main]: kmod_probe_list: None
DBG1 - 10:18:28.791286703 [Main]: kmod_extra_probe_list: None
DBG1 - 10:18:28.791295703 [Main]: rundir: /run/lttng
DBG1 - 10:18:28.791305703 [Main]: application socket path: /run/lttng/lttng-ust-sock-8
DBG1 - 10:18:28.791315369 [Main]: client socket path: /run/lttng/client-lttng-sessiond
DBG1 - 10:18:28.791325369 [Main]: wait shm path: /lttng-ust-wait-8
DBG1 - 10:18:28.791341369 [Main]: health socket path: /run/lttng/sessiond-health
DBG1 - 10:18:28.791357369 [Main]: LTTNG_UST_CLOCK_PLUGIN: None
DBG1 - 10:18:28.791368036 [Main]: pid file path: /run/lttng/lttng-sessiond.pid
DBG1 - 10:18:28.791378703 [Main]: lock file path: /run/lttng/lttng-sessiond.lck
DBG1 - 10:18:28.791388369 [Main]: session load path: None
DBG1 - 10:18:28.791398369 [Main]: agent port file path: /run/lttng/agent.port
DBG1 - 10:18:28.791408703 [Main]: consumerd32 path: /run/lttng/ustconsumerd32
DBG1 - 10:18:28.791418703 [Main]: consumerd32 bin path: Unknown
DBG1 - 10:18:28.791428369 [Main]: consumerd32 lib dir: Unknown
DBG1 - 10:18:28.791438369 [Main]: consumerd32 err unix sock path:/run/lttng/ustconsumerd32/error
DBG1 - 10:18:28.791448369 [Main]: consumerd32 cmd unix sock path:/run/lttng/ustconsumerd32/command
DBG1 - 10:18:28.791458369 [Main]: consumerd64 path: /run/lttng/ustconsumerd64
DBG1 - 10:18:28.791474369 [Main]: consumerd64 bin path: /usr/lib/lttng/libexec/lttng-consumerd
DBG1 - 10:18:28.791490369 [Main]: consumerd64 lib dir: /usr/lib
DBG1 - 10:18:28.791501036 [Main]: consumerd64 err unix sock path:/run/lttng/ustconsumerd64/error
DBG1 - 10:18:28.791511036 [Main]: consumerd64 cmd unix sock path:/run/lttng/ustconsumerd64/command
DBG1 - 10:18:28.791521036 [Main]: kconsumerd path: /run/lttng/kconsumerd
DBG1 - 10:18:28.791541036 [Main]: kconsumerd err unix sock path: /run/lttng/kconsumerd/error
DBG1 - 10:18:28.791556369 [Main]: kconsumerd cmd unix sock path: /run/lttng/kconsumerd/command
DBG1 - 10:18:28.791578036 [Main]: Starting lttng-sessiond {145c907b-9560-4b7b-8699-d739681a724a} (in sessiond_uuid_log() at main.c:1437)
DBG3 - 10:18:28.791589036 [Main]: Creating LTTng run directory: /run/lttng (in create_lttng_rundir() at main.c:1069)
Error: A session daemon is already running.
DBG1 - 10:18:28.792098703 [Main]: Cleaning up options (in sessiond_cleanup_options() at main.c:362)
DBG1 - 10:18:28.792170369 [Main]: Destroying run_as worker (in run_as_destroy_worker_no_lock() at runas.c:1576) - lttng -vvv list -k
DBG2 - 10:19:07.444221374 [10136/10136]: Session name: (null) (in cmd_list() at commands/list.c:2345)
DBG1 - 10:19:07.444408040 [10136/10136]: Getting kernel tracing events (in list_kernel_events() at commands/list.c:965)
DBG1 - 10:19:07.444641040 [10136/10136]: LSM cmd type: 'LTTNG_LIST_TRACEPOINTS' (14) (in send_session_msg() at lttng-ctl.c:121)
Error: lttng_ctl_ask_sessiond_fds_varlen:607
Error: Unable to list kernel events: Kernel tracer not available
DBG1 - 10:19:07.445415040 [10136/10136]: Clean exit (in clean_exit() at lttng.c:155)
I hope this information is helpful for this problem.
Updated by Kienan Stewart about 1 month ago
Hi Ai Chen,
it looks like you are using lttng-modules from master branch perhaps, but the stable lttng-tools version.Could you try using the latest release of lttng-modules instead, v2.13.15: https://github.com/lttng/lttng-modules/releases/tag/v2.13.15
In the steps you mentioned in comment #1419-7, `lttng-sessiond vvv` fails because `lttng create` will spawn a new session daemon by default if one is not already running. C.f. https://lttng.org/man/1/lttng-create/v2.13/#doc_description
thanks,
kienan
Updated by Ai Chen about 1 month ago
Hi Kienan,
I'm using the latest release of lttng-modules,v2.13.15 in kernel, but nothing has changed.----boot---
- dmesg | grep -i LTTng
[ 0.391869] LTTng: Loaded modules v2.13.15 (Nordicit¨¦)
[ 0.391871] LTTng: Experimental bitwise enum enabled. - lttng create mykernel
Spawning a session daemon
Session mykernel created.
Traces will be output to /root/lttng-traces/mykernel-20230213-092926 - lttng list -k
Error: lttng_ctl_ask_sessiond_fds_varlen:607
Error: Unable to list kernel events: Kernel tracer not available
- ldd $(which lttng)
linux-vdso.so.1 (0x0000ffffa1b71000)
liblttng-ctl.so.0 => /usr/lib64/liblttng-ctl.so.0 (0x0000ffffa1a9a000)
libxml2.so.2 => /usr/lib64/libxml2.so.2 (0x0000ffffa195c000)
libdl.so.2 => /lib64/libdl.so.2 (0x0000ffffa1948000)
libz.so.1 => /usr/lib64/libz.so.1 (0x0000ffffa1924000)
liblzma.so.5 => /usr/lib64/liblzma.so.5 (0x0000ffffa18f3000)
libpthread.so.0 => /lib64/libpthread.so.0 (0x0000ffffa18c2000)
libm.so.6 => /lib64/libm.so.6 (0x0000ffffa1818000)
libpopt.so.0 => /usr/lib64/libpopt.so.0 (0x0000ffffa17fd000)
librt.so.1 => /lib64/librt.so.1 (0x0000ffffa17e5000)
libc.so.6 => /lib64/libc.so.6 (0x0000ffffa1676000)
/lib/ld-linux-aarch64.so.1 (0x0000ffffa1b41000) - ldd $(which lttng-sessiond)
linux-vdso.so.1 (0x0000ffff9d905000)
libkmod.so.2 => /usr/lib64/libkmod.so.2 (0x0000ffff9d8b1000)
libcrypto.so.1.1 => /usr/lib64/libcrypto.so.1.1 (0x0000ffff9d650000)
liblttng-ctl.so.0 => /usr/lib64/liblttng-ctl.so.0 (0x0000ffff9d5a9000)
liburcu.so.6 => /usr/lib64/liburcu.so.6 (0x0000ffff9d591000)
liburcu-cds.so.6 => /usr/lib64/liburcu-cds.so.6 (0x0000ffff9d577000)
liburcu-common.so.6 => /usr/lib64/liburcu-common.so.6 (0x0000ffff9d562000)
libxml2.so.2 => /usr/lib64/libxml2.so.2 (0x0000ffff9d424000)
libdl.so.2 => /lib64/libdl.so.2 (0x0000ffff9d410000)
libz.so.1 => /usr/lib64/libz.so.1 (0x0000ffff9d3ec000)
liblzma.so.5 => /usr/lib64/liblzma.so.5 (0x0000ffff9d3bb000)
libpthread.so.0 => /lib64/libpthread.so.0 (0x0000ffff9d38a000)
libm.so.6 => /lib64/libm.so.6 (0x0000ffff9d2e0000)
librt.so.1 => /lib64/librt.so.1 (0x0000ffff9d2c8000)
libc.so.6 => /lib64/libc.so.6 (0x0000ffff9d159000)
libatomic.so.1 => /lib64/libatomic.so.1 (0x0000ffff9d13e000)
/lib/ld-linux-aarch64.so.1 (0x0000ffff9d8d5000) - lttng-sessiond -vvv
DBG1 - 09:30:04.314003676 [Main]: [sessiond configuration]
DBG1 - 09:30:04.314263009 [Main]: version 2.13.8
DBG1 - 09:30:04.314393009 [Main]: verbose: 3
DBG1 - 09:30:04.314442342 [Main]: verbose consumer: 0
DBG1 - 09:30:04.314489009 [Main]: quiet mode: False
DBG1 - 09:30:04.314535676 [Main]: agent_tcp_port: [5345, 5354]
DBG1 - 09:30:04.314583342 [Main]: application socket timeout: 5
DBG1 - 09:30:04.314728009 [Main]: no-kernel: False
DBG1 - 09:30:04.314772342 [Main]: background: False
DBG1 - 09:30:04.314815342 [Main]: daemonize: False
DBG1 - 09:30:04.314864676 [Main]: signal parent on start: False
DBG1 - 09:30:04.314913009 [Main]: tracing group name: tracing
DBG1 - 09:30:04.314955676 [Main]: kmod_probe_list: None
DBG1 - 09:30:04.314996676 [Main]: kmod_extra_probe_list: None
DBG1 - 09:30:04.315037009 [Main]: rundir: /run/lttng
DBG1 - 09:30:04.315079342 [Main]: application socket path: /run/lttng/lttng-ust-sock-8
DBG1 - 09:30:04.315129676 [Main]: client socket path: /run/lttng/client-lttng-sessiond
DBG1 - 09:30:04.315172009 [Main]: wait shm path: /lttng-ust-wait-8
DBG1 - 09:30:04.315214342 [Main]: health socket path: /run/lttng/sessiond-health
DBG1 - 09:30:04.315313342 [Main]: LTTNG_UST_CLOCK_PLUGIN: None
DBG1 - 09:30:04.315370342 [Main]: pid file path: /run/lttng/lttng-sessiond.pid
DBG1 - 09:30:04.315416342 [Main]: lock file path: /run/lttng/lttng-sessiond.lck
DBG1 - 09:30:04.315463342 [Main]: session load path: None
DBG1 - 09:30:04.315508009 [Main]: agent port file path: /run/lttng/agent.port
DBG1 - 09:30:04.315571342 [Main]: consumerd32 path: /run/lttng/ustconsumerd32
DBG1 - 09:30:04.315627676 [Main]: consumerd32 bin path: Unknown
DBG1 - 09:30:04.315672676 [Main]: consumerd32 lib dir: Unknown
DBG1 - 09:30:04.315717009 [Main]: consumerd32 err unix sock path:/run/lttng/ustconsumerd32/error
DBG1 - 09:30:04.315762009 [Main]: consumerd32 cmd unix sock path:/run/lttng/ustconsumerd32/command
DBG1 - 09:30:04.315808009 [Main]: consumerd64 path: /run/lttng/ustconsumerd64
DBG1 - 09:30:04.315853009 [Main]: consumerd64 bin path: /usr/lib/lttng/libexec/lttng-consumerd
DBG1 - 09:30:04.315897342 [Main]: consumerd64 lib dir: /usr/lib
DBG1 - 09:30:04.315941676 [Main]: consumerd64 err unix sock path:/run/lttng/ustconsumerd64/error
DBG1 - 09:30:04.316002009 [Main]: consumerd64 cmd unix sock path:/run/lttng/ustconsumerd64/command
DBG1 - 09:30:04.316048676 [Main]: kconsumerd path: /run/lttng/kconsumerd
DBG1 - 09:30:04.316094676 [Main]: kconsumerd err unix sock path: /run/lttng/kconsumerd/error
DBG1 - 09:30:04.316138342 [Main]: kconsumerd cmd unix sock path: /run/lttng/kconsumerd/command
DBG1 - 09:30:04.316194009 [Main]: Starting lttng-sessiond {08479ddc-7764-4281-b464-ac73c9af60d3} (in sessiond_uuid_log() at main.c:1437)
DBG3 - 09:30:04.316224676 [Main]: Creating LTTng run directory: /run/lttng (in create_lttng_rundir() at main.c:1069)
Error: A session daemon is already running.
DBG1 - 09:30:04.316858009 [Main]: Cleaning up options (in sessiond_cleanup_options() at main.c:362)
DBG1 - 09:30:04.316907676 [Main]: Destroying run_as worker (in run_as_destroy_worker_no_lock() at runas.c:1576) - lttng -vvv list -k
DBG2 - 09:30:18.896848011 [10103/10103]: Session name: (null) (in cmd_list() at commands/list.c:2345)
DBG1 - 09:30:18.897280011 [10103/10103]: Getting kernel tracing events (in list_kernel_events() at commands/list.c:965)
DBG1 - 09:30:18.897667011 [10103/10103]: LSM cmd type: 'LTTNG_LIST_TRACEPOINTS' (14) (in send_session_msg() at lttng-ctl.c:121)
Error: lttng_ctl_ask_sessiond_fds_varlen:607
Error: lttng_ctl_ask_sessiond_fds_varlen -33
Error: Unable to list kernel events: Kernel tracer not available
DBG1 - 09:30:18.898542011 [10103/10103]: Clean exit (in clean_exit() at lttng.c:155)
#
thanks,
Ai Chen
Updated by Ai Chen 26 days ago
Hi,
I execute lttng-sessiond -vvv in one terminal and lttng list -k in another terminal, the error always occurs in
Error: Failed to load kmod library resources
- lttng -vvv
DBG1 - 14:05:06.786747684 [10065/10065]: Clean exit (in clean_exit() at lttng.c:155) - lttng-sessiond -vvv
DBG1 - 14:05:17.330402352 [Main]: [sessiond configuration]
DBG1 - 14:05:17.330541686 [Main]: version 2.13.8
DBG1 - 14:05:17.330565019 [Main]: verbose: 3
DBG1 - 14:05:17.330584352 [Main]: verbose consumer: 0
DBG1 - 14:05:17.330595019 [Main]: quiet mode: False
DBG1 - 14:05:17.330605686 [Main]: agent_tcp_port: [5345, 5354]
DBG1 - 14:05:17.330616686 [Main]: application socket timeout: 5
DBG1 - 14:05:17.330633019 [Main]: no-kernel: False
DBG1 - 14:05:17.330643352 [Main]: background: False
DBG1 - 14:05:17.330654352 [Main]: daemonize: False
DBG1 - 14:05:17.330664019 [Main]: signal parent on start: False
DBG1 - 14:05:17.330674019 [Main]: tracing group name: tracing
DBG1 - 14:05:17.330684686 [Main]: kmod_probe_list: None
DBG1 - 14:05:17.330694352 [Main]: kmod_extra_probe_list: None
DBG1 - 14:05:17.330704019 [Main]: rundir: /run/lttng
DBG1 - 14:05:17.330718352 [Main]: application socket path: /run/lttng/lttng-ust-sock-8
DBG1 - 14:05:17.330746686 [Main]: client socket path: /run/lttng/client-lttng-sessiond
DBG1 - 14:05:17.330761686 [Main]: wait shm path: /lttng-ust-wait-8
DBG1 - 14:05:17.330772352 [Main]: health socket path: /run/lttng/sessiond-health
DBG1 - 14:05:17.330783019 [Main]: LTTNG_UST_CLOCK_PLUGIN: None
DBG1 - 14:05:17.330793352 [Main]: pid file path: /run/lttng/lttng-sessiond.pid
DBG1 - 14:05:17.330803352 [Main]: lock file path: /run/lttng/lttng-sessiond.lck
DBG1 - 14:05:17.330813352 [Main]: session load path: None
DBG1 - 14:05:17.330823686 [Main]: agent port file path: /run/lttng/agent.port
DBG1 - 14:05:17.330863352 [Main]: consumerd32 path: /run/lttng/ustconsumerd32
DBG1 - 14:05:17.330879352 [Main]: consumerd32 bin path: Unknown
DBG1 - 14:05:17.330890019 [Main]: consumerd32 lib dir: Unknown
DBG1 - 14:05:17.330900686 [Main]: consumerd32 err unix sock path:/run/lttng/ustconsumerd32/error
DBG1 - 14:05:17.330910686 [Main]: consumerd32 cmd unix sock path:/run/lttng/ustconsumerd32/command
DBG1 - 14:05:17.330921352 [Main]: consumerd64 path: /run/lttng/ustconsumerd64
DBG1 - 14:05:17.330931352 [Main]: consumerd64 bin path: /usr/lib/lttng/libexec/lttng-consumerd
DBG1 - 14:05:17.330941686 [Main]: consumerd64 lib dir: /usr/lib
DBG1 - 14:05:17.330952019 [Main]: consumerd64 err unix sock path:/run/lttng/ustconsumerd64/error
DBG1 - 14:05:17.330962019 [Main]: consumerd64 cmd unix sock path:/run/lttng/ustconsumerd64/command
DBG1 - 14:05:17.330972019 [Main]: kconsumerd path: /run/lttng/kconsumerd
DBG1 - 14:05:17.330982686 [Main]: kconsumerd err unix sock path: /run/lttng/kconsumerd/error
DBG1 - 14:05:17.330998019 [Main]: kconsumerd cmd unix sock path: /run/lttng/kconsumerd/command
DBG1 - 14:05:17.331017019 [Main]: Starting lttng-sessiond {5ff9d3f2-99f5-4e0b-8c04-388605692bc5} (in sessiond_uuid_log() at main.c:1437)
DBG3 - 14:05:17.331032352 [Main]: Creating LTTng run directory: /run/lttng (in create_lttng_rundir() at main.c:1069)
DBG1 - 14:05:17.332742019 [Main]: Resetting run_as worker signal handlers to default (in reset_sighandler() at runas.c:1377)
DBG1 - 14:05:17.333179019 [Main]: run_as signal handler set for SIGTERM and SIGINT (in set_worker_sighandlers() at runas.c:1438)
DBG1 - 14:05:17.335006019 [Main]: Health check time delta in seconds set to 20 (in health_init() at health.c:62)
DBG1 - 14:05:17.335314352 [HT cleanup]: Entering thread entry point (in launch_thread() at thread.c:65)
DBG1 - 14:05:17.335346019 [HT cleanup]: startup. (in thread_ht_cleanup() at ht-cleanup.c:98)
DBG1 - 14:05:17.335485352 [HT cleanup]: epoll set max size is 584785 (in compat_epoll_set_max_size() at poll.c:350)
DBG3 - 14:05:17.335542019 [Main]: Created hashtable size 16 at 0x338fa370 of type U64 (in lttng_ht_new() at hashtable.c:152)
DBG3 - 14:05:17.335570019 [Main]: Created hashtable size 16 at 0x338fa8c0 of type U64 (in lttng_ht_new() at hashtable.c:152)
DBG3 - 14:05:17.335602686 [Main]: Created hashtable size 16 at 0x338faf20 of type U64 (in lttng_ht_new() at hashtable.c:152)
DBG3 - 14:05:17.335622686 [Main]: Created hashtable size 4 at 0x338fb440 of type ULONG (in lttng_ht_new() at hashtable.c:152)
DBG3 - 14:05:17.335636352 [Main]: Created hashtable size 4 at 0x338fb880 of type U64 (in lttng_ht_new() at hashtable.c:152)
DBG2 - 14:05:17.335649019 [Main]: Creating consumer directory: /run/lttng/kconsumerd (in set_consumer_sockets() at main.c:1111)
DBG3 - 14:05:17.335992352 [HT cleanup]: Polling. (in thread_ht_cleanup() at ht-cleanup.c:122)
Warning: No tracing group detected
Error: Failed to load kmod library resources
Warning: No kernel tracer available
DBG2 - 14:05:17.337571352 [Main]: Creating consumer directory: /run/lttng/ustconsumerd64 (in set_consumer_sockets() at main.c:1111)
DBG2 - 14:05:17.337725019 [Main]: Creating consumer directory: /run/lttng/ustconsumerd32 (in set_consumer_sockets() at main.c:1111)
DBG3 - 14:05:17.337931686 [Main]: Created hashtable size 4 at 0x338fc6b0 of type U64 (in lttng_ht_new() at hashtable.c:152)
DBG3 - 14:05:17.337954352 [Main]: Global buffer per UID registry initialized (in buffer_reg_init_uid_registry() at buffer-registry.c:90)
DBG3 - 14:05:17.338101352 [Main]: Created hashtable size 4 at 0x338fd120 of type U64 (in lttng_ht_new() at hashtable.c:152)
DBG3 - 14:05:17.338122686 [Main]: Global buffer per PID registry initialized (in buffer_reg_init_pid_registry() at buffer-registry.c:219)
DBG1 - 14:05:17.338140352 [Main]: Command subsystem initialized (in cmd_init() at cmd.c:6064)
DBG1 - 14:05:17.338190352 [Main]: '10066' written in file /run/lttng/lttng-sessiond.pid (in utils_create_pid_file() at utils.c:257)
DBG1 - 14:05:17.338354686 [Main]: TCP inet operation timeout set to 216 sec (in lttcomm_inet_init() at inet.c:545)
DBG1 - 14:05:17.338485686 [Main]: Waiting for health management thread to be ready (in wait_until_thread_is_ready() at health.c:35)
DBG1 - 14:05:17.338508019 [Health management]: Entering thread entry point (in launch_thread() at thread.c:65)
DBG1 - 14:05:17.338543019 [Health management]: [thread] Manage health check started (in thread_manage_health() at health.c:65)
DBG1 - 14:05:17.338734352 [Health management]: Marking health management thread as ready (in mark_thread_as_ready() at health.c:28)
DBG1 - 14:05:17.338939019 [Health management]: Health check ready (in thread_manage_health() at health.c:136)
DBG1 - 14:05:17.338943352 [Main]: Health management thread is ready (in wait_until_thread_is_ready() at health.c:37)
DBG1 - 14:05:17.339052019 [Main]: Waiting for notification thread to be ready (in wait_until_thread_is_ready() at notification-thread.c:414)
DBG1 - 14:05:17.339069686 [Notification]: Entering thread entry point (in launch_thread() at thread.c:65)
DBG1 - 14:05:17.339090686 [Notification]: Started notification thread (in thread_notification() at notification-thread.c:642)
DBG1 - 14:05:17.339174352 [Notification]: Creating notification channel UNIX socket at /run/lttng/sessiond-notification (in notification_channel_socket_create() at notification-thread.c:223)
DBG1 - 14:05:17.339294686 [Notification]: Notification channel UNIX socket created (fd = 34) (in notification_channel_socket_create() at notification-thread.c:258)
DBG1 - 14:05:17.339370019 [Notification]: Listening on notification channel socket (in init_thread_state() at notification-thread.c:442)
DBG1 - 14:05:17.339481352 [Notification]: Marking notification thread as ready (in mark_thread_as_ready() at notification-thread.c:407)
DBG1 - 14:05:17.339507352 [Notification]: Entering poll wait (in thread_notification() at notification-thread.c:668)
DBG1 - 14:05:17.339514352 [Main]: Notification thread is ready (in wait_until_thread_is_ready() at notification-thread.c:416)
DBG1 - 14:05:17.339620686 [Timer]: Entering thread entry point (in launch_thread() at thread.c:65)
DBG1 - 14:05:17.339718686 [Rotation]: Entering thread entry point (in launch_thread() at thread.c:65)
DBG1 - 14:05:17.339745686 [Rotation]: Started rotation thread (in thread_rotation() at rotation-thread.c:789)
DBG1 - 14:05:17.339764352 [Main]: Created client socket (fd = 40) (in create_client_sock() at client.c:2428)
DBG1 - 14:05:17.339884352 [Main]: Waiting for client thread to be ready (in wait_thread_status() at client.c:65)
DBG1 - 14:05:17.339497686 [Action Executor]: Entering thread entry point (in launch_thread() at thread.c:65)
DBG1 - 14:05:17.339919686 [Action Executor]: Entering work execution loop (in action_executor_thread() at action-executor.c:761)
DBG1 - 14:05:17.339934019 [Action Executor]: No work items enqueued, entering wait (in action_executor_thread() at action-executor.c:770)
DBG1 - 14:05:17.340055019 [Client management]: Entering thread entry point (in launch_thread() at thread.c:65)
DBG1 - 14:05:17.340373352 [Client management]: [thread] Manage client started (in thread_manage_clients() at client.c:2461)
DBG1 - 14:05:17.340686019 [Client management]: Marking client thread's state as running (in set_thread_status() at client.c:58)
DBG1 - 14:05:17.340826019 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.c:670)
DBG1 - 14:05:17.340939019 [Main]: Client thread is ready (in wait_thread_status() at client.c:68)
DBG1 - 14:05:17.341094352 [Notification]: Handling fd (34) activity (1) (in thread_notification() at notification-thread.c:694)
DBG1 - 14:05:17.341124686 [Notification]: Handling new notification channel client connection (in handle_notification_thread_client_connect() at notification-thread-events.c:3351)
DBG1 - 14:05:17.341201019 [Notification]: Client socket (fd = 44) set as non-blocking (in socket_set_non_blocking() at notification-thread-events.c:3319)
DBG1 - 14:05:17.341220352 [Main]: All permissions are set (in set_permissions() at main.c:1057)
DBG1 - 14:05:17.341235019 [Notification]: Added new notification channel client socket (44) to poll set (in handle_notification_thread_client_connect() at notification-thread-events.c:3404)
DBG1 - 14:05:17.341281352 [Notification]: Entering poll wait (in thread_notification() at notification-thread.c:668)
DBG1 - 14:05:17.341358686 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.c:670)
DBG3 - 14:05:17.341376686 [Main]: Session daemon application socket created (fd = 47) (in create_application_socket() at register.c:71)
DBG1 - 14:05:17.340940686 [Client management]: Accepting client command ... (in thread_manage_clients() at client.c:2527)
DBG1 - 14:05:17.341481686 [UST application registration]: Entering thread entry point (in launch_thread() at thread.c:65)
DBG1 - 14:05:17.341377352 [Notification]: Handling fd (44) activity (1) (in thread_notification() at notification-thread.c:694)
DBG1 - 14:05:17.341682019 [Notification]: Entering poll wait (in thread_notification() at notification-thread.c:668)
DBG1 - 14:05:17.341698019 [Notification]: Poll wait returned (1) (in thread_notification() at notification-thread.c:670)
DBG1 - 14:05:17.341714019 [Notification]: Handling fd (44) activity (1) (in thread_notification() at notification-thread.c:694)
DBG1 - 14:05:17.341736019 [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:3879)
DBG1 - 14:05:17.341758352 [Notification]: Send command reply (0) (in client_send_command_reply() at notification-thread-events.c:3755)
DBG1 - 14:05:17.341778352 [Notification]: Flushing client (socket fd = 44) outgoing queue (in client_flush_outgoing_queue() at notification-thread-events.c:3644)
DBG1 - 14:05:17.341929019 [Notification]: Entering poll wait (in thread_notification() at notification-thread.c:668)
DBG1 - 14:05:17.341465019 [Main]: Waiting for application registration thread to be ready (in wait_thread_status() at register.c:131)
DBG1 - 14:05:17.341648352 [UST application registration]: [thread] Manage application registration started (in thread_application_registration() at register.c:168)
DBG1 - 14:05:17.341977352 [Rotation]: Entering poll wait (in thread_rotation() at rotation-thread.c:813)
DBG1 - 14:05:17.342037686 [UST registration dispatch]: Entering thread entry point (in launch_thread() at thread.c:65)
DBG1 - 14:05:17.342172019 [UST registration dispatch]: [thread] Dispatch UST command started (in thread_dispatch_ust_registration() at dispatch.c:250)
DBG1 - 14:05:17.342194019 [UST registration dispatch]: Futex n to 1 prepare done (in futex_nto1_prepare() at futex.c:67)
DBG1 - 14:05:17.342226352 [UST application registration]: Marking application registration thread's state as running (in set_thread_status() at register.c:124)
DBG1 - 14:05:17.342233019 [UST registration dispatch]: Woken up but nothing in the UST command queue (in thread_dispatch_ust_registration() at dispatch.c:279)
DBG1 - 14:05:17.342265019 [UST application registration]: Accepting application registration (in thread_application_registration() at register.c:207)
DBG1 - 14:05:17.342343686 [Main]: Application registration thread is ready (in wait_thread_status() at register.c:134)
DBG1 - 14:05:17.342366352 [Main]: Notifying applications of session daemon state: 1 (in notify_ust_apps() at register.c:91)
DBG1 - 14:05:17.342512352 [Main]: Wait shared memory file descriptor created successfully: path = '/lttng-ust-wait-8', mmap_size = 4096, global = true, fd = 49 (in get_wait_shm() at shm.c:133)
DBG1 - 14:05:17.342575686 [Main]: Futex wait update active 1 (in futex_wait_update() at futex.c:55)
DBG1 - 14:05:17.342739352 [UST application management]: Entering thread entry point (in launch_thread() at thread.c:65)
DBG1 - 14:05:17.342786352 [Kernel management]: Entering thread entry point (in launch_thread() at thread.c:65)
DBG1 - 14:05:17.343209686 [Kernel management]: [thread] Thread manage kernel started (in thread_kernel_management() at manage-kernel.c:173)
DBG1 - 14:05:17.343279019 [Kernel management]: Updating kernel poll set (in update_kernel_poll() at manage-kernel.c:37)
DBG1 - 14:05:17.343297352 [Kernel management]: Thread kernel polling (in thread_kernel_management() at manage-kernel.c:227)
DBG1 - 14:05:17.343105352 [UST application management]: [thread] Manage application started (in thread_application_management() at manage-apps.c:52)
DBG1 - 14:05:17.343602019 [UST application management]: Apps thread polling (in thread_application_management() at manage-apps.c:88)
DBG1 - 14:10:36.235825057 [Client management]: Wait for client response (in thread_manage_clients() at client.c:2569)
DBG1 - 14:10:36.235959390 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.c:2597)
DBG1 - 14:10:36.236005057 [Client management]: Processing client command 'LTTNG_LIST_TRACEPOINTS' (14) (in process_client_msg() at client.c:1009)
Error: Failed to load kmod library resources
Warning: No kernel tracer available
DBG1 - 14:10:36.236225057 [Client management]: Missing llm header, creating one. (in process_client_msg() at client.c:2374)
DBG1 - 14:10:36.236248390 [Client management]: Sending response (size: 24, retcode: Kernel tracer not available (33)) (in thread_manage_clients() at client.c:2676)
DBG1 - 14:10:36.236595390 [Client management]: Accepting client command ... (in thread_manage_clients() at client.c:2527)
DBG1 - 14:10:51.428531059 [Client management]: Wait for client response (in thread_manage_clients() at client.c:2569)
DBG1 - 14:10:51.428628392 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.c:2597)
DBG1 - 14:10:51.428917725 [Client management]: Incomplete recv() from client... continuing (in thread_manage_clients() at client.c:2601)
DBG1 - 14:10:51.428986725 [Client management]: Accepting client command ... (in thread_manage_clients() at client.c:2527)
DBG1 - 14:10:51.429568059 [Client management]: Wait for client response (in thread_manage_clients() at client.c:2569)
DBG1 - 14:10:51.429632059 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.c:2597)
DBG1 - 14:10:51.429919725 [Client management]: Processing client command 'LTTNG_CREATE_SESSION_EXT' (49) (in process_client_msg() at client.c:1009)
DBG2 - 14:10:51.430181059 [Client management]: Trying to find session by name mykernel (in session_find_by_name() at session.c:1143)
DBG3 - 14:10:51.430256392 [Client management]: Created hashtable size 4 at 0xffff64000f00 of type ULONG (in lttng_ht_new() at hashtable.c:152)
DBG3 - 14:10:51.430305392 [Client management]: Created hashtable size 4 at 0xffff64001340 of type ULONG (in lttng_ht_new() at hashtable.c:152)
DBG1 - 14:10:51.430500392 [Client management]: Allocating ltt_sessions_ht_by_id (in ltt_sessions_ht_alloc() at session.c:306)
DBG3 - 14:10:51.430523725 [Client management]: Created hashtable size 4 at 0xffff64001780 of type U64 (in lttng_ht_new() at hashtable.c:152)
DBG1 - 14:10:51.430536059 [Client management]: Allocating ltt_sessions_ht_by_name (in ltt_sessions_ht_alloc() at session.c:314)
DBG3 - 14:10:51.430550725 [Client management]: Created hashtable size 4 at 0xffff64001bc0 of type STRING (in lttng_ht_new() at hashtable.c:152)
DBG1 - 14:10:51.430578059 [Client management]: Tracing session mykernel created with ID 0 by uid = 0, gid = 0 (in session_create() at session.c:1348)
DBG3 - 14:10:51.430641725 [Client management]: URI string: file:///root/lttng-traces/mykernel-20230131-141051 (in uri_parse() at uri.c:298)
DBG3 - 14:10:51.430678059 [Client management]: URI file destination: /root/lttng-traces/mykernel-20230131-141051 (in uri_parse() at uri.c:335)
DBG3 - 14:10:51.430877059 [Client management]: URI dtype: 3, proto: 0, host: , subdir: , ctrl: 0, data: 0 (in uri_parse() at uri.c:510)
DBG2 - 14:10:51.430904059 [Client management]: Setting trace directory path from URI to /root/lttng-traces/mykernel-20230131-141051 (in add_uri_to_consumer() at cmd.c:695)
DBG1 - 14:10:51.431079725 [Client management]: Sending response (size: 8250, retcode: Success (10)) (in thread_manage_clients() at client.c:2676)
DBG1 - 14:10:51.431146725 [Client management]: Accepting client command ... (in thread_manage_clients() at client.c:2527)
DBG1 - 14:10:51.431715725 [Client management]: Wait for client response (in thread_manage_clients() at client.c:2569)
DBG1 - 14:10:51.431765392 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.c:2597)
DBG1 - 14:10:51.431966725 [Client management]: Processing client command 'LTTNG_LIST_SESSIONS' (13) (in process_client_msg() at client.c:1009)
DBG1 - 14:10:51.431992725 [Client management]: Counting number of available session for UID 0 (in lttng_sessions_count() at client.c:596)
DBG1 - 14:10:51.432010392 [Client management]: Getting all available session for UID 0 GID 0 (in cmd_list_lttng_sessions() at cmd.c:3923)
DBG1 - 14:10:51.432029725 [Client management]: Sending response (size: 4409, retcode: Success (10)) (in thread_manage_clients() at client.c:2676)
DBG1 - 14:10:51.432078725 [Client management]: Accepting client command ... (in thread_manage_clients() at client.c:2527)
DBG1 - 14:11:00.837239060 [Client management]: Wait for client response (in thread_manage_clients() at client.c:2569)
DBG1 - 14:11:00.837590060 [Client management]: Receiving data from client ... (in thread_manage_clients() at client.c:2597)
DBG1 - 14:11:00.837907060 [Client management]: Processing client command 'LTTNG_LIST_TRACEPOINTS' (14) (in process_client_msg() at client.c:1009)
Error: Failed to load kmod library resources
Warning: No kernel tracer available
DBG1 - 14:11:00.838546726 [Client management]: Missing llm header, creating one. (in process_client_msg() at client.c:2374)
DBG1 - 14:11:00.838575393 [Client management]: Sending response (size: 24, retcode: Kernel tracer not available (33)) (in thread_manage_clients() at client.c:2676)
DBG1 - 14:11:00.838631393 [Client management]: Accepting client command ... (in thread_manage_clients() at client.c:2527)
Updated by Kienan Stewart 24 days ago
- Status changed from New to Resolved
I'm glad you were able to fix it!