Bug #1419
openLTTng-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 3 days 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 3 days 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 21 hours 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 21 hours 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 21 hours 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 20 hours 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 10 hours 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