|
DEBUG1 - 16:17:36.106565048 [17803/17803]: [sessiond configuration]
|
|
DEBUG1 - 16:17:36.106600875 [17803/17803]: verbose: 3
|
|
DEBUG1 - 16:17:36.106603911 [17803/17803]: verbose consumer: 1
|
|
DEBUG1 - 16:17:36.106606440 [17803/17803]: quiet mode: False
|
|
DEBUG1 - 16:17:36.106608669 [17803/17803]: agent_tcp_port: [5345, 5354]
|
|
DEBUG1 - 16:17:36.106611008 [17803/17803]: application socket timeout: 5
|
|
DEBUG1 - 16:17:36.106613259 [17803/17803]: no-kernel: True
|
|
DEBUG1 - 16:17:36.106615469 [17803/17803]: background: False
|
|
DEBUG1 - 16:17:36.106617939 [17803/17803]: daemonize: False
|
|
DEBUG1 - 16:17:36.106620468 [17803/17803]: signal parent on start: False
|
|
DEBUG1 - 16:17:36.106623378 [17803/17803]: tracing group name: tracing
|
|
DEBUG1 - 16:17:36.106626408 [17803/17803]: kmod_probe_list: None
|
|
DEBUG1 - 16:17:36.106629568 [17803/17803]: kmod_extra_probe_list: None
|
|
DEBUG1 - 16:17:36.106631705 [17803/17803]: rundir: /var/lib/log/lttng_home/.lttng
|
|
DEBUG1 - 16:17:36.106633996 [17803/17803]: application socket path: /var/lib/log/lttng_home/.lttng/lttng-ust-sock-7
|
|
DEBUG1 - 16:17:36.106636270 [17803/17803]: client socket path: /var/lib/log/lttng_home/.lttng/client-lttng-sessiond
|
|
DEBUG1 - 16:17:36.106638523 [17803/17803]: wait shm path: /lttng-ust-wait-7-1000
|
|
DEBUG1 - 16:17:36.106640649 [17803/17803]: health socket path: /var/lib/log/lttng_home/.lttng/sessiond-health
|
|
DEBUG1 - 16:17:36.106642832 [17803/17803]: LTTNG_UST_CLOCK_PLUGIN: None
|
|
DEBUG1 - 16:17:36.106644893 [17803/17803]: pid file path: /var/lib/log/lttng_home/.lttng/lttng-sessiond.pid
|
|
DEBUG1 - 16:17:36.106647107 [17803/17803]: lock file path: /var/lib/log/lttng_home/.lttng/lttng-sessiond.lck
|
|
DEBUG1 - 16:17:36.106649252 [17803/17803]: session load path: None
|
|
DEBUG1 - 16:17:36.106652274 [17803/17803]: agent port file path: /var/lib/log/lttng_home/.lttng/agent.port
|
|
DEBUG3 - 16:17:36.106654576 [17803/17803]: Creating LTTng run directory: /var/lib/log/lttng_home/.lttng (in create_lttng_rundir() at main.c:5264)
|
|
DEBUG1 - 16:17:36.106995551 [17805/17805]: Resetting run_as worker signal handlers to default (in reset_sighandler() at runas.c:536)
|
|
DEBUG1 - 16:17:36.107088291 [17805/17805]: run_as signal handler set for SIGTERM and SIGINT (in set_worker_sighandlers() at runas.c:597)
|
|
DEBUG1 - 16:17:36.107136383 [17803/17803]: Health check time delta in seconds set to 20 (in health_init() at health.c:73)
|
|
DEBUG1 - 16:17:36.107192152 [17803/17806]: [ht-thread] startup. (in thread_ht_cleanup() at ht-cleanup.c:101)
|
|
DEBUG1 - 16:17:36.107222613 [17803/17806]: epoll set max size is 74124963 (in compat_epoll_set_max_size() at compat-epoll.c:337)
|
|
DEBUG3 - 16:17:36.107238395 [17803/17806]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:124)
|
|
DEBUG3 - 16:17:36.110542019 [17803/17803]: Created hashtable size 4 at 0x127e890 of type 1 (in lttng_ht_new() at hashtable.c:145)
|
|
DEBUG3 - 16:17:36.110550796 [17803/17803]: Created hashtable size 4 at 0x127edf0 of type 1 (in lttng_ht_new() at hashtable.c:145)
|
|
DEBUG3 - 16:17:36.110554308 [17803/17803]: Created hashtable size 4 at 0x127f330 of type 1 (in lttng_ht_new() at hashtable.c:145)
|
|
DEBUG3 - 16:17:36.110560263 [17803/17803]: Created hashtable size 4 at 0x127f870 of type 1 (in lttng_ht_new() at hashtable.c:145)
|
|
DEBUG2 - 16:17:36.110567134 [17803/17803]: Creating consumer directory: /var/lib/log/lttng_home/.lttng/ustconsumerd64 (in set_consumer_sockets() at main.c:5306)
|
|
DEBUG2 - 16:17:36.110620726 [17803/17803]: Creating consumer directory: /var/lib/log/lttng_home/.lttng/ustconsumerd32 (in set_consumer_sockets() at main.c:5306)
|
|
DEBUG3 - 16:17:36.110686428 [17803/17803]: Session daemon client socket 18 and application socket 19 created (in init_daemon_socket() at main.c:5133)
|
|
DEBUG3 - 16:17:36.110702184 [17803/17803]: Created hashtable size 4 at 0x127fdb0 of type 2 (in lttng_ht_new() at hashtable.c:145)
|
|
DEBUG3 - 16:17:36.110709204 [17803/17803]: Global buffer per UID registry initialized (in buffer_reg_init_uid_registry() at buffer-registry.c:99)
|
|
DEBUG3 - 16:17:36.110714406 [17803/17803]: Created hashtable size 4 at 0x12802f0 of type 2 (in lttng_ht_new() at hashtable.c:145)
|
|
DEBUG3 - 16:17:36.110716809 [17803/17803]: Global buffer per PID registry initialized (in buffer_reg_init_pid_registry() at buffer-registry.c:228)
|
|
DEBUG1 - 16:17:36.110721788 [17803/17803]: Command subsystem initialized (in cmd_init() at cmd.c:4149)
|
|
DEBUG1 - 16:17:36.110799593 [17803/17803]: Pid 17803 written in file /var/lib/log/lttng_home/.lttng/lttng-sessiond.pid (in utils_create_pid_file() at utils.c:507)
|
|
DEBUG1 - 16:17:36.110822279 [17803/17803]: TCP inet operation timeout set to 180 sec (in lttcomm_inet_init() at inet.c:546)
|
|
DEBUG1 - 16:17:36.110855753 [17803/17808]: [thread] Manage health check started (in thread_manage_health() at main.c:4070)
|
|
DEBUG1 - 16:17:36.110909907 [17803/17808]: Health check ready (in thread_manage_health() at main.c:4132)
|
|
DEBUG1 - 16:17:36.110923318 [17803/17810]: [thread] Manage client started (in thread_manage_clients() at main.c:4261)
|
|
DEBUG1 - 16:17:36.110954171 [17803/17811]: [thread] Dispatch UST command started (in thread_dispatch_ust_registration() at main.c:1757)
|
|
DEBUG1 - 16:17:36.110946836 [17803/17812]: [thread] Manage application registration started (in thread_registration_apps() at main.c:2002)
|
|
DEBUG1 - 16:17:36.110929096 [17803/17809]: [notification-thread] Started notification thread (in thread_notification() at notification-thread.c:482)
|
|
DEBUG1 - 16:17:36.110959609 [17803/17813]: [thread] Manage application started (in thread_manage_apps() at main.c:1443)
|
|
DEBUG1 - 16:17:36.111059553 [17803/17812]: Notifying applications of session daemon state: 1 (in notify_ust_apps() at main.c:661)
|
|
DEBUG1 - 16:17:36.111062674 [17803/17809]: [notification-thread] Creating notification channel UNIX socket at /var/lib/log/lttng_home/.lttng/sessiond-notification (in notification_channel_socket_create() at notification-thread.c:221)
|
|
DEBUG1 - 16:17:36.110994498 [17803/17811]: Futex n to 1 prepare done (in futex_nto1_prepare() at futex.c:77)
|
|
DEBUG1 - 16:17:36.111003021 [17803/17814]: [ust-thread] Manage application notify command (in ust_thread_manage_notify() at ust-thread.c:40)
|
|
DEBUG1 - 16:17:36.111081161 [17803/17816]: [load-session-thread] Load session (in thread_load_session() at load-session-thread.c:91)
|
|
DEBUG1 - 16:17:36.111072042 [17803/17811]: Woken up but nothing in the UST command queue (in thread_dispatch_ust_registration() at main.c:1784)
|
|
DEBUG3 - 16:17:36.111094862 [17803/17814]: [ust-thread] Manage notify polling (in ust_thread_manage_notify() at ust-thread.c:69)
|
|
DEBUG1 - 16:17:36.111072233 [17803/17813]: Apps thread polling (in thread_manage_apps() at main.c:1473)
|
|
DEBUG1 - 16:17:36.111104619 [17803/17809]: [notification-thread] Notification channel UNIX socket created (fd = 31) (in notification_channel_socket_create() at notification-thread.c:248)
|
|
DEBUG1 - 16:17:36.111028802 [17803/17815]: [agent-thread] Manage agent application registration. (in agent_thread_manage_registration() at agent-thread.c:300)
|
|
DEBUG1 - 16:17:36.111117958 [17803/17812]: Got the wait shm fd 33 (in get_wait_shm() at shm.c:115)
|
|
DEBUG3 - 16:17:36.111128288 [17803/17815]: URI string: tcp://localhost (in uri_parse() at uri.c:324)
|
|
DEBUG1 - 16:17:36.111119488 [17803/17809]: [notification-thread] Listening on notification channel socket (in init_thread_state() at notification-thread.c:387)
|
|
DEBUG1 - 16:17:36.111149792 [17803/17812]: Futex wait update active 1 (in futex_wait_update() at futex.c:65)
|
|
DEBUG1 - 16:17:36.111153200 [17803/17812]: Accepting application registration (in thread_registration_apps() at main.c:2039)
|
|
DEBUG1 - 16:17:36.111158230 [17803/17809]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:507)
|
|
DEBUG1 - 16:17:39.312718795 [17803/17812]: UST registration received with pid:17436 ppid:16398 uid:1000 gid:1000 sock:33 name:hello-ust (version 7.2) (in thread_registration_apps() at main.c:2155)
|
|
DEBUG1 - 16:17:39.312737333 [17803/17812]: Futex n to 1 wake done (in futex_nto1_wake() at futex.c:122)
|
|
DEBUG1 - 16:17:39.312740751 [17803/17812]: Accepting application registration (in thread_registration_apps() at main.c:2039)
|
|
DEBUG1 - 16:17:39.312742191 [17803/17811]: Futex n to 1 wait done (in futex_nto1_wait() at futex.c:105)
|
|
DEBUG1 - 16:17:39.312751241 [17803/17811]: Futex n to 1 prepare done (in futex_nto1_prepare() at futex.c:77)
|
|
DEBUG1 - 16:17:39.312767378 [17803/17811]: Dispatching UST registration pid:17436 ppid:16398 uid:1000 gid:1000 sock:33 name:hello-ust (version 7.2) (in thread_dispatch_ust_registration() at main.c:1796)
|
|
DEBUG1 - 16:17:39.312751760 [17803/17812]: UST registration received with pid:17436 ppid:16398 uid:1000 gid:1000 sock:37 name:hello-ust (version 7.2) (in thread_registration_apps() at main.c:2155)
|
|
DEBUG3 - 16:17:39.312776897 [17803/17811]: UST app creating application for socket 33 (in ust_app_create() at ust-app.c:3365)
|
|
DEBUG1 - 16:17:39.312779555 [17803/17812]: Futex n to 1 wake done (in futex_nto1_wake() at futex.c:122)
|
|
DEBUG1 - 16:17:39.312794266 [17803/17812]: Accepting application registration (in thread_registration_apps() at main.c:2039)
|
|
DEBUG3 - 16:17:39.312795625 [17803/17811]: Created hashtable size 4 at 0x1282250 of type 2 (in lttng_ht_new() at hashtable.c:145)
|
|
DEBUG3 - 16:17:39.312802445 [17803/17811]: Created hashtable size 4 at 0x1285510 of type 1 (in lttng_ht_new() at hashtable.c:145)
|
|
DEBUG3 - 16:17:39.312805400 [17803/17811]: Created hashtable size 4 at 0x1285a50 of type 1 (in lttng_ht_new() at hashtable.c:145)
|
|
DEBUG1 - 16:17:39.312818190 [17803/17811]: Dispatching UST registration pid:17436 ppid:16398 uid:1000 gid:1000 sock:37 name:hello-ust (version 7.2) (in thread_dispatch_ust_registration() at main.c:1796)
|
|
DEBUG3 - 16:17:39.312821308 [17803/17811]: UST app notify socket 37 is set (in thread_dispatch_ust_registration() at main.c:1853)
|
|
DEBUG1 - 16:17:39.312835314 [17803/17811]: App registered with pid:17436 ppid:16398 uid:1000 gid:1000 sock:33 name:hello-ust notify_sock:37 (version 7.2) (in ust_app_add() at ust-app.c:3454)
|
|
DEBUG3 - 16:17:39.312894396 [17803/17814]: [ust-thread] Manage notify return from poll on 2 fds (in ust_thread_manage_notify() at ust-thread.c:76)
|
|
DEBUG3 - 16:17:39.312909821 [17803/17814]: UST thread notify added sock 37 to pollset (in ust_thread_manage_notify() at ust-thread.c:137)
|
|
DEBUG1 - 16:17:39.312911308 [17803/17811]: Woken up but nothing in the UST command queue (in thread_dispatch_ust_registration() at main.c:1784)
|
|
DEBUG3 - 16:17:39.312912983 [17803/17814]: [ust-thread] Manage notify polling (in ust_thread_manage_notify() at ust-thread.c:69)
|
|
DEBUG1 - 16:17:39.312915520 [17803/17811]: Futex n to 1 wait done (in futex_nto1_wait() at futex.c:105)
|
|
DEBUG1 - 16:17:39.312918419 [17803/17811]: Futex n to 1 prepare done (in futex_nto1_prepare() at futex.c:77)
|
|
DEBUG1 - 16:17:39.312916038 [17803/17813]: Apps thread return from poll on 2 fds (in thread_manage_apps() at main.c:1480)
|
|
DEBUG1 - 16:17:39.312921854 [17803/17811]: Woken up but nothing in the UST command queue (in thread_dispatch_ust_registration() at main.c:1784)
|
|
DEBUG1 - 16:17:39.312935934 [17803/17813]: Apps with sock 33 added to poll set (in thread_manage_apps() at main.c:1537)
|
|
DEBUG1 - 16:17:39.312939509 [17803/17813]: Apps thread polling (in thread_manage_apps() at main.c:1473)
|
|
DEBUG1 - 16:17:39.355293923 [17803/17812]: UST registration received with pid:12709 ppid:1 uid:1000 gid:1000 sock:38 name:pbs-ust (version 7.2) (in thread_registration_apps() at main.c:2155)
|
|
DEBUG1 - 16:17:39.355304296 [17803/17812]: Futex n to 1 wake done (in futex_nto1_wake() at futex.c:122)
|
|
DEBUG1 - 16:17:39.355307126 [17803/17812]: Accepting application registration (in thread_registration_apps() at main.c:2039)
|
|
DEBUG1 - 16:17:39.355307112 [17803/17811]: Futex n to 1 wait done (in futex_nto1_wait() at futex.c:105)
|
|
DEBUG1 - 16:17:39.355312159 [17803/17811]: Futex n to 1 prepare done (in futex_nto1_prepare() at futex.c:77)
|
|
DEBUG1 - 16:17:39.355314652 [17803/17811]: Dispatching UST registration pid:12709 ppid:1 uid:1000 gid:1000 sock:38 name:pbs-ust (version 7.2) (in thread_dispatch_ust_registration() at main.c:1796)
|
|
DEBUG1 - 16:17:39.355317130 [17803/17812]: UST registration received with pid:12709 ppid:1 uid:1000 gid:1000 sock:39 name:pbs-ust (version 7.2) (in thread_registration_apps() at main.c:2155)
|
|
DEBUG3 - 16:17:39.355317754 [17803/17811]: UST app creating application for socket 38 (in ust_app_create() at ust-app.c:3365)
|
|
DEBUG1 - 16:17:39.355324168 [17803/17812]: Futex n to 1 wake done (in futex_nto1_wake() at futex.c:122)
|
|
DEBUG3 - 16:17:39.355328877 [17803/17811]: Created hashtable size 4 at 0x128b7a0 of type 2 (in lttng_ht_new() at hashtable.c:145)
|
|
DEBUG1 - 16:17:39.355329148 [17803/17812]: Accepting application registration (in thread_registration_apps() at main.c:2039)
|
|
DEBUG3 - 16:17:39.355344071 [17803/17811]: Created hashtable size 4 at 0x128bc50 of type 1 (in lttng_ht_new() at hashtable.c:145)
|
|
DEBUG3 - 16:17:39.355347547 [17803/17811]: Created hashtable size 4 at 0x128c100 of type 1 (in lttng_ht_new() at hashtable.c:145)
|
|
DEBUG1 - 16:17:39.355354838 [17803/17812]: UST registration received with pid:7905 ppid:15383 uid:1000 gid:1000 sock:40 name:mysqld-ust (version 7.2) (in thread_registration_apps() at main.c:2155)
|
|
DEBUG1 - 16:17:39.355356973 [17803/17811]: Dispatching UST registration pid:12709 ppid:1 uid:1000 gid:1000 sock:39 name:pbs-ust (version 7.2) (in thread_dispatch_ust_registration() at main.c:1796)
|
|
DEBUG1 - 16:17:39.355358271 [17803/17812]: Futex n to 1 wake done (in futex_nto1_wake() at futex.c:122)
|
|
DEBUG3 - 16:17:39.355361298 [17803/17811]: UST app notify socket 39 is set (in thread_dispatch_ust_registration() at main.c:1853)
|
|
DEBUG1 - 16:17:39.355363101 [17803/17812]: Accepting application registration (in thread_registration_apps() at main.c:2039)
|
|
DEBUG1 - 16:17:39.355364867 [17803/17811]: App registered with pid:12709 ppid:1 uid:1000 gid:1000 sock:38 name:pbs-ust notify_sock:39 (version 7.2) (in ust_app_add() at ust-app.c:3454)
|
|
DEBUG1 - 16:17:39.355372875 [17803/17812]: UST registration received with pid:7905 ppid:15383 uid:1000 gid:1000 sock:41 name:mysqld-ust (version 7.2) (in thread_registration_apps() at main.c:2155)
|
|
DEBUG1 - 16:17:39.355375970 [17803/17812]: Futex n to 1 wake done (in futex_nto1_wake() at futex.c:122)
|
|
DEBUG1 - 16:17:39.355378124 [17803/17812]: Accepting application registration (in thread_registration_apps() at main.c:2039)
|
|
DEBUG3 - 16:17:39.355413503 [17803/17814]: [ust-thread] Manage notify return from poll on 3 fds (in ust_thread_manage_notify() at ust-thread.c:76)
|
|
DEBUG3 - 16:17:39.355420933 [17803/17814]: UST thread notify added sock 39 to pollset (in ust_thread_manage_notify() at ust-thread.c:137)
|
|
DEBUG3 - 16:17:39.355423592 [17803/17814]: [ust-thread] Manage notify polling (in ust_thread_manage_notify() at ust-thread.c:69)
|
|
DEBUG1 - 16:17:39.355454426 [17803/17811]: Dispatching UST registration pid:7905 ppid:15383 uid:1000 gid:1000 sock:40 name:mysqld-ust (version 7.2) (in thread_dispatch_ust_registration() at main.c:1796)
|
|
DEBUG1 - 16:17:39.355456735 [17803/17813]: Apps thread return from poll on 3 fds (in thread_manage_apps() at main.c:1480)
|
|
DEBUG3 - 16:17:39.355457795 [17803/17811]: UST app creating application for socket 40 (in ust_app_create() at ust-app.c:3365)
|
|
DEBUG1 - 16:17:39.355466389 [17803/17813]: Apps with sock 38 added to poll set (in thread_manage_apps() at main.c:1537)
|
|
DEBUG3 - 16:17:39.355468160 [17803/17811]: Created hashtable size 4 at 0x128c5b0 of type 2 (in lttng_ht_new() at hashtable.c:145)
|
|
DEBUG1 - 16:17:39.355469360 [17803/17813]: Apps thread polling (in thread_manage_apps() at main.c:1473)
|
|
DEBUG3 - 16:17:39.355472819 [17803/17811]: Created hashtable size 4 at 0x128ca60 of type 1 (in lttng_ht_new() at hashtable.c:145)
|
|
DEBUG3 - 16:17:39.355477552 [17803/17811]: Created hashtable size 4 at 0x128cf10 of type 1 (in lttng_ht_new() at hashtable.c:145)
|
|
DEBUG1 - 16:17:39.355486101 [17803/17811]: Dispatching UST registration pid:7905 ppid:15383 uid:1000 gid:1000 sock:41 name:mysqld-ust (version 7.2) (in thread_dispatch_ust_registration() at main.c:1796)
|
|
DEBUG3 - 16:17:39.355488753 [17803/17811]: UST app notify socket 41 is set (in thread_dispatch_ust_registration() at main.c:1853)
|
|
DEBUG1 - 16:17:39.355491558 [17803/17811]: App registered with pid:7905 ppid:15383 uid:1000 gid:1000 sock:40 name:mysqld-ust notify_sock:41 (version 7.2) (in ust_app_add() at ust-app.c:3454)
|
|
DEBUG3 - 16:17:39.355517672 [17803/17814]: [ust-thread] Manage notify return from poll on 4 fds (in ust_thread_manage_notify() at ust-thread.c:76)
|
|
DEBUG3 - 16:17:39.355523630 [17803/17814]: UST thread notify added sock 41 to pollset (in ust_thread_manage_notify() at ust-thread.c:137)
|
|
DEBUG3 - 16:17:39.355525960 [17803/17814]: [ust-thread] Manage notify polling (in ust_thread_manage_notify() at ust-thread.c:69)
|
|
DEBUG1 - 16:17:39.355532153 [17803/17811]: Woken up but nothing in the UST command queue (in thread_dispatch_ust_registration() at main.c:1784)
|
|
DEBUG1 - 16:17:39.355533842 [17803/17813]: Apps thread return from poll on 4 fds (in thread_manage_apps() at main.c:1480)
|
|
DEBUG1 - 16:17:39.355535136 [17803/17811]: Futex n to 1 wait done (in futex_nto1_wait() at futex.c:105)
|
|
DEBUG1 - 16:17:39.355540067 [17803/17811]: Futex n to 1 prepare done (in futex_nto1_prepare() at futex.c:77)
|
|
DEBUG1 - 16:17:39.355540186 [17803/17813]: Apps with sock 40 added to poll set (in thread_manage_apps() at main.c:1537)
|
|
DEBUG1 - 16:17:39.355543460 [17803/17811]: Woken up but nothing in the UST command queue (in thread_dispatch_ust_registration() at main.c:1784)
|
|
DEBUG1 - 16:17:39.355545069 [17803/17813]: Apps thread polling (in thread_manage_apps() at main.c:1473)
|
|
DEBUG2 - 16:18:06.141450397 [17803/17815]: IP address resolved to 127.0.0.1 (in set_ip_address() at uri.c:165)
|
|
DEBUG3 - 16:18:06.141466604 [17803/17815]: URI dtype: 1, proto: 1, host: localhost, subdir: , ctrl: 0, data: 0 (in uri_parse() at uri.c:538)
|
|
DEBUG3 - 16:18:06.141482507 [17803/17815]: [agent-thread] Trying to bind on port 5345 (in init_tcp_socket() at agent-thread.c:118)
|
|
DEBUG1 - 16:18:06.141493250 [17803/17815]: [agent-thread] Listening on TCP port 5345 and socket 36 (in init_tcp_socket() at agent-thread.c:155)
|
|
DEBUG1 - 16:18:06.141593223 [17803/17815]: Pid 5345 written in file /var/lib/log/lttng_home/.lttng/agent.port (in utils_create_pid_file() at utils.c:507)
|
|
DEBUG3 - 16:18:06.141602677 [17803/17815]: [agent-thread] Manage agent polling (in agent_thread_manage_registration() at agent-thread.c:348)
|
|
DEBUG1 - 16:18:06.142188229 [17803/17810]: Accepting client command ... (in thread_manage_clients() at main.c:4337)
|
|
DEBUG1 - 16:18:38.213241643 [17803/17810]: Wait for client response (in thread_manage_clients() at main.c:4389)
|
|
DEBUG1 - 16:18:38.213285433 [17803/17810]: Receiving data from client ... (in thread_manage_clients() at main.c:4434)
|
|
DEBUG1 - 16:18:38.213291763 [17803/17810]: Nothing recv() from client... continuing (in thread_manage_clients() at main.c:4438)
|
|
DEBUG1 - 16:18:38.213300265 [17803/17810]: Clean command context structure (in clean_command_ctx() at main.c:641)
|
|
DEBUG1 - 16:18:38.213304530 [17803/17810]: Accepting client command ... (in thread_manage_clients() at main.c:4337)
|
|
DEBUG1 - 16:18:38.213330034 [17803/17810]: Wait for client response (in thread_manage_clients() at main.c:4389)
|
|
DEBUG1 - 16:18:38.213339809 [17803/17810]: Receiving data from client ... (in thread_manage_clients() at main.c:4434)
|
|
DEBUG1 - 16:18:38.213357242 [17803/17810]: Processing client command 8 (in process_client_msg() at main.c:2877)
|
|
DEBUG1 - 16:18:38.213368703 [17803/17810]: Waiting for 1 URIs from client ... (in process_client_msg() at main.c:3660)
|
|
DEBUG2 - 16:18:38.213377521 [17803/17810]: Trying to find session by name auto-20200114-161838 (in session_find_by_name() at session.c:276)
|
|
DEBUG3 - 16:18:38.213403946 [17803/17810]: Created hashtable size 4 at 0x1291940 of type 1 (in lttng_ht_new() at hashtable.c:145)
|
|
DEBUG1 - 16:18:38.213408423 [17803/17810]: Allocating ltt_sessions_ht_by_id (in ltt_sessions_ht_alloc() at session.c:153)
|
|
DEBUG3 - 16:18:38.213414099 [17803/17810]: Created hashtable size 4 at 0x1291df0 of type 2 (in lttng_ht_new() at hashtable.c:145)
|
|
DEBUG1 - 16:18:38.213417805 [17803/17810]: Tracing session auto-20200114-161838 created with ID 0 by UID 1000 GID 1000 (in session_create() at session.c:420)
|
|
DEBUG2 - 16:18:38.213420739 [17803/17810]: Trying to find session by name auto-20200114-161838 (in session_find_by_name() at session.c:276)
|
|
DEBUG3 - 16:18:38.213438584 [17803/17810]: Created hashtable size 4 at 0x1297310 of type 1 (in lttng_ht_new() at hashtable.c:145)
|
|
DEBUG2 - 16:18:38.213442365 [17803/17810]: Setting trace directory path from URI to /var/lib/log/lttng_home/lttng-traces/auto-20200114-161838 (in add_uri_to_consumer() at cmd.c:787)
|
|
DEBUG1 - 16:18:38.213452104 [17803/17810]: Sending response (size: 20, retcode: Success (10)) (in thread_manage_clients() at main.c:4484)
|
|
DEBUG1 - 16:18:38.213463357 [17803/17810]: Clean command context structure (in clean_command_ctx() at main.c:641)
|
|
DEBUG1 - 16:18:38.213465911 [17803/17810]: Accepting client command ... (in thread_manage_clients() at main.c:4337)
|
|
DEBUG1 - 16:18:58.666145912 [17803/17810]: Wait for client response (in thread_manage_clients() at main.c:4389)
|
|
DEBUG1 - 16:18:58.666172602 [17803/17810]: Receiving data from client ... (in thread_manage_clients() at main.c:4434)
|
|
DEBUG1 - 16:18:58.666181541 [17803/17810]: Processing client command 6 (in process_client_msg() at main.c:2877)
|
|
DEBUG1 - 16:18:58.666185315 [17803/17810]: Getting session auto-20200114-161838 by name (in process_client_msg() at main.c:2970)
|
|
DEBUG2 - 16:18:58.666188526 [17803/17810]: Trying to find session by name auto-20200114-161838 (in session_find_by_name() at session.c:276)
|
|
DEBUG1 - 16:18:58.666192317 [17803/17810]: Creating UST session (in create_ust_session() at main.c:2748)
|
|
DEBUG3 - 16:18:58.666207010 [17803/17810]: Created hashtable size 4 at 0x12832a0 of type 0 (in lttng_ht_new() at hashtable.c:145)
|
|
DEBUG3 - 16:18:58.666211527 [17803/17810]: Created hashtable size 4 at 0x12837e0 of type 2 (in lttng_ht_new() at hashtable.c:145)
|
|
DEBUG3 - 16:18:58.666228761 [17803/17810]: Created hashtable size 4 at 0x1283d20 of type 1 (in lttng_ht_new() at hashtable.c:145)
|
|
DEBUG2 - 16:18:58.666231470 [17803/17810]: UST trace session create successful (in trace_ust_create_session() at trace-ust.c:320)
|
|
DEBUG3 - 16:18:58.666236562 [17803/17810]: Copying tracing session consumer output in UST session (in copy_session_consumer() at main.c:2695)
|
|
DEBUG3 - 16:18:58.666257174 [17803/17810]: Created hashtable size 4 at 0x1284260 of type 1 (in lttng_ht_new() at hashtable.c:145)
|
|
DEBUG3 - 16:18:58.666256477 [17803/17806]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:128)
|
|
DEBUG3 - 16:18:58.666280008 [17803/17810]: Copy session consumer subdir /ust (in copy_session_consumer() at main.c:2713)
|
|
DEBUG1 - 16:18:58.666285145 [17803/17810]: Spawning consumerd (in spawn_consumerd() at main.c:2379)
|
|
DEBUG2 - 16:18:58.666488805 [17803/17810]: Consumer pid 19216 (in start_consumerd() at main.c:2556)
|
|
DEBUG2 - 16:18:58.666503174 [17803/17810]: Spawning consumer control thread (in start_consumerd() at main.c:2559)
|
|
DEBUG1 - 16:18:58.666546701 [17803/19217]: [thread] Manage consumer started (in thread_manage_consumer() at main.c:1085)
|
|
DEBUG1 - 16:18:58.666621953 [19216/19216]: Using 64-bit UST consumer at: /usr/lib64/lttng/libexec/lttng-consumerd (in spawn_consumerd() at main.c:2457)
|
|
DEBUG1 - 16:18:58.667645854 [19216/19216]: Health check time delta in seconds set to 20 (in health_init() at health.c:73)
|
|
DEBUG1 - 16:18:58.671635758 [19216/19216]: TCP inet operation timeout set to 180 sec (in lttcomm_inet_init() at inet.c:546)
|
|
DEBUG1 - 16:18:58.671766220 [19219/19219]: Resetting run_as worker signal handlers to default (in reset_sighandler() at runas.c:536)
|
|
DEBUG1 - 16:18:58.671851045 [19219/19219]: run_as signal handler set for SIGTERM and SIGINT (in set_worker_sighandlers() at runas.c:597)
|
|
DEBUG1 - 16:18:58.671918949 [19216/19216]: Connecting to error socket /var/lib/log/lttng_home/.lttng/ustconsumerd64/error (in main() at lttng-consumerd.c:464)
|
|
DEBUG2 - 16:18:58.671957182 [17803/19217]: Receiving code from consumer err_sock (in thread_manage_consumer() at main.c:1183)
|
|
DEBUG1 - 16:18:58.671999505 [19216/19220]: [thread] Manage health check started (in thread_manage_health() at health-consumerd.c:167)
|
|
DEBUG1 - 16:18:58.672083073 [19216/19220]: epoll set max size is 74124963 (in compat_epoll_set_max_size() at compat-epoll.c:337)
|
|
DEBUG1 - 16:18:58.672098606 [19216/19220]: Health check ready (in thread_manage_health() at health-consumerd.c:240)
|
|
DEBUG3 - 16:18:58.676366836 [17803/17806]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:124)
|
|
DEBUG1 - 16:18:58.772105324 [19216/19222]: Thread channel poll started (in consumer_thread_channel_poll() at consumer.c:2855)
|
|
DEBUG1 - 16:18:58.772124467 [19216/19223]: Thread metadata poll started (in consumer_thread_metadata_poll() at consumer.c:2259)
|
|
DEBUG1 - 16:18:58.772158457 [19216/19224]: Updating poll fd array (in update_poll_array() at consumer.c:1091)
|
|
DEBUG1 - 16:18:58.772170559 [19216/19223]: Metadata main loop started (in consumer_thread_metadata_poll() at consumer.c:2275)
|
|
DEBUG1 - 16:18:58.772173826 [19216/19224]: polling on 2 fd (in consumer_thread_data_poll() at consumer.c:2544)
|
|
DEBUG1 - 16:18:58.772132719 [19216/19222]: Channel main loop started (in consumer_thread_channel_poll() at consumer.c:2870)
|
|
DEBUG1 - 16:18:58.772188088 [19216/19225]: Creating command socket /var/lib/log/lttng_home/.lttng/ustconsumerd64/command (in consumer_thread_sessiond_poll() at consumer.c:3123)
|
|
DEBUG1 - 16:18:58.772193947 [19216/19222]: Channel poll wait (in consumer_thread_channel_poll() at consumer.c:2875)
|
|
DEBUG1 - 16:18:58.772176604 [19216/19223]: Metadata poll wait (in consumer_thread_metadata_poll() at consumer.c:2281)
|
|
DEBUG1 - 16:18:58.772235101 [19216/19225]: Sending ready command to lttng-sessiond (in consumer_thread_sessiond_poll() at consumer.c:3136)
|
|
DEBUG1 - 16:18:58.772263066 [19216/19225]: Connection on client_socket (in consumer_thread_sessiond_poll() at consumer.c:3158)
|
|
DEBUG1 - 16:18:58.772266171 [17803/19217]: Consumer command socket ready (fd: 45 (in thread_manage_consumer() at main.c:1223)
|
|
DEBUG1 - 16:18:58.772271077 [19216/19225]: Metadata connection on client_socket (in set_metadata_socket() at consumer.c:3084)
|
|
DEBUG1 - 16:18:58.772272352 [17803/19217]: Consumer metadata socket ready (fd: 46) (in thread_manage_consumer() at main.c:1225)
|
|
DEBUG3 - 16:18:58.772287037 [17803/19217]: Sending set_channel_monitor_pipe command to consumer (in consumer_send_channel_monitor_pipe() at consumer.c:1078)
|
|
DEBUG1 - 16:18:58.772304786 [19216/19225]: Incoming command on sock (in consumer_thread_sessiond_poll() at consumer.c:3204)
|
|
DEBUG3 - 16:18:58.772329880 [17803/19217]: Sending channel monitoring pipe 14 to consumer on socket 45 (in consumer_send_channel_monitor_pipe() at consumer.c:1085)
|
|
DEBUG1 - 16:18:58.772353148 [19216/19225]: Received channel monitor pipe (27) (in lttng_ustconsumer_recv_cmd() at ust-consumer.c:1899)
|
|
DEBUG1 - 16:18:58.772364341 [19216/19225]: Channel monitor pipe set as non-blocking (in lttng_ustconsumer_recv_cmd() at ust-consumer.c:1920)
|
|
DEBUG1 - 16:18:58.772369361 [19216/19225]: received command on sock (in consumer_thread_sessiond_poll() at consumer.c:3220)
|
|
DEBUG2 - 16:18:58.772371754 [17803/19217]: Channel monitoring pipe successfully sent (in consumer_send_channel_monitor_pipe() at consumer.c:1091)
|
|
DEBUG3 - 16:18:58.772412085 [17803/17810]: Consumer socket created (fd: 45) and added to output (in consumer_create_socket() at consumer.c:301)
|
|
DEBUG1 - 16:18:58.772421222 [17803/17810]: Setting relayd for session auto-20200114-161838 (in cmd_setup_relayd() at cmd.c:1043)
|
|
DEBUG1 - 16:18:58.772427244 [17803/17810]: Enable event command for event 'hello_world:my_first_tracepoint' (in _cmd_enable_event() at cmd.c:1864)
|
|
DEBUG2 - 16:18:58.772431344 [17803/17810]: Trace UST channel channel0 not found by name (in trace_ust_find_channel_by_name() at trace-ust.c:196)
|
|
DEBUG1 - 16:18:58.772439454 [17803/17810]: Enabling channel for session auto-20200114-161838 (in cmd_enable_channel() at cmd.c:1346)
|
|
DEBUG2 - 16:18:58.772442251 [17803/17810]: Trace UST channel channel0 not found by name (in trace_ust_find_channel_by_name() at trace-ust.c:196)
|
|
DEBUG3 - 16:18:58.772446726 [17803/17810]: Created hashtable size 4 at 0x1284d80 of type 0 (in lttng_ht_new() at hashtable.c:145)
|
|
DEBUG3 - 16:18:58.772451277 [17803/17810]: Created hashtable size 4 at 0x129ea00 of type 1 (in lttng_ht_new() at hashtable.c:145)
|
|
DEBUG2 - 16:18:58.772453713 [17803/17810]: Trace UST channel channel0 created (in trace_ust_create_channel() at trace-ust.c:395)
|
|
DEBUG2 - 16:18:58.772457121 [17803/17810]: Channel channel0 is being created for UST with buffer 1 and id 0 (in channel_ust_create() at channel.c:455)
|
|
DEBUG2 - 16:18:58.772461671 [17803/17810]: UST app adding channel channel0 to UST domain for session id 0 (in ust_app_create_channel_glb() at ust-app.c:4144)
|
|
DEBUG2 - 16:18:58.772469667 [17803/17810]: UST app pid: 12709 session id 0 not found, creating it (in create_ust_app_session() at ust-app.c:2172)
|
|
DEBUG3 - 16:18:58.772486972 [17803/17810]: Created hashtable size 4 at 0x12a1fe0 of type 0 (in lttng_ht_new() at hashtable.c:145)
|
|
DEBUG2 - 16:18:58.772504938 [17803/17810]: Shadow copy of session handle -1 (in shadow_copy_session() at ust-app.c:1870)
|
|
DEBUG3 - 16:18:58.772513991 [17803/17810]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.c:203)
|
|
DEBUG3 - 16:18:58.772523669 [17803/17810]: Created hashtable size 4 at 0x12a44f0 of type 2 (in lttng_ht_new() at hashtable.c:145)
|
|
DEBUG3 - 16:18:58.772526171 [17803/17810]: Buffer registry per UID created id: 0, ABI: 64, uid: 1000, domain: 2 (in buffer_reg_uid_create() at buffer-registry.c:152)
|
|
DEBUG3 - 16:18:58.772537218 [17803/17810]: Created hashtable size 4 at 0x12a7ac0 of type 0 (in lttng_ht_new() at hashtable.c:145)
|
|
DEBUG3 - 16:18:58.772542326 [17803/17810]: Created hashtable size 4 at 0x12a8000 of type 2 (in lttng_ht_new() at hashtable.c:145)
|
|
DEBUG3 - 16:18:58.772582579 [17803/17810]: Append to metadata: "/* CTF 1.8 */
|
|
|
|
" (in lttng_metadata_printf() at ust-metadata.c:178)
|
|
DEBUG3 - 16:18:58.772590748 [17803/17810]: Append to metadata: "typealias integer { size = 8; align = 8; signed = false; } := uint8_t;
|
|
typealias integer { size = 16; align = 8; signed = false; } := uint16_t;
|
|
typealias integer { size = 32; align = 8; signed = false; } := uint32_t;
|
|
typealias integer { size = 64; align = 8; signed = false; } := uint64_t;
|
|
typealias integer { size = 64; align = 8; signed = false; } := unsigned long;
|
|
typealias integer { size = 5; align = 1; signed = false; } := uint5_t;
|
|
typealias integer { size = 27; align = 1; signed = false; } := uint27_t;
|
|
|
|
trace {
|
|
major = 1;
|
|
minor = 8;
|
|
uuid = "80c2cf72-d481-4dc2-9a14-e62b29f73213";
|
|
byte_order = le;
|
|
packet.header := struct {
|
|
uint32_t magic;
|
|
uint8_t uuid[16];
|
|
uint32_t stream_id;
|
|
uint64_t stream_instance_id;
|
|
};
|
|
};
|
|
|
|
" (in lttng_metadata_printf() at ust-metadata.c:178)
|
|
DEBUG3 - 16:18:58.772597229 [17803/17810]: Append to metadata: "env {
|
|
hostname = "localhost.localdomain";
|
|
domain = "ust";
|
|
tracer_name = "lttng-ust";
|
|
tracer_major = 2;
|
|
tracer_minor = 10;
|
|
" (in lttng_metadata_printf() at ust-metadata.c:178)
|
|
DEBUG3 - 16:18:58.772600362 [17803/17810]: Append to metadata: "};
|
|
|
|
" (in lttng_metadata_printf() at ust-metadata.c:178)
|
|
DEBUG3 - 16:18:58.772603218 [17803/17810]: Append to metadata: "clock {
|
|
name = "monotonic";
|
|
" (in lttng_metadata_printf() at ust-metadata.c:178)
|
|
DEBUG3 - 16:18:58.772624614 [17803/17810]: Append to metadata: " uuid = "86ee69d8-dedc-429a-a5ee-5ffa3686ad13";
|
|
" (in lttng_metadata_printf() at ust-metadata.c:178)
|
|
DEBUG3 - 16:18:58.772630391 [17803/17810]: Append to metadata: " description = "Monotonic Clock";
|
|
freq = 1000000000; /* Frequency, in Hz */
|
|
/* clock value offset from Epoch is: offset * (1/freq) */
|
|
offset = 1576467154520961239;
|
|
};
|
|
|
|
" (in lttng_metadata_printf() at ust-metadata.c:178)
|
|
DEBUG3 - 16:18:58.772635336 [17803/17810]: Append to metadata: "typealias integer {
|
|
size = 27; align = 1; signed = false;
|
|
map = clock.monotonic.value;
|
|
} := uint27_clock_monotonic_t;
|
|
|
|
typealias integer {
|
|
size = 32; align = 8; signed = false;
|
|
map = clock.monotonic.value;
|
|
} := uint32_clock_monotonic_t;
|
|
|
|
typealias integer {
|
|
size = 64; align = 8; signed = false;
|
|
map = clock.monotonic.value;
|
|
} := uint64_clock_monotonic_t;
|
|
|
|
" (in lttng_metadata_printf() at ust-metadata.c:178)
|
|
DEBUG3 - 16:18:58.772639347 [17803/17810]: Append to metadata: "struct packet_context {
|
|
uint64_clock_monotonic_t timestamp_begin;
|
|
uint64_clock_monotonic_t timestamp_end;
|
|
uint64_t content_size;
|
|
uint64_t packet_size;
|
|
uint64_t packet_seq_num;
|
|
unsigned long events_discarded;
|
|
uint32_t cpu_id;
|
|
};
|
|
|
|
" (in lttng_metadata_printf() at ust-metadata.c:178)
|
|
DEBUG3 - 16:18:58.772645604 [17803/17810]: Append to metadata: "struct event_header_compact {
|
|
enum : uint5_t { compact = 0 ... 30, extended = 31 } id;
|
|
variant <id> {
|
|
struct {
|
|
uint27_clock_monotonic_t timestamp;
|
|
} compact;
|
|
struct {
|
|
uint32_t id;
|
|
uint64_clock_monotonic_t timestamp;
|
|
} extended;
|
|
} v;
|
|
} align(8);
|
|
|
|
struct event_header_large {
|
|
enum : uint16_t { compact = 0 ... 65534, extended = 65535 } id;
|
|
variant <id> {
|
|
struct {
|
|
uint32_clock_monotonic_t timestamp;
|
|
} compact;
|
|
struct {
|
|
uint32_t id;
|
|
uint64_clock_monotonic_t timestamp;
|
|
} extended;
|
|
} v;
|
|
} align(8);
|
|
|
|
" (in lttng_metadata_printf() at ust-metadata.c:178)
|
|
DEBUG3 - 16:18:58.772649410 [17803/17810]: Buffer registry per UID adding to global registry with id: 0 (in buffer_reg_uid_add() at buffer-registry.c:174)
|
|
DEBUG3 - 16:18:58.772652294 [17803/17810]: UST app buffer registry per UID created successfully (in setup_buffer_reg_uid() at ust-app.c:2135)
|
|
DEBUG2 - 16:18:58.772763324 [17803/17810]: UST app session created successfully with handle 4 (in create_ust_app_session() at ust-app.c:2247)
|
|
DEBUG3 - 16:18:58.772769027 [17803/17810]: Created hashtable size 4 at 0x12a8770 of type 1 (in lttng_ht_new() at hashtable.c:145)
|
|
DEBUG3 - 16:18:58.772771872 [17803/17810]: Created hashtable size 4 at 0x12a8cb0 of type 0 (in lttng_ht_new() at hashtable.c:145)
|
|
DEBUG3 - 16:18:58.772774206 [17803/17810]: UST app channel channel0 allocated (in alloc_ust_app_channel() at ust-app.c:1049)
|
|
DEBUG2 - 16:18:58.772776853 [17803/17810]: UST app shadow copy of channel channel0 started (in shadow_copy_channel() at ust-app.c:1792)
|
|
DEBUG3 - 16:18:58.772779564 [17803/17810]: UST app shadow copy of channel channel0 done (in shadow_copy_channel() at ust-app.c:1846)
|
|
DEBUG1 - 16:18:58.772783467 [17803/17810]: UST app creating channel channel0 with per UID buffers (in create_channel_per_uid() at ust-app.c:2864)
|
|
DEBUG3 - 16:18:58.772786159 [17803/17810]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.c:203)
|
|
DEBUG2 - 16:18:58.772789314 [17803/17810]: UST app creating buffer registry channel for channel0 (in create_buffer_reg_channel() at ust-app.c:2708)
|
|
DEBUG3 - 16:18:58.772791910 [17803/17810]: Buffer registry channel create with key: 0 (in buffer_reg_channel_create() at buffer-registry.c:380)
|
|
DEBUG3 - 16:18:58.772796183 [17803/17810]: Created hashtable size 4 at 0x12aa330 of type 0 (in lttng_ht_new() at hashtable.c:145)
|
|
DEBUG3 - 16:18:58.772802135 [17803/17810]: Session 0 found by id. (in session_find_by_id() at session.c:312)
|
|
DEBUG2 - 16:18:58.772808039 [17803/17810]: Asking UST consumer for channel (in ask_channel_creation() at ust-consumer.c:121)
|
|
DEBUG3 - 16:18:58.772817078 [17803/17810]: mkdir() recursive /var/lib/log/lttng_home/lttng-traces/auto-20200114-161838/ust/uid/1000/64-bit with mode 504 for uid 1000 and gid 1000 (in run_as_mkdir_recursive() at runas.c:470)
|
|
DEBUG1 - 16:18:58.772825971 [17803/17810]: Using run_as worker (in run_as() at runas.c:450)
|
|
DEBUG3 - 16:18:58.772997254 [17803/17810]: UST registry channel finding key 0 (in ust_registry_channel_find() at ust-registry.c:796)
|
|
DEBUG1 - 16:18:58.773009765 [19216/19225]: Incoming command on sock (in consumer_thread_sessiond_poll() at consumer.c:3204)
|
|
DEBUG1 - 16:18:58.773026317 [19216/19225]: Allocated channel (key 1) (in consumer_allocate_channel() at consumer.c:1031)
|
|
DEBUG1 - 16:18:58.779662531 [19216/19225]: Using run_as worker (in run_as() at runas.c:450)
|
|
DEBUG1 - 16:18:58.779739270 [19216/19225]: Using run_as worker (in run_as() at runas.c:450)
|
|
DEBUG1 - 16:18:58.779800999 [19216/19225]: Using run_as worker (in run_as() at runas.c:450)
|
|
DEBUG1 - 16:18:58.779836276 [19216/19225]: utils_unlink_stream_file /var/lib/log/lttng_home/lttng-traces/auto-20200114-161838/ust/uid/1000/64-bit/index/channel0_0.idx returns -1 (in utils_unlink_stream_file() at utils.c:830)
|
|
DEBUG1 - 16:18:58.779845576 [19216/19225]: Using run_as worker (in run_as() at runas.c:450)
|
|
DEBUG1 - 16:18:58.779887415 [19216/19225]: UST consumer add stream channel0_0 (key: 38) with relayd id 0 (in create_ust_streams() at ust-consumer.c:347)
|
|
DEBUG1 - 16:18:58.779896404 [19216/19225]: Using run_as worker (in run_as() at runas.c:450)
|
|
DEBUG1 - 16:18:58.779928122 [19216/19225]: Using run_as worker (in run_as() at runas.c:450)
|
|
DEBUG1 - 16:18:58.779954357 [19216/19225]: Using run_as worker (in run_as() at runas.c:450)
|
|
DEBUG1 - 16:18:58.779983374 [19216/19225]: utils_unlink_stream_file /var/lib/log/lttng_home/lttng-traces/auto-20200114-161838/ust/uid/1000/64-bit/index/channel0_1.idx returns -1 (in utils_unlink_stream_file() at utils.c:830)
|
|
DEBUG1 - 16:18:58.779991620 [19216/19225]: Using run_as worker (in run_as() at runas.c:450)
|
|
DEBUG1 - 16:18:58.780022268 [19216/19225]: UST consumer add stream channel0_1 (key: 40) with relayd id 0 (in create_ust_streams() at ust-consumer.c:347)
|
|
DEBUG1 - 16:18:58.780030537 [19216/19225]: Using run_as worker (in run_as() at runas.c:450)
|
|
DEBUG1 - 16:18:58.780062266 [19216/19225]: Using run_as worker (in run_as() at runas.c:450)
|
|
DEBUG1 - 16:18:58.780088701 [19216/19225]: Using run_as worker (in run_as() at runas.c:450)
|
|
DEBUG1 - 16:18:58.780111591 [19216/19225]: utils_unlink_stream_file /var/lib/log/lttng_home/lttng-traces/auto-20200114-161838/ust/uid/1000/64-bit/index/channel0_2.idx returns -1 (in utils_unlink_stream_file() at utils.c:830)
|
|
DEBUG1 - 16:18:58.780119568 [19216/19225]: Using run_as worker (in run_as() at runas.c:450)
|
|
DEBUG1 - 16:18:58.780152724 [19216/19225]: UST consumer add stream channel0_2 (key: 42) with relayd id 0 (in create_ust_streams() at ust-consumer.c:347)
|
|
DEBUG1 - 16:18:58.780160414 [19216/19225]: Using run_as worker (in run_as() at runas.c:450)
|
|
DEBUG1 - 16:18:58.780192420 [19216/19225]: Using run_as worker (in run_as() at runas.c:450)
|
|
DEBUG1 - 16:18:58.780218499 [19216/19225]: Using run_as worker (in run_as() at runas.c:450)
|
|
DEBUG1 - 16:18:58.780241514 [19216/19225]: utils_unlink_stream_file /var/lib/log/lttng_home/lttng-traces/auto-20200114-161838/ust/uid/1000/64-bit/index/channel0_3.idx returns -1 (in utils_unlink_stream_file() at utils.c:830)
|
|
DEBUG1 - 16:18:58.780249278 [19216/19225]: Using run_as worker (in run_as() at runas.c:450)
|
|
DEBUG1 - 16:18:58.780281499 [19216/19225]: UST consumer add stream channel0_3 (key: 44) with relayd id 0 (in create_ust_streams() at ust-consumer.c:347)
|
|
DEBUG1 - 16:18:58.780304235 [19216/19225]: UST consumer channel added (key: 1) (in add_channel() at ust-consumer.c:115)
|
|
DEBUG1 - 16:18:58.780308498 [19216/19222]: Channel poll return from wait with 1 fd(s) (in consumer_thread_channel_poll() at consumer.c:2879)
|
|
DEBUG2 - 16:18:58.780315283 [17803/17810]: UST ask channel 1 successfully done with 4 stream(s) (in ask_channel_creation() at ust-consumer.c:218)
|
|
DEBUG1 - 16:18:58.780316766 [19216/19222]: Channel event caught in thread (in consumer_thread_channel_poll() at consumer.c:2881)
|
|
DEBUG1 - 16:18:58.780311245 [19216/19225]: received command on sock (in consumer_thread_sessiond_poll() at consumer.c:3220)
|
|
DEBUG1 - 16:18:58.780324454 [19216/19222]: Adding channel 35 to poll set (in consumer_thread_channel_poll() at consumer.c:2924)
|
|
DEBUG1 - 16:18:58.780328043 [19216/19225]: Incoming command on sock (in consumer_thread_sessiond_poll() at consumer.c:3204)
|
|
DEBUG1 - 16:18:58.780330517 [19216/19222]: Channel poll wait (in consumer_thread_channel_poll() at consumer.c:2875)
|
|
DEBUG1 - 16:18:58.780336016 [19216/19225]: UST consumer sending channel channel0 to sessiond (in send_sessiond_channel() at ust-consumer.c:562)
|
|
DEBUG1 - 16:18:58.780356732 [19216/19225]: UST consumer sending stream 38 to sessiond (in send_sessiond_stream() at ust-consumer.c:533)
|
|
DEBUG1 - 16:18:58.780373301 [19216/19225]: UST consumer sending stream 40 to sessiond (in send_sessiond_stream() at ust-consumer.c:533)
|
|
DEBUG2 - 16:18:58.780375782 [17803/17810]: UST app stream 1 received successfully (in ust_consumer_get_channel() at ust-consumer.c:339)
|
|
DEBUG1 - 16:18:58.780380111 [19216/19225]: UST consumer sending stream 42 to sessiond (in send_sessiond_stream() at ust-consumer.c:533)
|
|
DEBUG1 - 16:18:58.780386938 [19216/19225]: UST consumer sending stream 44 to sessiond (in send_sessiond_stream() at ust-consumer.c:533)
|
|
DEBUG2 - 16:18:58.780388004 [17803/17810]: UST app stream 2 received successfully (in ust_consumer_get_channel() at ust-consumer.c:339)
|
|
DEBUG1 - 16:18:58.780394068 [19216/19225]: UST consumer NULL stream sent to sessiond (in send_sessiond_channel() at ust-consumer.c:626)
|
|
DEBUG2 - 16:18:58.780397112 [17803/17810]: UST app stream 3 received successfully (in ust_consumer_get_channel() at ust-consumer.c:339)
|
|
DEBUG2 - 16:18:58.780405310 [17803/17810]: UST app stream 4 received successfully (in ust_consumer_get_channel() at ust-consumer.c:339)
|
|
DEBUG1 - 16:18:58.780411204 [19216/19225]: received command on sock (in consumer_thread_sessiond_poll() at consumer.c:3220)
|
|
DEBUG3 - 16:18:58.780414398 [17803/17810]: UST app consumer has no more stream available (in ust_consumer_get_channel() at ust-consumer.c:323)
|
|
DEBUG1 - 16:18:58.780411016 [19216/19224]: poll num_rdy : 1 (in consumer_thread_data_poll() at consumer.c:2551)
|
|
DEBUG2 - 16:18:58.780418631 [17803/17810]: UST app setup buffer registry channel for channel0 (in setup_buffer_reg_channel() at ust-app.c:2758)
|
|
DEBUG2 - 16:18:58.780421379 [17803/17810]: UST app setup buffer registry stream (in setup_buffer_reg_streams() at ust-app.c:2663)
|
|
DEBUG1 - 16:18:58.780421031 [19216/19224]: consumer_data_pipe wake up (in consumer_thread_data_poll() at consumer.c:2581)
|
|
DEBUG3 - 16:18:58.780423800 [17803/17810]: Buffer registry creating stream (in buffer_reg_stream_create() at buffer-registry.c:410)
|
|
DEBUG3 - 16:18:58.780427179 [17803/17810]: Buffer registry creating stream (in buffer_reg_stream_create() at buffer-registry.c:410)
|
|
DEBUG1 - 16:18:58.780426948 [19216/19224]: Updating poll fd array (in update_poll_array() at consumer.c:1091)
|
|
DEBUG3 - 16:18:58.780429595 [17803/17810]: Buffer registry creating stream (in buffer_reg_stream_create() at buffer-registry.c:410)
|
|
DEBUG3 - 16:18:58.780432113 [17803/17810]: Buffer registry creating stream (in buffer_reg_stream_create() at buffer-registry.c:410)
|
|
DEBUG1 - 16:18:58.780432408 [19216/19224]: polling on 6 fd (in consumer_thread_data_poll() at consumer.c:2544)
|
|
DEBUG3 - 16:18:58.780434557 [17803/17810]: UST registry channel finding key 0 (in ust_registry_channel_find() at ust-registry.c:796)
|
|
DEBUG1 - 16:18:58.780437090 [19216/19224]: poll num_rdy : 1 (in consumer_thread_data_poll() at consumer.c:2551)
|
|
DEBUG3 - 16:18:58.780437259 [17803/17810]: Session 0 found by id. (in session_find_by_id() at session.c:312)
|
|
DEBUG1 - 16:18:58.780439665 [19216/19224]: consumer_data_pipe wake up (in consumer_thread_data_poll() at consumer.c:2581)
|
|
DEBUG1 - 16:18:58.780442729 [19216/19224]: polling on 6 fd (in consumer_thread_data_poll() at consumer.c:2544)
|
|
DEBUG1 - 16:18:58.780446003 [19216/19224]: poll num_rdy : 1 (in consumer_thread_data_poll() at consumer.c:2551)
|
|
DEBUG1 - 16:18:58.780447466 [17803/17810]: Beginning of waiter wait period (in lttng_waiter_wait() at waiter.c:58)
|
|
DEBUG1 - 16:18:58.780448187 [19216/19224]: consumer_data_pipe wake up (in consumer_thread_data_poll() at consumer.c:2581)
|
|
DEBUG1 - 16:18:58.780451156 [19216/19224]: polling on 6 fd (in consumer_thread_data_poll() at consumer.c:2544)
|
|
DEBUG1 - 16:18:58.780454423 [19216/19224]: poll num_rdy : 1 (in consumer_thread_data_poll() at consumer.c:2551)
|
|
DEBUG1 - 16:18:58.780457958 [19216/19224]: consumer_data_pipe wake up (in consumer_thread_data_poll() at consumer.c:2581)
|
|
DEBUG1 - 16:18:58.780454811 [17803/17809]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:509)
|
|
DEBUG1 - 16:18:58.780461373 [19216/19224]: polling on 6 fd (in consumer_thread_data_poll() at consumer.c:2544)
|
|
DEBUG1 - 16:18:58.780463897 [17803/17809]: [notification-thread] Handling fd (24) activity (1) (in thread_notification() at notification-thread.c:530)
|
|
DEBUG1 - 16:18:58.780471106 [17803/17809]: [notification-thread] Received add channel command (in handle_notification_thread_command() at notification-thread-events.c:1300)
|
|
DEBUG1 - 16:18:58.780475614 [17803/17809]: [notification-thread] Adding channel channel0 from session auto-20200114-161838, channel key = 1 in user space domain (in handle_notification_thread_command_add_channel() at notification-thread-events.c:812)
|
|
DEBUG1 - 16:18:58.780483030 [17803/17809]: [notification-thread] Found 0 triggers that apply to newly added channel (in handle_notification_thread_command_add_channel() at notification-thread-events.c:844)
|
|
DEBUG1 - 16:18:58.780494013 [17803/17809]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:507)
|
|
DEBUG1 - 16:18:58.780494024 [17803/17810]: End of waiter wait period (in lttng_waiter_wait() at waiter.c:101)
|
|
DEBUG1 - 16:18:58.780498681 [17803/17810]: UST app sending buffer registry channel to ust sock 38 (in send_channel_uid_to_ust() at ust-app.c:2794)
|
|
DEBUG2 - 16:18:58.780504229 [17803/17810]: UST app send channel to sock 38 pid 12709 (name: channel0, key: 0) (in ust_consumer_send_channel_to_ust() at ust-consumer.c:445)
|
|
DEBUG2 - 16:18:58.780554206 [17803/17810]: UST consumer send stream to app 38 (in ust_consumer_send_stream_to_ust() at ust-consumer.c:408)
|
|
DEBUG2 - 16:18:58.780597456 [17803/17810]: UST consumer send stream to app 38 (in ust_consumer_send_stream_to_ust() at ust-consumer.c:408)
|
|
DEBUG2 - 16:18:58.780627269 [17803/17810]: UST consumer send stream to app 38 (in ust_consumer_send_stream_to_ust() at ust-consumer.c:408)
|
|
DEBUG2 - 16:18:58.780654235 [17803/17810]: UST consumer send stream to app 38 (in ust_consumer_send_stream_to_ust() at ust-consumer.c:408)
|
|
DEBUG2 - 16:18:58.780683243 [17803/17810]: UST app create channel channel0 for PID 12709 completed (in create_ust_app_channel() at ust-app.c:3157)
|
|
DEBUG2 - 16:18:58.780688793 [17803/17810]: UST app pid: 7905 session id 0 not found, creating it (in create_ust_app_session() at ust-app.c:2172)
|
|
DEBUG3 - 16:18:58.780697790 [17803/17810]: Created hashtable size 4 at 0x12ab310 of type 0 (in lttng_ht_new() at hashtable.c:145)
|
|
DEBUG2 - 16:18:58.780705489 [17803/17810]: Shadow copy of session handle -1 (in shadow_copy_session() at ust-app.c:1870)
|
|
DEBUG3 - 16:18:58.780709143 [17803/17810]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.c:203)
|
|
DEBUG2 - 16:18:58.780804889 [17803/17810]: UST app session created successfully with handle 4 (in create_ust_app_session() at ust-app.c:2247)
|
|
DEBUG3 - 16:18:58.780809691 [17803/17810]: Created hashtable size 4 at 0x12aba80 of type 1 (in lttng_ht_new() at hashtable.c:145)
|
|
DEBUG3 - 16:18:58.780812588 [17803/17810]: Created hashtable size 4 at 0x12ad530 of type 0 (in lttng_ht_new() at hashtable.c:145)
|
|
DEBUG3 - 16:18:58.780814952 [17803/17810]: UST app channel channel0 allocated (in alloc_ust_app_channel() at ust-app.c:1049)
|
|
DEBUG2 - 16:18:58.780817300 [17803/17810]: UST app shadow copy of channel channel0 started (in shadow_copy_channel() at ust-app.c:1792)
|
|
DEBUG3 - 16:18:58.780819808 [17803/17810]: UST app shadow copy of channel channel0 done (in shadow_copy_channel() at ust-app.c:1846)
|
|
DEBUG1 - 16:18:58.780822214 [17803/17810]: UST app creating channel channel0 with per UID buffers (in create_channel_per_uid() at ust-app.c:2864)
|
|
DEBUG3 - 16:18:58.780824599 [17803/17810]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.c:203)
|
|
DEBUG1 - 16:18:58.780829330 [17803/17810]: UST app sending buffer registry channel to ust sock 40 (in send_channel_uid_to_ust() at ust-app.c:2794)
|
|
DEBUG2 - 16:18:58.780832620 [17803/17810]: UST app send channel to sock 40 pid 7905 (name: channel0, key: 0) (in ust_consumer_send_channel_to_ust() at ust-consumer.c:445)
|
|
DEBUG2 - 16:18:58.780864588 [17803/17810]: UST consumer send stream to app 40 (in ust_consumer_send_stream_to_ust() at ust-consumer.c:408)
|
|
DEBUG2 - 16:18:58.780895921 [17803/17810]: UST consumer send stream to app 40 (in ust_consumer_send_stream_to_ust() at ust-consumer.c:408)
|
|
DEBUG2 - 16:18:58.780924783 [17803/17810]: UST consumer send stream to app 40 (in ust_consumer_send_stream_to_ust() at ust-consumer.c:408)
|
|
DEBUG2 - 16:18:58.780952813 [17803/17810]: UST consumer send stream to app 40 (in ust_consumer_send_stream_to_ust() at ust-consumer.c:408)
|
|
DEBUG2 - 16:18:58.780990137 [17803/17810]: UST app create channel channel0 for PID 7905 completed (in create_ust_app_channel() at ust-app.c:3157)
|
|
DEBUG2 - 16:18:58.780994698 [17803/17810]: UST app pid: 17436 session id 0 not found, creating it (in create_ust_app_session() at ust-app.c:2172)
|
|
DEBUG3 - 16:18:58.781003903 [17803/17810]: Created hashtable size 4 at 0x12adf70 of type 0 (in lttng_ht_new() at hashtable.c:145)
|
|
DEBUG2 - 16:18:58.781008755 [17803/17810]: Shadow copy of session handle -1 (in shadow_copy_session() at ust-app.c:1870)
|
|
DEBUG3 - 16:18:58.781011868 [17803/17810]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.c:203)
|
|
DEBUG2 - 16:18:58.781102210 [17803/17810]: UST app session created successfully with handle 1 (in create_ust_app_session() at ust-app.c:2247)
|
|
DEBUG3 - 16:18:58.781106518 [17803/17810]: Created hashtable size 4 at 0x12ae9f0 of type 1 (in lttng_ht_new() at hashtable.c:145)
|
|
DEBUG3 - 16:18:58.781109418 [17803/17810]: Created hashtable size 4 at 0x12aef30 of type 0 (in lttng_ht_new() at hashtable.c:145)
|
|
DEBUG3 - 16:18:58.781111736 [17803/17810]: UST app channel channel0 allocated (in alloc_ust_app_channel() at ust-app.c:1049)
|
|
DEBUG2 - 16:18:58.781114014 [17803/17810]: UST app shadow copy of channel channel0 started (in shadow_copy_channel() at ust-app.c:1792)
|
|
DEBUG3 - 16:18:58.781116344 [17803/17810]: UST app shadow copy of channel channel0 done (in shadow_copy_channel() at ust-app.c:1846)
|
|
DEBUG1 - 16:18:58.781118694 [17803/17810]: UST app creating channel channel0 with per UID buffers (in create_channel_per_uid() at ust-app.c:2864)
|
|
DEBUG3 - 16:18:58.781120963 [17803/17810]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.c:203)
|
|
DEBUG1 - 16:18:58.781123382 [17803/17810]: UST app sending buffer registry channel to ust sock 33 (in send_channel_uid_to_ust() at ust-app.c:2794)
|
|
DEBUG2 - 16:18:58.781126692 [17803/17810]: UST app send channel to sock 33 pid 17436 (name: channel0, key: 0) (in ust_consumer_send_channel_to_ust() at ust-consumer.c:445)
|
|
DEBUG2 - 16:18:58.782539612 [17803/17810]: UST consumer send stream to app 33 (in ust_consumer_send_stream_to_ust() at ust-consumer.c:408)
|
|
DEBUG2 - 16:18:58.782568942 [17803/17810]: UST consumer send stream to app 33 (in ust_consumer_send_stream_to_ust() at ust-consumer.c:408)
|
|
DEBUG2 - 16:18:58.782596656 [17803/17810]: UST consumer send stream to app 33 (in ust_consumer_send_stream_to_ust() at ust-consumer.c:408)
|
|
DEBUG2 - 16:18:58.782622435 [17803/17810]: UST consumer send stream to app 33 (in ust_consumer_send_stream_to_ust() at ust-consumer.c:408)
|
|
DEBUG2 - 16:18:58.782649871 [17803/17810]: UST app create channel channel0 for PID 17436 completed (in create_ust_app_channel() at ust-app.c:3157)
|
|
DEBUG2 - 16:18:58.782654174 [17803/17810]: Channel channel0 created successfully (in channel_ust_create() at channel.c:490)
|
|
DEBUG2 - 16:18:58.782657279 [17803/17810]: Trace UST channel channel0 found by name (in trace_ust_find_channel_by_name() at trace-ust.c:191)
|
|
DEBUG2 - 16:18:58.782661962 [17803/17810]: Trace UST event hello_world:my_first_tracepoint NOT found (in trace_ust_find_event() at trace-ust.c:234)
|
|
DEBUG2 - 16:18:58.782665007 [17803/17810]: Trace UST event hello_world:my_first_tracepoint, loglevel (0,-1) created (in trace_ust_create_event() at trace-ust.c:512)
|
|
DEBUG1 - 16:18:58.782668835 [17803/17810]: UST app creating event hello_world:my_first_tracepoint for all apps for session id 0 (in ust_app_create_event_glb() at ust-app.c:4328)
|
|
DEBUG3 - 16:18:58.782673384 [17803/17810]: UST app event hello_world:my_first_tracepoint allocated (in alloc_ust_app_event() at ust-app.c:1105)
|
|
DEBUG2 - 16:18:58.782698448 [17803/17810]: UST app event hello_world:my_first_tracepoint created successfully for pid:12709 (in create_ust_event() at ust-app.c:1692)
|
|
DEBUG2 - 16:18:58.782717559 [17803/17810]: UST app event hello_world:my_first_tracepoint enabled successfully for app (pid: 12709) (in enable_ust_event() at ust-app.c:1596)
|
|
DEBUG2 - 16:18:58.782720931 [17803/17810]: UST app create event hello_world:my_first_tracepoint for PID 12709 completed (in create_ust_app_event() at ust-app.c:3216)
|
|
DEBUG3 - 16:18:58.782724063 [17803/17810]: UST app event hello_world:my_first_tracepoint allocated (in alloc_ust_app_event() at ust-app.c:1105)
|
|
DEBUG2 - 16:18:58.782743691 [17803/17810]: UST app event hello_world:my_first_tracepoint created successfully for pid:7905 (in create_ust_event() at ust-app.c:1692)
|
|
DEBUG2 - 16:18:58.782761388 [17803/17810]: UST app event hello_world:my_first_tracepoint enabled successfully for app (pid: 7905) (in enable_ust_event() at ust-app.c:1596)
|
|
DEBUG2 - 16:18:58.782764192 [17803/17810]: UST app create event hello_world:my_first_tracepoint for PID 7905 completed (in create_ust_app_event() at ust-app.c:3216)
|
|
DEBUG3 - 16:18:58.782767016 [17803/17810]: UST app event hello_world:my_first_tracepoint allocated (in alloc_ust_app_event() at ust-app.c:1105)
|
|
DEBUG2 - 16:18:58.782788059 [17803/17810]: UST app event hello_world:my_first_tracepoint created successfully for pid:17436 (in create_ust_event() at ust-app.c:1692)
|
|
DEBUG2 - 16:18:58.782806145 [17803/17810]: UST app event hello_world:my_first_tracepoint enabled successfully for app (pid: 17436) (in enable_ust_event() at ust-app.c:1596)
|
|
DEBUG2 - 16:18:58.782808929 [17803/17810]: UST app create event hello_world:my_first_tracepoint for PID 17436 completed (in create_ust_app_event() at ust-app.c:3216)
|
|
DEBUG1 - 16:18:58.782811625 [17803/17810]: Event UST hello_world:my_first_tracepoint created in channel channel0 (in event_ust_enable_tracepoint() at event.c:236)
|
|
DEBUG1 - 16:18:58.782817424 [17803/17810]: Sending response (size: 20, retcode: Success (10)) (in thread_manage_clients() at main.c:4484)
|
|
DEBUG1 - 16:18:58.782829894 [17803/17810]: Clean command context structure (in clean_command_ctx() at main.c:641)
|
|
DEBUG1 - 16:18:58.782833006 [17803/17810]: Accepting client command ... (in thread_manage_clients() at main.c:4337)
|
|
DEBUG1 - 16:18:59.780332106 [17803/17809]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:509)
|
|
DEBUG1 - 16:18:59.780326837 [19216/19221]: Sent channel monitoring sample for channel key 1, (highest = 84, lowest = 84) (in monitor_timer() at consumer-timer.c:763)
|
|
DEBUG1 - 16:18:59.780345753 [17803/17809]: [notification-thread] Handling fd (13) activity (1) (in thread_notification() at notification-thread.c:530)
|
|
DEBUG1 - 16:18:59.780357463 [17803/17809]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session auto-20200114-161838 (highest usage = 84, lowest usage = 84) (in handle_notification_thread_channel_sample() at notification-thread-events.c:2209)
|
|
DEBUG1 - 16:18:59.780364560 [17803/17809]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:507)
|
|
DEBUG1 - 16:19:00.780317204 [19216/19221]: Sent channel monitoring sample for channel key 1, (highest = 84, lowest = 84) (in monitor_timer() at consumer-timer.c:763)
|
|
DEBUG1 - 16:19:00.780323144 [17803/17809]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:509)
|
|
DEBUG1 - 16:19:00.780334889 [17803/17809]: [notification-thread] Handling fd (13) activity (1) (in thread_notification() at notification-thread.c:530)
|
|
DEBUG1 - 16:19:00.780343192 [17803/17809]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session auto-20200114-161838 (highest usage = 84, lowest usage = 84) (in handle_notification_thread_channel_sample() at notification-thread-events.c:2209)
|
|
DEBUG1 - 16:19:00.780347914 [17803/17809]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:507)
|
|
DEBUG1 - 16:19:01.780316739 [19216/19221]: Sent channel monitoring sample for channel key 1, (highest = 84, lowest = 84) (in monitor_timer() at consumer-timer.c:763)
|
|
DEBUG1 - 16:19:01.780322304 [17803/17809]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:509)
|
|
DEBUG1 - 16:19:01.780333755 [17803/17809]: [notification-thread] Handling fd (13) activity (1) (in thread_notification() at notification-thread.c:530)
|
|
DEBUG1 - 16:19:01.780342904 [17803/17809]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session auto-20200114-161838 (highest usage = 84, lowest usage = 84) (in handle_notification_thread_channel_sample() at notification-thread-events.c:2209)
|
|
DEBUG1 - 16:19:01.780348552 [17803/17809]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:507)
|
|
DEBUG1 - 16:19:02.780317611 [19216/19221]: Sent channel monitoring sample for channel key 1, (highest = 84, lowest = 84) (in monitor_timer() at consumer-timer.c:763)
|
|
DEBUG1 - 16:19:02.780323807 [17803/17809]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:509)
|
|
DEBUG1 - 16:19:02.780337322 [17803/17809]: [notification-thread] Handling fd (13) activity (1) (in thread_notification() at notification-thread.c:530)
|
|
DEBUG1 - 16:19:02.780345815 [17803/17809]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session auto-20200114-161838 (highest usage = 84, lowest usage = 84) (in handle_notification_thread_channel_sample() at notification-thread-events.c:2209)
|
|
DEBUG1 - 16:19:02.780350416 [17803/17809]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:507)
|
|
DEBUG1 - 16:19:03.780318816 [19216/19221]: Sent channel monitoring sample for channel key 1, (highest = 84, lowest = 84) (in monitor_timer() at consumer-timer.c:763)
|
|
DEBUG1 - 16:19:03.780324076 [17803/17809]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:509)
|
|
DEBUG1 - 16:19:03.780334647 [17803/17809]: [notification-thread] Handling fd (13) activity (1) (in thread_notification() at notification-thread.c:530)
|
|
DEBUG1 - 16:19:03.780342682 [17803/17809]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session auto-20200114-161838 (highest usage = 84, lowest usage = 84) (in handle_notification_thread_channel_sample() at notification-thread-events.c:2209)
|
|
DEBUG1 - 16:19:03.780347341 [17803/17809]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:507)
|
|
DEBUG1 - 16:19:04.780316868 [19216/19221]: Sent channel monitoring sample for channel key 1, (highest = 84, lowest = 84) (in monitor_timer() at consumer-timer.c:763)
|
|
DEBUG1 - 16:19:04.780322750 [17803/17809]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:509)
|
|
DEBUG1 - 16:19:04.780333556 [17803/17809]: [notification-thread] Handling fd (13) activity (1) (in thread_notification() at notification-thread.c:530)
|
|
DEBUG1 - 16:19:04.780341851 [17803/17809]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session auto-20200114-161838 (highest usage = 84, lowest usage = 84) (in handle_notification_thread_channel_sample() at notification-thread-events.c:2209)
|
|
DEBUG1 - 16:19:04.780346639 [17803/17809]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:507)
|
|
DEBUG1 - 16:19:05.780315442 [19216/19221]: Sent channel monitoring sample for channel key 1, (highest = 84, lowest = 84) (in monitor_timer() at consumer-timer.c:763)
|
|
DEBUG1 - 16:19:05.780321405 [17803/17809]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:509)
|
|
DEBUG1 - 16:19:05.780332220 [17803/17809]: [notification-thread] Handling fd (13) activity (1) (in thread_notification() at notification-thread.c:530)
|
|
DEBUG1 - 16:19:05.780340026 [17803/17809]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session auto-20200114-161838 (highest usage = 84, lowest usage = 84) (in handle_notification_thread_channel_sample() at notification-thread-events.c:2209)
|
|
DEBUG1 - 16:19:05.780344784 [17803/17809]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:507)
|
|
DEBUG1 - 16:19:05.812530335 [17803/17810]: Wait for client response (in thread_manage_clients() at main.c:4389)
|
|
DEBUG1 - 16:19:05.812554595 [17803/17810]: Receiving data from client ... (in thread_manage_clients() at main.c:4434)
|
|
DEBUG1 - 16:19:05.812563496 [17803/17810]: Processing client command 0 (in process_client_msg() at main.c:2877)
|
|
DEBUG1 - 16:19:05.812567392 [17803/17810]: Getting session auto-20200114-161838 by name (in process_client_msg() at main.c:2970)
|
|
DEBUG2 - 16:19:05.812570310 [17803/17810]: Trying to find session by name auto-20200114-161838 (in session_find_by_name() at session.c:276)
|
|
DEBUG3 - 16:19:05.812575940 [17803/17810]: Consumer socket created (fd: 45) and added to output (in consumer_create_socket() at consumer.c:301)
|
|
DEBUG1 - 16:19:05.812578972 [17803/17810]: Setting relayd for session auto-20200114-161838 (in cmd_setup_relayd() at cmd.c:1043)
|
|
DEBUG2 - 16:19:05.812594052 [17803/17810]: UST app adding context to channel channel0 (in create_ust_app_channel_context() at ust-app.c:2357)
|
|
DEBUG3 - 16:19:05.812597637 [17803/17810]: UST app context 1 allocated (in alloc_ust_app_ctx() at ust-app.c:1146)
|
|
DEBUG2 - 16:19:05.812646459 [17803/17810]: UST app context handle -1 created successfully for channel channel0 (in create_ust_channel_context() at ust-app.c:1321)
|
|
DEBUG2 - 16:19:05.812651799 [17803/17810]: UST app adding context to channel channel0 (in create_ust_app_channel_context() at ust-app.c:2357)
|
|
DEBUG3 - 16:19:05.812657523 [17803/17810]: UST app context 1 allocated (in alloc_ust_app_ctx() at ust-app.c:1146)
|
|
DEBUG2 - 16:19:05.812694424 [17803/17810]: UST app context handle -1 created successfully for channel channel0 (in create_ust_channel_context() at ust-app.c:1321)
|
|
DEBUG2 - 16:19:05.812698798 [17803/17810]: UST app adding context to channel channel0 (in create_ust_app_channel_context() at ust-app.c:2357)
|
|
DEBUG3 - 16:19:05.812701569 [17803/17810]: UST app context 1 allocated (in alloc_ust_app_ctx() at ust-app.c:1146)
|
|
DEBUG2 - 16:19:05.812742780 [17803/17810]: UST app context handle -1 created successfully for channel channel0 (in create_ust_channel_context() at ust-app.c:1321)
|
|
DEBUG1 - 16:19:05.812747071 [17803/17810]: Context UST 1 added to channel channel0 (in add_uctx_to_channel() at context.c:184)
|
|
DEBUG1 - 16:19:05.812750881 [17803/17810]: Sending response (size: 20, retcode: Success (10)) (in thread_manage_clients() at main.c:4484)
|
|
DEBUG1 - 16:19:05.812760352 [17803/17810]: Clean command context structure (in clean_command_ctx() at main.c:641)
|
|
DEBUG1 - 16:19:05.812763681 [17803/17810]: Accepting client command ... (in thread_manage_clients() at main.c:4337)
|
|
DEBUG1 - 16:19:05.812817845 [17803/17810]: Wait for client response (in thread_manage_clients() at main.c:4389)
|
|
DEBUG1 - 16:19:05.812825619 [17803/17810]: Receiving data from client ... (in thread_manage_clients() at main.c:4434)
|
|
DEBUG1 - 16:19:05.812832275 [17803/17810]: Processing client command 0 (in process_client_msg() at main.c:2877)
|
|
DEBUG1 - 16:19:05.812834956 [17803/17810]: Getting session auto-20200114-161838 by name (in process_client_msg() at main.c:2970)
|
|
DEBUG2 - 16:19:05.812837307 [17803/17810]: Trying to find session by name auto-20200114-161838 (in session_find_by_name() at session.c:276)
|
|
DEBUG3 - 16:19:05.812839990 [17803/17810]: Consumer socket created (fd: 45) and added to output (in consumer_create_socket() at consumer.c:301)
|
|
DEBUG1 - 16:19:05.812842481 [17803/17810]: Setting relayd for session auto-20200114-161838 (in cmd_setup_relayd() at cmd.c:1043)
|
|
DEBUG2 - 16:19:05.812845675 [17803/17810]: UST app adding context to channel channel0 (in create_ust_app_channel_context() at ust-app.c:2357)
|
|
DEBUG3 - 16:19:05.812848233 [17803/17810]: UST app context 2 allocated (in alloc_ust_app_ctx() at ust-app.c:1146)
|
|
DEBUG2 - 16:19:05.812877212 [17803/17810]: UST app context handle -1 created successfully for channel channel0 (in create_ust_channel_context() at ust-app.c:1321)
|
|
DEBUG2 - 16:19:05.812880157 [17803/17810]: UST app adding context to channel channel0 (in create_ust_app_channel_context() at ust-app.c:2357)
|
|
DEBUG3 - 16:19:05.812882447 [17803/17810]: UST app context 2 allocated (in alloc_ust_app_ctx() at ust-app.c:1146)
|
|
DEBUG2 - 16:19:05.812907471 [17803/17810]: UST app context handle -1 created successfully for channel channel0 (in create_ust_channel_context() at ust-app.c:1321)
|
|
DEBUG2 - 16:19:05.812910222 [17803/17810]: UST app adding context to channel channel0 (in create_ust_app_channel_context() at ust-app.c:2357)
|
|
DEBUG3 - 16:19:05.812912551 [17803/17810]: UST app context 2 allocated (in alloc_ust_app_ctx() at ust-app.c:1146)
|
|
DEBUG2 - 16:19:05.812938990 [17803/17810]: UST app context handle -1 created successfully for channel channel0 (in create_ust_channel_context() at ust-app.c:1321)
|
|
DEBUG1 - 16:19:05.812942989 [17803/17810]: Context UST 2 added to channel channel0 (in add_uctx_to_channel() at context.c:184)
|
|
DEBUG1 - 16:19:05.812945592 [17803/17810]: Sending response (size: 20, retcode: Success (10)) (in thread_manage_clients() at main.c:4484)
|
|
DEBUG1 - 16:19:05.812952094 [17803/17810]: Clean command context structure (in clean_command_ctx() at main.c:641)
|
|
DEBUG1 - 16:19:05.812954520 [17803/17810]: Accepting client command ... (in thread_manage_clients() at main.c:4337)
|
|
DEBUG1 - 16:19:06.780316782 [19216/19221]: Sent channel monitoring sample for channel key 1, (highest = 84, lowest = 84) (in monitor_timer() at consumer-timer.c:763)
|
|
DEBUG1 - 16:19:06.780321716 [17803/17809]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:509)
|
|
DEBUG1 - 16:19:06.780333025 [17803/17809]: [notification-thread] Handling fd (13) activity (1) (in thread_notification() at notification-thread.c:530)
|
|
DEBUG1 - 16:19:06.780341177 [17803/17809]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session auto-20200114-161838 (highest usage = 84, lowest usage = 84) (in handle_notification_thread_channel_sample() at notification-thread-events.c:2209)
|
|
DEBUG1 - 16:19:06.780346094 [17803/17809]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:507)
|
|
DEBUG1 - 16:19:07.780318808 [19216/19221]: Sent channel monitoring sample for channel key 1, (highest = 84, lowest = 84) (in monitor_timer() at consumer-timer.c:763)
|
|
DEBUG1 - 16:19:07.780324232 [17803/17809]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:509)
|
|
DEBUG1 - 16:19:07.780334262 [17803/17809]: [notification-thread] Handling fd (13) activity (1) (in thread_notification() at notification-thread.c:530)
|
|
DEBUG1 - 16:19:07.780341896 [17803/17809]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session auto-20200114-161838 (highest usage = 84, lowest usage = 84) (in handle_notification_thread_channel_sample() at notification-thread-events.c:2209)
|
|
DEBUG1 - 16:19:07.780346684 [17803/17809]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:507)
|
|
DEBUG1 - 16:19:08.146383961 [17803/17810]: Wait for client response (in thread_manage_clients() at main.c:4389)
|
|
DEBUG1 - 16:19:08.146408004 [17803/17810]: Receiving data from client ... (in thread_manage_clients() at main.c:4434)
|
|
DEBUG1 - 16:19:08.146416938 [17803/17810]: Processing client command 16 (in process_client_msg() at main.c:2877)
|
|
DEBUG1 - 16:19:08.146421035 [17803/17810]: Getting session auto-20200114-161838 by name (in process_client_msg() at main.c:2970)
|
|
DEBUG2 - 16:19:08.146423870 [17803/17810]: Trying to find session by name auto-20200114-161838 (in session_find_by_name() at session.c:276)
|
|
DEBUG1 - 16:19:08.146429342 [17803/17810]: Starting all UST traces (in ust_app_start_trace_all() at ust-app.c:4929)
|
|
DEBUG1 - 16:19:08.146431967 [17803/17810]: Clearing stream quiescent state for all ust apps (in ust_app_clear_quiescent_session() at ust-app.c:4804)
|
|
DEBUG2 - 16:19:08.146440999 [17803/17810]: Consumer clear quiescent channel key 1 (in consumer_clear_quiescent_channel() at consumer.c:1252)
|
|
DEBUG1 - 16:19:08.146461521 [19216/19225]: Incoming command on sock (in consumer_thread_sessiond_poll() at consumer.c:3204)
|
|
DEBUG1 - 16:19:08.146480942 [19216/19225]: UST consumer clear quiescent channel key 1 (in clear_quiescent_channel() at ust-consumer.c:796)
|
|
DEBUG1 - 16:19:08.146491747 [19216/19225]: received command on sock (in consumer_thread_sessiond_poll() at consumer.c:3220)
|
|
DEBUG1 - 16:19:08.146495876 [17803/17810]: Starting tracing for ust app pid 12709 (in ust_app_start_trace() at ust-app.c:4392)
|
|
DEBUG3 - 16:19:08.146499989 [17803/17810]: mkdir() recursive /var/lib/log/lttng_home/lttng-traces/auto-20200114-161838 with mode 504 for uid 1000 and gid 1000 (in run_as_mkdir_recursive() at runas.c:470)
|
|
DEBUG1 - 16:19:08.146507385 [17803/17810]: Using run_as worker (in run_as() at runas.c:450)
|
|
DEBUG3 - 16:19:08.146552317 [17803/17810]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.c:203)
|
|
DEBUG3 - 16:19:08.146563340 [17803/17810]: Created hashtable size 4 at 0x12b70c0 of type 1 (in lttng_ht_new() at hashtable.c:145)
|
|
DEBUG3 - 16:19:08.146567386 [17803/17810]: Created hashtable size 4 at 0x12b7570 of type 0 (in lttng_ht_new() at hashtable.c:145)
|
|
DEBUG3 - 16:19:08.146569950 [17803/17810]: UST app channel metadata allocated (in alloc_ust_app_channel() at ust-app.c:1049)
|
|
DEBUG3 - 16:19:08.146573668 [17803/17810]: Session 0 found by id. (in session_find_by_id() at session.c:312)
|
|
DEBUG2 - 16:19:08.146576582 [17803/17810]: Asking UST consumer for channel (in ask_channel_creation() at ust-consumer.c:121)
|
|
DEBUG3 - 16:19:08.146582596 [17803/17810]: mkdir() recursive /var/lib/log/lttng_home/lttng-traces/auto-20200114-161838/ust/uid/1000/64-bit with mode 504 for uid 1000 and gid 1000 (in run_as_mkdir_recursive() at runas.c:470)
|
|
DEBUG1 - 16:19:08.146588947 [17803/17810]: Using run_as worker (in run_as() at runas.c:450)
|
|
DEBUG1 - 16:19:08.146642128 [19216/19225]: Incoming command on sock (in consumer_thread_sessiond_poll() at consumer.c:3204)
|
|
DEBUG1 - 16:19:08.146662273 [19216/19225]: Allocated channel (key 4) (in consumer_allocate_channel() at consumer.c:1031)
|
|
DEBUG1 - 16:19:08.146743371 [19216/19225]: Using run_as worker (in run_as() at runas.c:450)
|
|
DEBUG1 - 16:19:08.146808102 [19216/19225]: UST consumer add stream metadata (key: 58) with relayd id 0 (in create_ust_streams() at ust-consumer.c:347)
|
|
DEBUG1 - 16:19:08.146813206 [19216/19225]: Allocated metadata cache of 4096 bytes (in consumer_metadata_cache_allocate() at consumer-metadata-cache.c:198)
|
|
DEBUG1 - 16:19:08.146818147 [19216/19225]: UST consumer channel added (key: 4) (in add_channel() at ust-consumer.c:115)
|
|
DEBUG1 - 16:19:08.146823967 [19216/19225]: received command on sock (in consumer_thread_sessiond_poll() at consumer.c:3220)
|
|
DEBUG2 - 16:19:08.146826842 [17803/17810]: UST ask channel 4 successfully done with 1 stream(s) (in ask_channel_creation() at ust-consumer.c:218)
|
|
DEBUG2 - 16:19:08.146830425 [17803/17810]: Consumer setup metadata channel key 4 (in consumer_setup_metadata() at consumer.c:1319)
|
|
DEBUG1 - 16:19:08.146839842 [19216/19225]: Incoming command on sock (in consumer_thread_sessiond_poll() at consumer.c:3204)
|
|
DEBUG1 - 16:19:08.146846925 [19216/19225]: UST consumer setup metadata key 4 (in setup_metadata() at ust-consumer.c:912)
|
|
DEBUG1 - 16:19:08.146858714 [19216/19225]: received command on sock (in consumer_thread_sessiond_poll() at consumer.c:3220)
|
|
DEBUG2 - 16:19:08.146861338 [17803/17810]: UST metadata with key 4 created for app pid 12709 (in create_ust_app_metadata() at ust-app.c:3316)
|
|
DEBUG1 - 16:19:08.146859562 [19216/19223]: Metadata poll return from wait with 1 fd(s) (in consumer_thread_metadata_poll() at consumer.c:2284)
|
|
DEBUG3 - 16:19:08.146864880 [17803/17810]: UST app deleting channel metadata (in delete_ust_app_channel() at ust-app.c:460)
|
|
DEBUG1 - 16:19:08.146865577 [19216/19223]: Metadata event caught in thread (in consumer_thread_metadata_poll() at consumer.c:2286)
|
|
DEBUG1 - 16:19:08.146870166 [19216/19223]: Adding metadata stream 58 to poll set (in consumer_thread_metadata_poll() at consumer.c:2340)
|
|
DEBUG1 - 16:19:08.146874943 [19216/19223]: Metadata poll wait (in consumer_thread_metadata_poll() at consumer.c:2281)
|
|
DEBUG3 - 16:19:08.146914407 [17803/17814]: [ust-thread] Manage notify return from poll on 5 fds (in ust_thread_manage_notify() at ust-thread.c:76)
|
|
DEBUG3 - 16:19:08.146924364 [17803/17814]: UST app receiving notify from sock 39 (in ust_app_recv_notify() at ust-app.c:5699)
|
|
DEBUG2 - 16:19:08.146936626 [17803/17814]: UST app ustctl register channel received (in ust_app_recv_notify() at ust-app.c:5753)
|
|
DEBUG3 - 16:19:08.146951247 [17803/17814]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.c:203)
|
|
DEBUG3 - 16:19:08.146958849 [17803/17814]: UST registry channel finding key 0 (in ust_registry_channel_find() at ust-registry.c:796)
|
|
DEBUG3 - 16:19:08.146971112 [17803/17814]: Append to metadata: "stream {
|
|
id = 0;
|
|
event.header := struct event_header_compact;
|
|
packet.context := struct packet_context;
|
|
" (in lttng_metadata_printf() at ust-metadata.c:178)
|
|
DEBUG3 - 16:19:08.146974996 [17803/17814]: Append to metadata: " event.context := struct {
|
|
" (in lttng_metadata_printf() at ust-metadata.c:178)
|
|
DEBUG3 - 16:19:08.146978075 [17803/17814]: Append to metadata: " " (in lttng_metadata_printf() at ust-metadata.c:178)
|
|
DEBUG3 - 16:19:08.146980525 [17803/17814]: Append to metadata: " " (in lttng_metadata_printf() at ust-metadata.c:178)
|
|
DEBUG3 - 16:19:08.146984006 [17803/17814]: Append to metadata: "integer { size = 32; align = 8; signed = 1; encoding = none; base = 10; } _vpid;
|
|
" (in lttng_metadata_printf() at ust-metadata.c:178)
|
|
DEBUG3 - 16:19:08.146986872 [17803/17814]: Append to metadata: " " (in lttng_metadata_printf() at ust-metadata.c:178)
|
|
DEBUG3 - 16:19:08.146989160 [17803/17814]: Append to metadata: " " (in lttng_metadata_printf() at ust-metadata.c:178)
|
|
DEBUG3 - 16:19:08.146991969 [17803/17814]: Append to metadata: "integer { size = 64; align = 8; signed = 0; encoding = none; base = 10; } _pthread_id;
|
|
" (in lttng_metadata_printf() at ust-metadata.c:178)
|
|
DEBUG3 - 16:19:08.146994607 [17803/17814]: Append to metadata: " };
|
|
" (in lttng_metadata_printf() at ust-metadata.c:178)
|
|
DEBUG3 - 16:19:08.146996964 [17803/17814]: Append to metadata: "};
|
|
|
|
" (in lttng_metadata_printf() at ust-metadata.c:178)
|
|
DEBUG3 - 16:19:08.146999202 [17803/17814]: UST app replying to register channel key 0 with id 0, type: 1, ret: 0 (in reply_ust_register_channel() at ust-app.c:5479)
|
|
DEBUG3 - 16:19:08.147007191 [17803/17814]: [ust-thread] Manage notify polling (in ust_thread_manage_notify() at ust-thread.c:69)
|
|
DEBUG1 - 16:19:08.153365365 [17803/17810]: Starting tracing for ust app pid 7905 (in ust_app_start_trace() at ust-app.c:4392)
|
|
DEBUG3 - 16:19:08.153370734 [17803/17810]: mkdir() recursive /var/lib/log/lttng_home/lttng-traces/auto-20200114-161838 with mode 504 for uid 1000 and gid 1000 (in run_as_mkdir_recursive() at runas.c:470)
|
|
DEBUG1 - 16:19:08.153376795 [17803/17810]: Using run_as worker (in run_as() at runas.c:450)
|
|
DEBUG3 - 16:19:08.153405825 [17803/17810]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.c:203)
|
|
DEBUG3 - 16:19:08.153436355 [17803/17814]: [ust-thread] Manage notify return from poll on 5 fds (in ust_thread_manage_notify() at ust-thread.c:76)
|
|
DEBUG3 - 16:19:08.153440588 [17803/17814]: UST app receiving notify from sock 41 (in ust_app_recv_notify() at ust-app.c:5699)
|
|
DEBUG2 - 16:19:08.153444193 [17803/17814]: UST app ustctl register channel received (in ust_app_recv_notify() at ust-app.c:5753)
|
|
DEBUG3 - 16:19:08.153459781 [17803/17814]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.c:203)
|
|
DEBUG3 - 16:19:08.153462912 [17803/17814]: UST registry channel finding key 0 (in ust_registry_channel_find() at ust-registry.c:796)
|
|
DEBUG3 - 16:19:08.153465234 [17803/17814]: UST app replying to register channel key 0 with id 0, type: 1, ret: 0 (in reply_ust_register_channel() at ust-app.c:5479)
|
|
DEBUG3 - 16:19:08.153470431 [17803/17814]: [ust-thread] Manage notify polling (in ust_thread_manage_notify() at ust-thread.c:69)
|
|
DEBUG1 - 16:19:08.159490884 [17803/17810]: Starting tracing for ust app pid 17436 (in ust_app_start_trace() at ust-app.c:4392)
|
|
DEBUG3 - 16:19:08.159495952 [17803/17810]: mkdir() recursive /var/lib/log/lttng_home/lttng-traces/auto-20200114-161838 with mode 504 for uid 1000 and gid 1000 (in run_as_mkdir_recursive() at runas.c:470)
|
|
DEBUG1 - 16:19:08.159501724 [17803/17810]: Using run_as worker (in run_as() at runas.c:450)
|
|
DEBUG3 - 16:19:08.159537286 [17803/17810]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.c:203)
|
|
DEBUG3 - 16:19:08.159577076 [17803/17814]: [ust-thread] Manage notify return from poll on 5 fds (in ust_thread_manage_notify() at ust-thread.c:76)
|
|
DEBUG3 - 16:19:08.159580983 [17803/17814]: UST app receiving notify from sock 37 (in ust_app_recv_notify() at ust-app.c:5699)
|
|
DEBUG2 - 16:19:08.159584382 [17803/17814]: UST app ustctl register channel received (in ust_app_recv_notify() at ust-app.c:5753)
|
|
DEBUG3 - 16:19:08.159591305 [17803/17814]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.c:203)
|
|
DEBUG3 - 16:19:08.159594081 [17803/17814]: UST registry channel finding key 0 (in ust_registry_channel_find() at ust-registry.c:796)
|
|
DEBUG3 - 16:19:08.159596429 [17803/17814]: UST app replying to register channel key 0 with id 0, type: 1, ret: 0 (in reply_ust_register_channel() at ust-app.c:5479)
|
|
DEBUG3 - 16:19:08.159604303 [17803/17814]: [ust-thread] Manage notify polling (in ust_thread_manage_notify() at ust-thread.c:69)
|
|
DEBUG3 - 16:19:08.159620144 [17803/17814]: [ust-thread] Manage notify return from poll on 5 fds (in ust_thread_manage_notify() at ust-thread.c:76)
|
|
DEBUG3 - 16:19:08.159622598 [17803/17814]: UST app receiving notify from sock 37 (in ust_app_recv_notify() at ust-app.c:5699)
|
|
DEBUG2 - 16:19:08.159626004 [17803/17814]: UST app ustctl register event received (in ust_app_recv_notify() at ust-app.c:5719)
|
|
DEBUG3 - 16:19:08.159642136 [17803/17814]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.c:203)
|
|
DEBUG3 - 16:19:08.159644904 [17803/17814]: UST registry channel finding key 0 (in ust_registry_channel_find() at ust-registry.c:796)
|
|
DEBUG3 - 16:19:08.159647696 [17803/17814]: UST registry creating event with event: hello_world:my_first_tracepoint, sig: int, my_integer_arg, char*, my_string_arg, id: 0, chan_objd: 2, sess_objd: 1, chan_id: 0 (in ust_registry_create_event() at ust-registry.c:426)
|
|
DEBUG3 - 16:19:08.159654974 [17803/17814]: Append to metadata: "event {
|
|
name = "hello_world:my_first_tracepoint";
|
|
id = 0;
|
|
stream_id = 0;
|
|
" (in lttng_metadata_printf() at ust-metadata.c:178)
|
|
DEBUG3 - 16:19:08.159658245 [17803/17814]: Append to metadata: " loglevel = 13;
|
|
" (in lttng_metadata_printf() at ust-metadata.c:178)
|
|
DEBUG3 - 16:19:08.159660911 [17803/17814]: Append to metadata: " fields := struct {
|
|
" (in lttng_metadata_printf() at ust-metadata.c:178)
|
|
DEBUG3 - 16:19:08.159663502 [17803/17814]: Append to metadata: " " (in lttng_metadata_printf() at ust-metadata.c:178)
|
|
DEBUG3 - 16:19:08.159665908 [17803/17814]: Append to metadata: " " (in lttng_metadata_printf() at ust-metadata.c:178)
|
|
DEBUG3 - 16:19:08.159668616 [17803/17814]: Append to metadata: "string _my_string_field;
|
|
" (in lttng_metadata_printf() at ust-metadata.c:178)
|
|
DEBUG3 - 16:19:08.159671056 [17803/17814]: Append to metadata: " " (in lttng_metadata_printf() at ust-metadata.c:178)
|
|
DEBUG3 - 16:19:08.159673310 [17803/17814]: Append to metadata: " " (in lttng_metadata_printf() at ust-metadata.c:178)
|
|
DEBUG3 - 16:19:08.159676144 [17803/17814]: Append to metadata: "integer { size = 32; align = 8; signed = 1; encoding = none; base = 10; } _my_integer_field;
|
|
" (in lttng_metadata_printf() at ust-metadata.c:178)
|
|
DEBUG3 - 16:19:08.159678743 [17803/17814]: Append to metadata: " };
|
|
};
|
|
|
|
" (in lttng_metadata_printf() at ust-metadata.c:178)
|
|
DEBUG3 - 16:19:08.159684742 [17803/17814]: UST registry event hello_world:my_first_tracepoint with id 0 added successfully (in add_event_ust_registry() at ust-app.c:5593)
|
|
DEBUG3 - 16:19:08.159690155 [17803/17814]: [ust-thread] Manage notify polling (in ust_thread_manage_notify() at ust-thread.c:69)
|
|
DEBUG1 - 16:19:08.160869072 [17803/17810]: Sending response (size: 20, retcode: Success (10)) (in thread_manage_clients() at main.c:4484)
|
|
DEBUG1 - 16:19:08.160880956 [17803/17810]: Clean command context structure (in clean_command_ctx() at main.c:641)
|
|
DEBUG3 - 16:19:08.160880465 [17803/17806]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:128)
|
|
DEBUG1 - 16:19:08.160899623 [17803/17810]: Accepting client command ... (in thread_manage_clients() at main.c:4337)
|
|
DEBUG3 - 16:19:08.170984393 [17803/17806]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:124)
|
|
DEBUG3 - 16:19:08.170991554 [17803/17806]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:128)
|
|
DEBUG3 - 16:19:08.181061206 [17803/17806]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:124)
|
|
DEBUG1 - 16:19:08.780316397 [19216/19221]: Sent channel monitoring sample for channel key 1, (highest = 84, lowest = 84) (in monitor_timer() at consumer-timer.c:763)
|
|
DEBUG1 - 16:19:08.780321427 [17803/17809]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:509)
|
|
DEBUG1 - 16:19:08.780333129 [17803/17809]: [notification-thread] Handling fd (13) activity (1) (in thread_notification() at notification-thread.c:530)
|
|
DEBUG1 - 16:19:08.780341111 [17803/17809]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session auto-20200114-161838 (highest usage = 84, lowest usage = 84) (in handle_notification_thread_channel_sample() at notification-thread-events.c:2209)
|
|
DEBUG1 - 16:19:08.780345971 [17803/17809]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:507)
|
|
DEBUG1 - 16:19:09.780317007 [19216/19221]: Sent channel monitoring sample for channel key 1, (highest = 84, lowest = 84) (in monitor_timer() at consumer-timer.c:763)
|
|
DEBUG1 - 16:19:09.780322029 [17803/17809]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:509)
|
|
DEBUG1 - 16:19:09.780333356 [17803/17809]: [notification-thread] Handling fd (13) activity (1) (in thread_notification() at notification-thread.c:530)
|
|
DEBUG1 - 16:19:09.780341669 [17803/17809]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session auto-20200114-161838 (highest usage = 84, lowest usage = 84) (in handle_notification_thread_channel_sample() at notification-thread-events.c:2209)
|
|
DEBUG1 - 16:19:09.780346433 [17803/17809]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:507)
|
|
DEBUG1 - 16:19:10.780318741 [19216/19221]: Sent channel monitoring sample for channel key 1, (highest = 84, lowest = 84) (in monitor_timer() at consumer-timer.c:763)
|
|
DEBUG1 - 16:19:10.780323374 [17803/17809]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:509)
|
|
DEBUG1 - 16:19:10.780333531 [17803/17809]: [notification-thread] Handling fd (13) activity (1) (in thread_notification() at notification-thread.c:530)
|
|
DEBUG1 - 16:19:10.780341210 [17803/17809]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session auto-20200114-161838 (highest usage = 84, lowest usage = 84) (in handle_notification_thread_channel_sample() at notification-thread-events.c:2209)
|
|
DEBUG1 - 16:19:10.780346269 [17803/17809]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:507)
|
|
DEBUG1 - 16:19:11.780316828 [19216/19221]: Sent channel monitoring sample for channel key 1, (highest = 84, lowest = 84) (in monitor_timer() at consumer-timer.c:763)
|
|
DEBUG1 - 16:19:11.780322027 [17803/17809]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:509)
|
|
DEBUG1 - 16:19:11.780333335 [17803/17809]: [notification-thread] Handling fd (13) activity (1) (in thread_notification() at notification-thread.c:530)
|
|
DEBUG1 - 16:19:11.780341299 [17803/17809]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session auto-20200114-161838 (highest usage = 84, lowest usage = 84) (in handle_notification_thread_channel_sample() at notification-thread-events.c:2209)
|
|
DEBUG1 - 16:19:11.780346045 [17803/17809]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:507)
|
|
DEBUG1 - 16:19:12.780316600 [19216/19221]: Sent channel monitoring sample for channel key 1, (highest = 84, lowest = 84) (in monitor_timer() at consumer-timer.c:763)
|
|
DEBUG1 - 16:19:12.780322381 [17803/17809]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:509)
|
|
DEBUG1 - 16:19:12.780333614 [17803/17809]: [notification-thread] Handling fd (13) activity (1) (in thread_notification() at notification-thread.c:530)
|
|
DEBUG1 - 16:19:12.780341795 [17803/17809]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session auto-20200114-161838 (highest usage = 84, lowest usage = 84) (in handle_notification_thread_channel_sample() at notification-thread-events.c:2209)
|
|
DEBUG1 - 16:19:12.780346441 [17803/17809]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:507)
|
|
DEBUG1 - 16:19:13.780316196 [19216/19221]: Sent channel monitoring sample for channel key 1, (highest = 84, lowest = 84) (in monitor_timer() at consumer-timer.c:763)
|
|
DEBUG1 - 16:19:13.780321266 [17803/17809]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:509)
|
|
DEBUG1 - 16:19:13.780332126 [17803/17809]: [notification-thread] Handling fd (13) activity (1) (in thread_notification() at notification-thread.c:530)
|
|
DEBUG1 - 16:19:13.780339780 [17803/17809]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session auto-20200114-161838 (highest usage = 84, lowest usage = 84) (in handle_notification_thread_channel_sample() at notification-thread-events.c:2209)
|
|
DEBUG1 - 16:19:13.780344403 [17803/17809]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:507)
|
|
DEBUG1 - 16:19:14.780317009 [19216/19221]: Sent channel monitoring sample for channel key 1, (highest = 84, lowest = 84) (in monitor_timer() at consumer-timer.c:763)
|
|
DEBUG1 - 16:19:14.780322463 [17803/17809]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:509)
|
|
DEBUG1 - 16:19:14.780332683 [17803/17809]: [notification-thread] Handling fd (13) activity (1) (in thread_notification() at notification-thread.c:530)
|
|
DEBUG1 - 16:19:14.780340659 [17803/17809]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session auto-20200114-161838 (highest usage = 84, lowest usage = 84) (in handle_notification_thread_channel_sample() at notification-thread-events.c:2209)
|
|
DEBUG1 - 16:19:14.780345263 [17803/17809]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:507)
|
|
DEBUG1 - 16:19:15.575767668 [17803/17813]: Apps thread return from poll on 5 fds (in thread_manage_apps() at main.c:1480)
|
|
DEBUG3 - 16:19:15.575769550 [17803/17814]: [ust-thread] Manage notify return from poll on 5 fds (in ust_thread_manage_notify() at ust-thread.c:76)
|
|
DEBUG1 - 16:19:15.575796155 [17803/17813]: PID 17436 unregistering with sock 33 (in ust_app_unregister() at ust-app.c:3508)
|
|
DEBUG3 - 16:19:15.575797227 [17803/17814]: UST app receiving notify from sock 37 (in ust_app_recv_notify() at ust-app.c:5699)
|
|
DEBUG3 - 16:19:15.575813520 [17803/17813]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.c:203)
|
|
DEBUG3 - 16:19:15.575815960 [17803/17814]: UST app recv notify failed. Application died (in ust_app_recv_notify() at ust-app.c:5706)
|
|
DEBUG2 - 16:19:15.575831536 [17803/17813]: Consumer push metadata to consumer socket 45 (in consumer_push_metadata() at consumer.c:1354)
|
|
DEBUG1 - 16:19:15.575834675 [17803/17814]: UST app notify socket unregister 37 (in ust_app_notify_sock_unregister() at ust-app.c:5856)
|
|
DEBUG3 - 16:19:15.575849665 [17803/17814]: [ust-thread] Manage notify polling (in ust_thread_manage_notify() at ust-thread.c:69)
|
|
DEBUG1 - 16:19:15.575858366 [19216/19225]: Incoming command on sock (in consumer_thread_sessiond_poll() at consumer.c:3204)
|
|
DEBUG1 - 16:19:15.575875667 [19216/19225]: UST consumer push metadata key 4 of len 2823 (in lttng_ustconsumer_recv_cmd() at ust-consumer.c:1681)
|
|
DEBUG3 - 16:19:15.575887939 [17803/17813]: Consumer pushing metadata on sock 45 of len 2823 (in consumer_push_metadata() at consumer.c:1372)
|
|
DEBUG1 - 16:19:15.575897243 [19216/19225]: UST consumer push metadata key 4 of len 2823 (in lttng_ustconsumer_recv_metadata() at ust-consumer.c:1267)
|
|
DEBUG1 - 16:19:15.575910383 [19216/19225]: Writing 2823 bytes from offset 0 in metadata cache (in consumer_metadata_cache_write() at consumer-metadata-cache.c:134)
|
|
DEBUG1 - 16:19:15.575920360 [19216/19225]: Waiting for metadata to be flushed (in lttng_ustconsumer_recv_metadata() at ust-consumer.c:1308)
|
|
DEBUG1 - 16:19:15.575924071 [19216/19223]: Metadata poll return from wait with 2 fd(s) (in consumer_thread_metadata_poll() at consumer.c:2284)
|
|
DEBUG1 - 16:19:15.575929578 [19216/19223]: Metadata event caught in thread (in consumer_thread_metadata_poll() at consumer.c:2286)
|
|
DEBUG1 - 16:19:15.575933778 [19216/19223]: Metadata available on fd 58 (in consumer_thread_metadata_poll() at consumer.c:2378)
|
|
DEBUG1 - 16:19:15.575939710 [19216/19223]: In UST read_subbuffer (wait_fd: 58, name: metadata) (in lttng_ustconsumer_read_subbuffer() at ust-consumer.c:2519)
|
|
DEBUG1 - 16:19:15.576002913 [19216/19223]: Consumer mmap write() ret 4096 (len 4096) (in lttng_consumer_on_read_subbuffer_mmap() at consumer.c:1670)
|
|
DEBUG1 - 16:19:15.576070386 [19216/19223]: In UST read_subbuffer (wait_fd: 58, name: metadata) (in lttng_ustconsumer_read_subbuffer() at ust-consumer.c:2519)
|
|
DEBUG1 - 16:19:15.576075993 [19216/19223]: Metadata poll wait (in consumer_thread_metadata_poll() at consumer.c:2281)
|
|
DEBUG1 - 16:19:15.775983826 [19216/19225]: received command on sock (in consumer_thread_sessiond_poll() at consumer.c:3220)
|
|
DEBUG1 - 16:19:15.776003649 [17803/17813]: Apps thread polling (in thread_manage_apps() at main.c:1473)
|
|
DEBUG1 - 16:19:15.780315662 [19216/19221]: Sent channel monitoring sample for channel key 1, (highest = 84, lowest = 84) (in monitor_timer() at consumer-timer.c:763)
|
|
DEBUG1 - 16:19:15.780320255 [17803/17809]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:509)
|
|
DEBUG1 - 16:19:15.780327933 [17803/17809]: [notification-thread] Handling fd (13) activity (1) (in thread_notification() at notification-thread.c:530)
|
|
DEBUG1 - 16:19:15.780335898 [17803/17809]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session auto-20200114-161838 (highest usage = 84, lowest usage = 84) (in handle_notification_thread_channel_sample() at notification-thread-events.c:2209)
|
|
DEBUG1 - 16:19:15.780341580 [17803/17809]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:507)
|
|
DEBUG3 - 16:19:15.786035390 [17803/19226]: Call RCU deleting app PID 17436 (in delete_ust_app_rcu() at ust-app.c:944)
|
|
DEBUG3 - 16:19:15.786051723 [17803/19226]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.c:203)
|
|
DEBUG3 - 16:19:15.786061502 [17803/19226]: No metadata to push for metadata key 4 (in ust_app_push_metadata() at ust-app.c:579)
|
|
DEBUG3 - 16:19:15.786069379 [17803/19226]: UST app deleting channel channel0 (in delete_ust_app_channel() at ust-app.c:460)
|
|
DEBUG2 - 16:19:15.786108332 [17803/19226]: UST app pid 17436 deleted (in delete_ust_app() at ust-app.c:928)
|
|
DEBUG3 - 16:19:15.786107000 [17803/17806]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:128)
|
|
DEBUG3 - 16:19:15.796195199 [17803/17806]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:124)
|
|
DEBUG3 - 16:19:15.796202548 [17803/17806]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:128)
|
|
DEBUG3 - 16:19:15.806270814 [17803/17806]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:124)
|
|
DEBUG3 - 16:19:15.806276354 [17803/17806]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:128)
|
|
DEBUG3 - 16:19:15.816345178 [17803/17806]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:124)
|
|
DEBUG3 - 16:19:15.816350647 [17803/17806]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:128)
|
|
DEBUG3 - 16:19:15.826418337 [17803/17806]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:124)
|
|
DEBUG3 - 16:19:15.826423855 [17803/17806]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:128)
|
|
DEBUG3 - 16:19:15.836490495 [17803/17806]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:124)
|
|
DEBUG3 - 16:19:15.836495680 [17803/17806]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:128)
|
|
DEBUG3 - 16:19:15.846563560 [17803/17806]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:124)
|
|
DEBUG1 - 16:19:16.780316671 [19216/19221]: Sent channel monitoring sample for channel key 1, (highest = 84, lowest = 84) (in monitor_timer() at consumer-timer.c:763)
|
|
DEBUG1 - 16:19:16.780322104 [17803/17809]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:509)
|
|
DEBUG1 - 16:19:16.780332588 [17803/17809]: [notification-thread] Handling fd (13) activity (1) (in thread_notification() at notification-thread.c:530)
|
|
DEBUG1 - 16:19:16.780340797 [17803/17809]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session auto-20200114-161838 (highest usage = 84, lowest usage = 84) (in handle_notification_thread_channel_sample() at notification-thread-events.c:2209)
|
|
DEBUG1 - 16:19:16.780345473 [17803/17809]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:507)
|
|
DEBUG1 - 16:19:17.780318147 [19216/19221]: Sent channel monitoring sample for channel key 1, (highest = 84, lowest = 84) (in monitor_timer() at consumer-timer.c:763)
|
|
DEBUG1 - 16:19:17.780323470 [17803/17809]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:509)
|
|
DEBUG1 - 16:19:17.780333009 [17803/17809]: [notification-thread] Handling fd (13) activity (1) (in thread_notification() at notification-thread.c:530)
|
|
DEBUG1 - 16:19:17.780343052 [17803/17809]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session auto-20200114-161838 (highest usage = 84, lowest usage = 84) (in handle_notification_thread_channel_sample() at notification-thread-events.c:2209)
|
|
DEBUG1 - 16:19:17.780348148 [17803/17809]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:507)
|
|
DEBUG1 - 16:19:18.780316636 [19216/19221]: Sent channel monitoring sample for channel key 1, (highest = 84, lowest = 84) (in monitor_timer() at consumer-timer.c:763)
|
|
DEBUG1 - 16:19:18.780322291 [17803/17809]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:509)
|
|
DEBUG1 - 16:19:18.780332501 [17803/17809]: [notification-thread] Handling fd (13) activity (1) (in thread_notification() at notification-thread.c:530)
|
|
DEBUG1 - 16:19:18.780340866 [17803/17809]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session auto-20200114-161838 (highest usage = 84, lowest usage = 84) (in handle_notification_thread_channel_sample() at notification-thread-events.c:2209)
|
|
DEBUG1 - 16:19:18.780346498 [17803/17809]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:507)
|
|
DEBUG1 - 16:19:19.780317757 [19216/19221]: Sent channel monitoring sample for channel key 1, (highest = 84, lowest = 84) (in monitor_timer() at consumer-timer.c:763)
|
|
DEBUG1 - 16:19:19.780323299 [17803/17809]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:509)
|
|
DEBUG1 - 16:19:19.780334582 [17803/17809]: [notification-thread] Handling fd (13) activity (1) (in thread_notification() at notification-thread.c:530)
|
|
DEBUG1 - 16:19:19.780342434 [17803/17809]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session auto-20200114-161838 (highest usage = 84, lowest usage = 84) (in handle_notification_thread_channel_sample() at notification-thread-events.c:2209)
|
|
DEBUG1 - 16:19:19.780346795 [17803/17809]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:507)
|
|
DEBUG1 - 16:19:20.780318456 [19216/19221]: Sent channel monitoring sample for channel key 1, (highest = 84, lowest = 84) (in monitor_timer() at consumer-timer.c:763)
|
|
DEBUG1 - 16:19:20.780324328 [17803/17809]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:509)
|
|
DEBUG1 - 16:19:20.780335254 [17803/17809]: [notification-thread] Handling fd (13) activity (1) (in thread_notification() at notification-thread.c:530)
|
|
DEBUG1 - 16:19:20.780343064 [17803/17809]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session auto-20200114-161838 (highest usage = 84, lowest usage = 84) (in handle_notification_thread_channel_sample() at notification-thread-events.c:2209)
|
|
DEBUG1 - 16:19:20.780348105 [17803/17809]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:507)
|
|
DEBUG1 - 16:19:21.780317204 [19216/19221]: Sent channel monitoring sample for channel key 1, (highest = 84, lowest = 84) (in monitor_timer() at consumer-timer.c:763)
|
|
DEBUG1 - 16:19:21.780322294 [17803/17809]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:509)
|
|
DEBUG1 - 16:19:21.780331962 [17803/17809]: [notification-thread] Handling fd (13) activity (1) (in thread_notification() at notification-thread.c:530)
|
|
DEBUG1 - 16:19:21.780340801 [17803/17809]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session auto-20200114-161838 (highest usage = 84, lowest usage = 84) (in handle_notification_thread_channel_sample() at notification-thread-events.c:2209)
|
|
DEBUG1 - 16:19:21.780345525 [17803/17809]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:507)
|
|
DEBUG1 - 16:19:22.780317227 [19216/19221]: Sent channel monitoring sample for channel key 1, (highest = 84, lowest = 84) (in monitor_timer() at consumer-timer.c:763)
|
|
DEBUG1 - 16:19:22.780321870 [17803/17809]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:509)
|
|
DEBUG1 - 16:19:22.780333953 [17803/17809]: [notification-thread] Handling fd (13) activity (1) (in thread_notification() at notification-thread.c:530)
|
|
DEBUG1 - 16:19:22.780341736 [17803/17809]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session auto-20200114-161838 (highest usage = 84, lowest usage = 84) (in handle_notification_thread_channel_sample() at notification-thread-events.c:2209)
|
|
DEBUG1 - 16:19:22.780346712 [17803/17809]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:507)
|
|
DEBUG1 - 16:19:23.780316818 [19216/19221]: Sent channel monitoring sample for channel key 1, (highest = 84, lowest = 84) (in monitor_timer() at consumer-timer.c:763)
|
|
DEBUG1 - 16:19:23.780326163 [17803/17809]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:509)
|
|
DEBUG1 - 16:19:23.780344078 [17803/17809]: [notification-thread] Handling fd (13) activity (1) (in thread_notification() at notification-thread.c:530)
|
|
DEBUG1 - 16:19:23.780357976 [17803/17809]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session auto-20200114-161838 (highest usage = 84, lowest usage = 84) (in handle_notification_thread_channel_sample() at notification-thread-events.c:2209)
|
|
DEBUG1 - 16:19:23.780366462 [17803/17809]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:507)
|
|
DEBUG1 - 16:19:24.780317027 [19216/19221]: Sent channel monitoring sample for channel key 1, (highest = 84, lowest = 84) (in monitor_timer() at consumer-timer.c:763)
|
|
DEBUG1 - 16:19:24.780322518 [17803/17809]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:509)
|
|
DEBUG1 - 16:19:24.780333494 [17803/17809]: [notification-thread] Handling fd (13) activity (1) (in thread_notification() at notification-thread.c:530)
|
|
DEBUG1 - 16:19:24.780341949 [17803/17809]: [notification-thread] Handling channel sample for channel channel0 (key = 1) in session auto-20200114-161838 (highest usage = 84, lowest usage = 84) (in handle_notification_thread_channel_sample() at notification-thread-events.c:2209)
|
|
DEBUG1 - 16:19:24.780346539 [17803/17809]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:507)
|
|
DEBUG1 - 16:19:25.199055644 [17803/17810]: Wait for client response (in thread_manage_clients() at main.c:4389)
|
|
DEBUG1 - 16:19:25.199081635 [17803/17810]: Receiving data from client ... (in thread_manage_clients() at main.c:4434)
|
|
DEBUG1 - 16:19:25.199090606 [17803/17810]: Processing client command 13 (in process_client_msg() at main.c:2877)
|
|
DEBUG1 - 16:19:25.199094837 [17803/17810]: Counting number of available session for UID 1000 GID 1000 (in lttng_sessions_count() at main.c:2846)
|
|
DEBUG1 - 16:19:25.199102457 [17803/17810]: Getting all available session for UID 1000 GID 1000 (in cmd_list_lttng_sessions() at cmd.c:3092)
|
|
DEBUG1 - 16:19:25.199111086 [17803/17810]: Sending response (size: 4396, retcode: Success (10)) (in thread_manage_clients() at main.c:4484)
|
|
DEBUG1 - 16:19:25.199120855 [17803/17810]: Clean command context structure (in clean_command_ctx() at main.c:641)
|
|
DEBUG1 - 16:19:25.199124070 [17803/17810]: Accepting client command ... (in thread_manage_clients() at main.c:4337)
|
|
DEBUG1 - 16:19:25.199195823 [17803/17810]: Wait for client response (in thread_manage_clients() at main.c:4389)
|
|
DEBUG1 - 16:19:25.199203725 [17803/17810]: Receiving data from client ... (in thread_manage_clients() at main.c:4434)
|
|
DEBUG1 - 16:19:25.199210568 [17803/17810]: Processing client command 17 (in process_client_msg() at main.c:2877)
|
|
DEBUG1 - 16:19:25.199213178 [17803/17810]: Getting session auto-20200114-161838 by name (in process_client_msg() at main.c:2970)
|
|
DEBUG2 - 16:19:25.199215643 [17803/17810]: Trying to find session by name auto-20200114-161838 (in session_find_by_name() at session.c:276)
|
|
DEBUG1 - 16:19:25.199219426 [17803/17810]: Stopping all UST traces (in ust_app_stop_trace_all() at ust-app.c:4964)
|
|
DEBUG1 - 16:19:25.199222974 [17803/17810]: Stopping tracing for ust app pid 12709 (in ust_app_stop_trace() at ust-app.c:4502)
|
|
DEBUG3 - 16:19:25.199302627 [17803/17810]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.c:203)
|
|
DEBUG3 - 16:19:25.199309730 [17803/17810]: No metadata to push for metadata key 4 (in ust_app_push_metadata() at ust-app.c:579)
|
|
DEBUG1 - 16:19:25.199312720 [17803/17810]: Stopping tracing for ust app pid 7905 (in ust_app_stop_trace() at ust-app.c:4502)
|
|
DEBUG3 - 16:19:25.199376434 [17803/17810]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.c:203)
|
|
DEBUG3 - 16:19:25.199380388 [17803/17810]: No metadata to push for metadata key 4 (in ust_app_push_metadata() at ust-app.c:579)
|
|
DEBUG1 - 16:19:25.199382804 [17803/17810]: Flushing session buffers for all ust apps (in ust_app_flush_session() at ust-app.c:4659)
|
|
DEBUG2 - 16:19:25.199385959 [17803/17810]: Consumer flush channel key 1 (in consumer_flush_channel() at consumer.c:1220)
|
|
DEBUG1 - 16:19:25.199403270 [19216/19225]: Incoming command on sock (in consumer_thread_sessiond_poll() at consumer.c:3204)
|
|
DEBUG1 - 16:19:25.199420592 [19216/19225]: UST consumer flush channel key 1 (in flush_channel() at ust-consumer.c:751)
|
|
DEBUG1 - 16:19:25.199451508 [19216/19224]: poll num_rdy : 1 (in consumer_thread_data_poll() at consumer.c:2551)
|
|
DEBUG1 - 16:19:25.199461371 [19216/19224]: Normal read on fd 38 (in consumer_thread_data_poll() at consumer.c:2658)
|
|
DEBUG3 - 16:19:25.199464045 [17803/17810]: No metadata to push for metadata key 4 (in ust_app_push_metadata() at ust-app.c:579)
|
|
DEBUG1 - 16:19:25.199461434 [19216/19225]: received command on sock (in consumer_thread_sessiond_poll() at consumer.c:3220)
|
|
DEBUG1 - 16:19:25.199467109 [17803/17810]: Sending response (size: 20, retcode: Success (10)) (in thread_manage_clients() at main.c:4484)
|
|
DEBUG1 - 16:19:25.199466393 [19216/19224]: In UST read_subbuffer (wait_fd: 38, name: channel0_0) (in lttng_ustconsumer_read_subbuffer() at ust-consumer.c:2519)
|
|
DEBUG1 - 16:19:25.199474527 [17803/17810]: Clean command context structure (in clean_command_ctx() at main.c:641)
|
|
DEBUG1 - 16:19:25.199477285 [17803/17810]: Accepting client command ... (in thread_manage_clients() at main.c:4337)
|
|
DEBUG1 - 16:19:25.199502658 [17803/17810]: Wait for client response (in thread_manage_clients() at main.c:4389)
|
|
DEBUG1 - 16:19:25.199509182 [17803/17810]: Receiving data from client ... (in thread_manage_clients() at main.c:4434)
|
|
DEBUG1 - 16:19:25.199510938 [19216/19224]: Consumer mmap write() ret 4096 (len 4096) (in lttng_consumer_on_read_subbuffer_mmap() at consumer.c:1670)
|
|
DEBUG1 - 16:19:25.199515988 [17803/17810]: Processing client command 24 (in process_client_msg() at main.c:2877)
|
|
DEBUG1 - 16:19:25.199518595 [17803/17810]: Getting session auto-20200114-161838 by name (in process_client_msg() at main.c:2970)
|
|
DEBUG2 - 16:19:25.199520901 [17803/17810]: Trying to find session by name auto-20200114-161838 (in session_find_by_name() at session.c:276)
|
|
DEBUG3 - 16:19:25.199523904 [17803/17810]: Consumer data pending for id 0 (in consumer_is_data_pending() at consumer.c:1164)
|
|
DEBUG1 - 16:19:25.199533217 [19216/19225]: Incoming command on sock (in consumer_thread_sessiond_poll() at consumer.c:3204)
|
|
DEBUG1 - 16:19:25.199540763 [19216/19225]: UST consumer data pending command for id 0 (in lttng_ustconsumer_recv_cmd() at ust-consumer.c:1411)
|
|
DEBUG1 - 16:19:25.199543519 [19216/19225]: Consumer data pending command on session id 0 (in consumer_data_pending() at consumer.c:3621)
|
|
DEBUG1 - 16:19:25.199552259 [19216/19225]: received command on sock (in consumer_thread_sessiond_poll() at consumer.c:3220)
|
|
DEBUG1 - 16:19:25.199554848 [17803/17810]: Consumer data is pending for session id 0 (in consumer_is_data_pending() at consumer.c:1200)
|
|
DEBUG1 - 16:19:25.199558469 [17803/17810]: Sending response (size: 21, retcode: Success (10)) (in thread_manage_clients() at main.c:4484)
|
|
DEBUG1 - 16:19:25.199564647 [17803/17810]: Clean command context structure (in clean_command_ctx() at main.c:641)
|
|
DEBUG1 - 16:19:25.199567044 [17803/17810]: Accepting client command ... (in thread_manage_clients() at main.c:4337)
|
|
DEBUG1 - 16:19:25.199572098 [19216/19224]: polling on 6 fd (in consumer_thread_data_poll() at consumer.c:2544)
|
|
DEBUG1 - 16:19:25.199576709 [19216/19224]: poll num_rdy : 3 (in consumer_thread_data_poll() at consumer.c:2551)
|
|
DEBUG1 - 16:19:25.199579022 [19216/19224]: Normal read on fd 42 (in consumer_thread_data_poll() at consumer.c:2658)
|
|
DEBUG1 - 16:19:25.199581485 [19216/19224]: In UST read_subbuffer (wait_fd: 42, name: channel0_2) (in lttng_ustconsumer_read_subbuffer() at ust-consumer.c:2519)
|
|
DEBUG1 - 16:19:25.199593172 [19216/19224]: Consumer mmap write() ret 4096 (len 4096) (in lttng_consumer_on_read_subbuffer_mmap() at consumer.c:1670)
|
|
DEBUG1 - 16:19:25.199612865 [19216/19224]: Normal read on fd 40 (in consumer_thread_data_poll() at consumer.c:2658)
|
|
DEBUG1 - 16:19:25.199615533 [19216/19224]: In UST read_subbuffer (wait_fd: 40, name: channel0_1) (in lttng_ustconsumer_read_subbuffer() at ust-consumer.c:2519)
|
|
DEBUG1 - 16:19:25.199625137 [19216/19224]: Consumer mmap write() ret 4096 (len 4096) (in lttng_consumer_on_read_subbuffer_mmap() at consumer.c:1670)
|
|
DEBUG1 - 16:19:25.199641034 [19216/19224]: Normal read on fd 44 (in consumer_thread_data_poll() at consumer.c:2658)
|
|
DEBUG1 - 16:19:25.199643697 [19216/19224]: In UST read_subbuffer (wait_fd: 44, name: channel0_3) (in lttng_ustconsumer_read_subbuffer() at ust-consumer.c:2519)
|
|
DEBUG1 - 16:19:25.199653676 [19216/19224]: Consumer mmap write() ret 4096 (len 4096) (in lttng_consumer_on_read_subbuffer_mmap() at consumer.c:1670)
|
|
DEBUG1 - 16:19:25.199668885 [19216/19224]: polling on 6 fd (in consumer_thread_data_poll() at consumer.c:2544)
|
|
DEBUG1 - 16:19:25.399737708 [17803/17810]: Wait for client response (in thread_manage_clients() at main.c:4389)
|
|
DEBUG1 - 16:19:25.399759646 [17803/17810]: Receiving data from client ... (in thread_manage_clients() at main.c:4434)
|
|
DEBUG1 - 16:19:25.399768824 [17803/17810]: Processing client command 24 (in process_client_msg() at main.c:2877)
|
|
DEBUG1 - 16:19:25.399772014 [17803/17810]: Getting session auto-20200114-161838 by name (in process_client_msg() at main.c:2970)
|
|
DEBUG2 - 16:19:25.399774831 [17803/17810]: Trying to find session by name auto-20200114-161838 (in session_find_by_name() at session.c:276)
|
|
DEBUG3 - 16:19:25.399779086 [17803/17810]: Consumer data pending for id 0 (in consumer_is_data_pending() at consumer.c:1164)
|
|
DEBUG1 - 16:19:25.399798551 [19216/19225]: Incoming command on sock (in consumer_thread_sessiond_poll() at consumer.c:3204)
|
|
DEBUG1 - 16:19:25.399814264 [19216/19225]: UST consumer data pending command for id 0 (in lttng_ustconsumer_recv_cmd() at ust-consumer.c:1411)
|
|
DEBUG1 - 16:19:25.399817908 [19216/19225]: Consumer data pending command on session id 0 (in consumer_data_pending() at consumer.c:3621)
|
|
DEBUG1 - 16:19:25.399823976 [19216/19225]: UST consumer checking data pending (in lttng_ustconsumer_data_pending() at ust-consumer.c:2742)
|
|
DEBUG1 - 16:19:25.399828748 [19216/19225]: UST consumer checking data pending (in lttng_ustconsumer_data_pending() at ust-consumer.c:2742)
|
|
DEBUG1 - 16:19:25.399831049 [19216/19225]: UST consumer checking data pending (in lttng_ustconsumer_data_pending() at ust-consumer.c:2742)
|
|
DEBUG1 - 16:19:25.399833495 [19216/19225]: UST consumer checking data pending (in lttng_ustconsumer_data_pending() at ust-consumer.c:2742)
|
|
DEBUG1 - 16:19:25.399835942 [19216/19225]: UST consumer checking data pending (in lttng_ustconsumer_data_pending() at ust-consumer.c:2742)
|
|
DEBUG1 - 16:19:25.399838394 [19216/19225]: UST consumer metadata pending check: contiguous 2823 vs pushed 2823 (in lttng_ustconsumer_data_pending() at ust-consumer.c:2767)
|
|
DEBUG1 - 16:19:25.399845498 [19216/19225]: received command on sock (in consumer_thread_sessiond_poll() at consumer.c:3220)
|
|
DEBUG1 - 16:19:25.399848422 [17803/17810]: Consumer data is NOT pending for session id 0 (in consumer_is_data_pending() at consumer.c:1200)
|
|
DEBUG1 - 16:19:25.399853330 [17803/17810]: Sending response (size: 21, retcode: Success (10)) (in thread_manage_clients() at main.c:4484)
|
|
DEBUG1 - 16:19:25.399862586 [17803/17810]: Clean command context structure (in clean_command_ctx() at main.c:641)
|
|
DEBUG1 - 16:19:25.399866071 [17803/17810]: Accepting client command ... (in thread_manage_clients() at main.c:4337)
|
|
DEBUG1 - 16:19:25.399912809 [17803/17810]: Wait for client response (in thread_manage_clients() at main.c:4389)
|
|
DEBUG1 - 16:19:25.399921903 [17803/17810]: Receiving data from client ... (in thread_manage_clients() at main.c:4434)
|
|
DEBUG1 - 16:19:25.399928705 [17803/17810]: Processing client command 13 (in process_client_msg() at main.c:2877)
|
|
DEBUG1 - 16:19:25.399931281 [17803/17810]: Counting number of available session for UID 1000 GID 1000 (in lttng_sessions_count() at main.c:2846)
|
|
DEBUG1 - 16:19:25.399935200 [17803/17810]: Getting all available session for UID 1000 GID 1000 (in cmd_list_lttng_sessions() at cmd.c:3092)
|
|
DEBUG1 - 16:19:25.399940653 [17803/17810]: Sending response (size: 4396, retcode: Success (10)) (in thread_manage_clients() at main.c:4484)
|
|
DEBUG1 - 16:19:25.399947612 [17803/17810]: Clean command context structure (in clean_command_ctx() at main.c:641)
|
|
DEBUG1 - 16:19:25.399950122 [17803/17810]: Accepting client command ... (in thread_manage_clients() at main.c:4337)
|
|
DEBUG1 - 16:19:25.399991334 [17803/17810]: Wait for client response (in thread_manage_clients() at main.c:4389)
|
|
DEBUG1 - 16:19:25.399998631 [17803/17810]: Receiving data from client ... (in thread_manage_clients() at main.c:4434)
|
|
DEBUG1 - 16:19:25.400005651 [17803/17810]: Processing client command 11 (in process_client_msg() at main.c:2877)
|
|
DEBUG1 - 16:19:25.400008051 [17803/17810]: Getting session auto-20200114-161838 by name (in process_client_msg() at main.c:2970)
|
|
DEBUG2 - 16:19:25.400010409 [17803/17810]: Trying to find session by name auto-20200114-161838 (in session_find_by_name() at session.c:276)
|
|
DEBUG3 - 16:19:25.400016769 [17803/17810]: Listing domains found UST global domain (in cmd_list_domains() at cmd.c:2894)
|
|
DEBUG1 - 16:19:25.400021059 [17803/17810]: Sending response (size: 328, retcode: Success (10)) (in thread_manage_clients() at main.c:4484)
|
|
DEBUG1 - 16:19:25.400027593 [17803/17810]: Clean command context structure (in clean_command_ctx() at main.c:641)
|
|
DEBUG1 - 16:19:25.400030007 [17803/17810]: Accepting client command ... (in thread_manage_clients() at main.c:4337)
|
|
DEBUG1 - 16:19:25.400056816 [17803/17810]: Wait for client response (in thread_manage_clients() at main.c:4389)
|
|
DEBUG1 - 16:19:25.400063110 [17803/17810]: Receiving data from client ... (in thread_manage_clients() at main.c:4434)
|
|
DEBUG1 - 16:19:25.400069627 [17803/17810]: Processing client command 10 (in process_client_msg() at main.c:2877)
|
|
DEBUG1 - 16:19:25.400071997 [17803/17810]: Getting session auto-20200114-161838 by name (in process_client_msg() at main.c:2970)
|
|
DEBUG2 - 16:19:25.400074287 [17803/17810]: Trying to find session by name auto-20200114-161838 (in session_find_by_name() at session.c:276)
|
|
DEBUG3 - 16:19:25.400077949 [17803/17810]: Consumer socket created (fd: 45) and added to output (in consumer_create_socket() at consumer.c:301)
|
|
DEBUG1 - 16:19:25.400080928 [17803/17810]: Setting relayd for session auto-20200114-161838 (in cmd_setup_relayd() at cmd.c:1043)
|
|
DEBUG3 - 16:19:25.400084315 [17803/17810]: Number of UST global channels 1 (in cmd_list_channels() at cmd.c:2977)
|
|
DEBUG1 - 16:19:25.400087147 [17803/17810]: Listing channels for session auto-20200114-161838 (in list_lttng_channels() at cmd.c:255)
|
|
DEBUG3 - 16:19:25.400090971 [17803/17810]: Consumer discarded events id 0 (in consumer_get_discarded_events() at consumer.c:1476)
|
|
DEBUG1 - 16:19:25.400100870 [19216/19225]: Incoming command on sock (in consumer_thread_sessiond_poll() at consumer.c:3204)
|
|
DEBUG1 - 16:19:25.400108369 [19216/19225]: UST consumer discarded events command for session id 0 (in lttng_ustconsumer_recv_cmd() at ust-consumer.c:1790)
|
|
DEBUG1 - 16:19:25.400111568 [19216/19225]: UST consumer discarded events command for session id 0, channel key 1 (in lttng_ustconsumer_recv_cmd() at ust-consumer.c:1817)
|
|
DEBUG1 - 16:19:25.400116420 [19216/19225]: received command on sock (in consumer_thread_sessiond_poll() at consumer.c:3220)
|
|
DEBUG1 - 16:19:25.400119180 [17803/17810]: Consumer discarded 0 events in session id 0 (in consumer_get_discarded_events() at consumer.c:1513)
|
|
DEBUG1 - 16:19:25.400122808 [17803/17810]: Sending response (size: 676, retcode: Success (10)) (in thread_manage_clients() at main.c:4484)
|
|
DEBUG1 - 16:19:25.400129232 [17803/17810]: Clean command context structure (in clean_command_ctx() at main.c:641)
|
|
DEBUG1 - 16:19:25.400131602 [17803/17810]: Accepting client command ... (in thread_manage_clients() at main.c:4337)
|
|
DEBUG1 - 16:19:25.400159535 [17803/17810]: Wait for client response (in thread_manage_clients() at main.c:4389)
|
|
DEBUG1 - 16:19:25.400165785 [17803/17810]: Receiving data from client ... (in thread_manage_clients() at main.c:4434)
|
|
DEBUG1 - 16:19:25.400172371 [17803/17810]: Processing client command 17 (in process_client_msg() at main.c:2877)
|
|
DEBUG1 - 16:19:25.400174819 [17803/17810]: Getting session auto-20200114-161838 by name (in process_client_msg() at main.c:2970)
|
|
DEBUG2 - 16:19:25.400177078 [17803/17810]: Trying to find session by name auto-20200114-161838 (in session_find_by_name() at session.c:276)
|
|
DEBUG1 - 16:19:25.400179718 [17803/17810]: Sending response (size: 20, retcode: Tracing has already been stopped (81)) (in thread_manage_clients() at main.c:4484)
|
|
DEBUG1 - 16:19:25.400186084 [17803/17810]: Clean command context structure (in clean_command_ctx() at main.c:641)
|
|
DEBUG1 - 16:19:25.400188360 [17803/17810]: Accepting client command ... (in thread_manage_clients() at main.c:4337)
|
|
DEBUG1 - 16:19:25.400212773 [17803/17810]: Wait for client response (in thread_manage_clients() at main.c:4389)
|
|
DEBUG1 - 16:19:25.400219008 [17803/17810]: Receiving data from client ... (in thread_manage_clients() at main.c:4434)
|
|
DEBUG1 - 16:19:25.400225569 [17803/17810]: Processing client command 9 (in process_client_msg() at main.c:2877)
|
|
DEBUG1 - 16:19:25.400228050 [17803/17810]: Getting session auto-20200114-161838 by name (in process_client_msg() at main.c:2970)
|
|
DEBUG2 - 16:19:25.400230319 [17803/17810]: Trying to find session by name auto-20200114-161838 (in session_find_by_name() at session.c:276)
|
|
DEBUG3 - 16:19:25.400233215 [17803/17810]: No kernel session when tearing down session (in kernel_destroy_session() at kernel.c:898)
|
|
DEBUG1 - 16:19:25.400236193 [17803/17810]: Destroy all UST traces (in ust_app_destroy_trace_all() at ust-app.c:4992)
|
|
DEBUG1 - 16:19:25.400239125 [17803/17810]: Destroy tracing for ust app pid 12709 (in destroy_trace() at ust-app.c:4885)
|
|
DEBUG3 - 16:19:25.400243369 [17803/17810]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.c:203)
|
|
DEBUG3 - 16:19:25.400247288 [17803/17810]: No metadata to push for metadata key 4 (in ust_app_push_metadata() at ust-app.c:579)
|
|
DEBUG3 - 16:19:25.400250788 [17803/17810]: UST app deleting channel channel0 (in delete_ust_app_channel() at ust-app.c:460)
|
|
DEBUG1 - 16:19:25.400387584 [17803/17810]: Destroy tracing for ust app pid 7905 (in destroy_trace() at ust-app.c:4885)
|
|
DEBUG3 - 16:19:25.400392068 [17803/17810]: Buffer registry per UID find id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_find() at buffer-registry.c:203)
|
|
DEBUG3 - 16:19:25.400394621 [17803/17810]: No metadata to push for metadata key 4 (in ust_app_push_metadata() at ust-app.c:579)
|
|
DEBUG3 - 16:19:25.400397479 [17803/17810]: UST app deleting channel channel0 (in delete_ust_app_channel() at ust-app.c:460)
|
|
DEBUG2 - 16:19:25.400508721 [17803/17810]: Trace UST destroy session 0 (in trace_ust_destroy_session() at trace-ust.c:1163)
|
|
DEBUG3 - 16:19:25.400522105 [17803/17810]: Buffer registry per UID destroy with id: 0, ABI: 64, uid: 1000 (in buffer_reg_uid_destroy() at buffer-registry.c:678)
|
|
DEBUG3 - 16:19:25.400524502 [17803/17806]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:128)
|
|
DEBUG2 - 16:19:25.400534929 [17803/17810]: Consumer close metadata channel key 4 (in consumer_close_metadata() at consumer.c:1286)
|
|
DEBUG1 - 16:19:25.400554052 [19216/19225]: Incoming command on sock (in consumer_thread_sessiond_poll() at consumer.c:3204)
|
|
DEBUG1 - 16:19:25.400560890 [19216/19225]: UST consumer close metadata key 4 (in close_metadata() at ust-consumer.c:836)
|
|
DEBUG1 - 16:19:25.400564347 [19216/19225]: Closing metadata channel key 4 (in lttng_ustconsumer_close_metadata() at ust-consumer.c:2808)
|
|
DEBUG1 - 16:19:25.400575862 [19216/19225]: received command on sock (in consumer_thread_sessiond_poll() at consumer.c:3220)
|
|
DEBUG1 - 16:19:25.400577477 [19216/19223]: Metadata poll return from wait with 2 fd(s) (in consumer_thread_metadata_poll() at consumer.c:2284)
|
|
DEBUG1 - 16:19:25.400580952 [17803/17810]: Destroying session auto-20200114-161838 (in session_destroy() at session.c:331)
|
|
DEBUG1 - 16:19:25.400582741 [19216/19223]: Metadata event caught in thread (in consumer_thread_metadata_poll() at consumer.c:2286)
|
|
DEBUG1 - 16:19:25.400587013 [19216/19223]: Metadata fd 58 is hup|err. (in consumer_thread_metadata_poll() at consumer.c:2400)
|
|
DEBUG1 - 16:19:25.400590287 [17803/17810]: Empty ltt_sessions_ht_by_id, destroying it (in del_session_ht() at session.c:240)
|
|
DEBUG1 - 16:19:25.400590429 [19216/19223]: Attempting to flush and consume the UST buffers (in consumer_thread_metadata_poll() at consumer.c:2404)
|
|
DEBUG1 - 16:19:25.400597625 [17803/17810]: Sending response (size: 20, retcode: Success (10)) (in thread_manage_clients() at main.c:4484)
|
|
DEBUG1 - 16:19:25.400604836 [17803/17810]: Clean command context structure (in clean_command_ctx() at main.c:641)
|
|
DEBUG1 - 16:19:25.400607244 [17803/17810]: Accepting client command ... (in thread_manage_clients() at main.c:4337)
|
|
DEBUG1 - 16:19:25.400606990 [19216/19223]: In UST read_subbuffer (wait_fd: 58, name: metadata) (in lttng_ustconsumer_read_subbuffer() at ust-consumer.c:2519)
|
|
DEBUG1 - 16:19:25.400625372 [19216/19223]: Consumer mmap write() ret 4096 (len 4096) (in lttng_consumer_on_read_subbuffer_mmap() at consumer.c:1670)
|
|
DEBUG1 - 16:19:25.400677267 [19216/19223]: In UST read_subbuffer (wait_fd: 58, name: metadata) (in lttng_ustconsumer_read_subbuffer() at ust-consumer.c:2519)
|
|
DEBUG1 - 16:19:25.400688233 [19216/19223]: Closing metadata channel key 4 (in lttng_ustconsumer_close_metadata() at ust-consumer.c:2808)
|
|
DEBUG1 - 16:19:25.400706922 [19216/19223]: Consumer delete channel key 4 (in consumer_del_channel() at consumer.c:363)
|
|
DEBUG1 - 16:19:25.400745716 [19216/19223]: Metadata poll wait (in consumer_thread_metadata_poll() at consumer.c:2281)
|
|
DEBUG1 - 16:19:25.400758516 [19216/19691]: Destroying metadata cache (in consumer_metadata_cache_destroy() at consumer-metadata-cache.c:220)
|
|
DEBUG2 - 16:19:25.410392973 [17803/19226]: Trace destroy UST event hello_world:my_first_tracepoint (in trace_ust_destroy_event() at trace-ust.c:1007)
|
|
DEBUG2 - 16:19:25.410401414 [17803/19226]: Trace destroy UST channel channel0 (in _trace_ust_destroy_channel() at trace-ust.c:1072)
|
|
DEBUG3 - 16:19:25.410404954 [17803/19226]: Buffer registry session destroy (in buffer_reg_session_destroy() at buffer-registry.c:597)
|
|
DEBUG3 - 16:19:25.410409037 [17803/19226]: Buffer registry channel destroy with key 0 (in buffer_reg_channel_destroy() at buffer-registry.c:552)
|
|
DEBUG3 - 16:19:25.410411997 [17803/19226]: Buffer registry stream destroy with handle -1 (in buffer_reg_stream_destroy() at buffer-registry.c:500)
|
|
DEBUG3 - 16:19:25.410417111 [17803/19226]: Buffer registry stream destroy with handle -1 (in buffer_reg_stream_destroy() at buffer-registry.c:500)
|
|
DEBUG3 - 16:19:25.410420790 [17803/19226]: Buffer registry stream destroy with handle -1 (in buffer_reg_stream_destroy() at buffer-registry.c:500)
|
|
DEBUG3 - 16:19:25.410424326 [17803/19226]: Buffer registry stream destroy with handle -1 (in buffer_reg_stream_destroy() at buffer-registry.c:500)
|
|
DEBUG1 - 16:19:25.410436735 [19216/19222]: Channel poll return from wait with 2 fd(s) (in consumer_thread_channel_poll() at consumer.c:2879)
|
|
DEBUG1 - 16:19:25.410440438 [17803/19226]: Beginning of waiter wait period (in lttng_waiter_wait() at waiter.c:58)
|
|
DEBUG1 - 16:19:25.410443975 [19216/19222]: Channel event caught in thread (in consumer_thread_channel_poll() at consumer.c:2881)
|
|
DEBUG1 - 16:19:25.410444773 [17803/17809]: [notification-thread] Poll wait returned (1) (in thread_notification() at notification-thread.c:509)
|
|
DEBUG1 - 16:19:25.410448107 [19216/19222]: Channel fd 35 is hup|err. (in consumer_thread_channel_poll() at consumer.c:3025)
|
|
DEBUG1 - 16:19:25.410451982 [17803/17809]: [notification-thread] Handling fd (24) activity (1) (in thread_notification() at notification-thread.c:530)
|
|
DEBUG1 - 16:19:25.410457719 [17803/17809]: [notification-thread] Received remove channel command (in handle_notification_thread_command() at notification-thread-events.c:1306)
|
|
DEBUG1 - 16:19:25.410460888 [17803/17809]: [notification-thread] Removing channel key = 1 in user space domain (in handle_notification_thread_command_remove_channel() at notification-thread-events.c:889)
|
|
DEBUG1 - 16:19:25.410469168 [17803/17809]: [notification-thread] Entering poll wait (in thread_notification() at notification-thread.c:507)
|
|
DEBUG1 - 16:19:25.410465921 [19216/19224]: poll num_rdy : 2 (in consumer_thread_data_poll() at consumer.c:2551)
|
|
DEBUG1 - 16:19:25.410469448 [17803/19226]: End of waiter wait period (in lttng_waiter_wait() at waiter.c:101)
|
|
DEBUG1 - 16:19:25.410466269 [19216/19222]: Channel poll wait (in consumer_thread_channel_poll() at consumer.c:2875)
|
|
DEBUG1 - 16:19:25.410488273 [19216/19224]: fd 38 is hup|err|nval. Attempting flush and read. (in consumer_thread_data_poll() at consumer.c:2683)
|
|
DEBUG1 - 16:19:25.410506395 [19216/19224]: Polling fd 38 tells it has hung up. (in consumer_thread_data_poll() at consumer.c:2694)
|
|
DEBUG1 - 16:19:25.410509190 [19216/19224]: fd 40 is hup|err|nval. Attempting flush and read. (in consumer_thread_data_poll() at consumer.c:2683)
|
|
DEBUG1 - 16:19:25.410511743 [19216/19224]: Polling fd 40 tells it has hung up. (in consumer_thread_data_poll() at consumer.c:2694)
|
|
DEBUG1 - 16:19:25.410514269 [19216/19224]: polling on 6 fd (in consumer_thread_data_poll() at consumer.c:2544)
|
|
DEBUG1 - 16:19:25.410518047 [19216/19224]: poll num_rdy : 4 (in consumer_thread_data_poll() at consumer.c:2551)
|
|
DEBUG1 - 16:19:25.410520395 [19216/19224]: Normal read on fd 38 (in consumer_thread_data_poll() at consumer.c:2658)
|
|
DEBUG1 - 16:19:25.410522908 [19216/19224]: In UST read_subbuffer (wait_fd: 38, name: channel0_0) (in lttng_ustconsumer_read_subbuffer() at ust-consumer.c:2519)
|
|
DEBUG1 - 16:19:25.410526249 [19216/19224]: Reserving sub buffer failed (everything is normal, it is due to concurrency) [ret: -11] (in lttng_ustconsumer_read_subbuffer() at ust-consumer.c:2570)
|
|
DEBUG1 - 16:19:25.410528692 [19216/19224]: Normal read on fd 40 (in consumer_thread_data_poll() at consumer.c:2658)
|
|
DEBUG1 - 16:19:25.410530931 [19216/19224]: In UST read_subbuffer (wait_fd: 40, name: channel0_1) (in lttng_ustconsumer_read_subbuffer() at ust-consumer.c:2519)
|
|
DEBUG1 - 16:19:25.410533448 [19216/19224]: Reserving sub buffer failed (everything is normal, it is due to concurrency) [ret: -11] (in lttng_ustconsumer_read_subbuffer() at ust-consumer.c:2570)
|
|
DEBUG1 - 16:19:25.410535804 [19216/19224]: fd 42 is hup|err|nval. Attempting flush and read. (in consumer_thread_data_poll() at consumer.c:2683)
|
|
DEBUG1 - 16:19:25.410538134 [19216/19224]: Polling fd 42 tells it has hung up. (in consumer_thread_data_poll() at consumer.c:2694)
|
|
DEBUG1 - 16:19:25.410540384 [19216/19224]: Polling fd 38 tells it has hung up. (in consumer_thread_data_poll() at consumer.c:2694)
|
|
DEBUG1 - 16:19:25.410544709 [19216/19224]: Consumer stream destroy monitored key: 38 (in destroy_close_stream() at consumer-stream.c:265)
|
|
DEBUG1 - 16:19:25.410559396 [19216/19224]: Polling fd 40 tells it has hung up. (in consumer_thread_data_poll() at consumer.c:2694)
|
|
DEBUG1 - 16:19:25.410562144 [19216/19224]: Consumer stream destroy monitored key: 40 (in destroy_close_stream() at consumer-stream.c:265)
|
|
DEBUG1 - 16:19:25.410569506 [19216/19224]: fd 44 is hup|err|nval. Attempting flush and read. (in consumer_thread_data_poll() at consumer.c:2683)
|
|
DEBUG1 - 16:19:25.410571873 [19216/19224]: Polling fd 44 tells it has hung up. (in consumer_thread_data_poll() at consumer.c:2694)
|
|
DEBUG1 - 16:19:25.410575023 [19216/19224]: Updating poll fd array (in update_poll_array() at consumer.c:1091)
|
|
DEBUG1 - 16:19:25.410578087 [19216/19224]: polling on 4 fd (in consumer_thread_data_poll() at consumer.c:2544)
|
|
DEBUG1 - 16:19:25.410581009 [19216/19224]: poll num_rdy : 2 (in consumer_thread_data_poll() at consumer.c:2551)
|
|
DEBUG1 - 16:19:25.410583307 [19216/19224]: Normal read on fd 42 (in consumer_thread_data_poll() at consumer.c:2658)
|
|
DEBUG1 - 16:19:25.410585591 [19216/19224]: In UST read_subbuffer (wait_fd: 42, name: channel0_2) (in lttng_ustconsumer_read_subbuffer() at ust-consumer.c:2519)
|
|
DEBUG1 - 16:19:25.410588001 [19216/19224]: Reserving sub buffer failed (everything is normal, it is due to concurrency) [ret: -11] (in lttng_ustconsumer_read_subbuffer() at ust-consumer.c:2570)
|
|
DEBUG1 - 16:19:25.410590231 [19216/19224]: Normal read on fd 44 (in consumer_thread_data_poll() at consumer.c:2658)
|
|
DEBUG1 - 16:19:25.410592384 [19216/19224]: In UST read_subbuffer (wait_fd: 44, name: channel0_3) (in lttng_ustconsumer_read_subbuffer() at ust-consumer.c:2519)
|
|
DEBUG1 - 16:19:25.410594829 [19216/19224]: Reserving sub buffer failed (everything is normal, it is due to concurrency) [ret: -11] (in lttng_ustconsumer_read_subbuffer() at ust-consumer.c:2570)
|
|
DEBUG1 - 16:19:25.410597023 [19216/19224]: Polling fd 42 tells it has hung up. (in consumer_thread_data_poll() at consumer.c:2694)
|
|
DEBUG1 - 16:19:25.410599553 [19216/19224]: Consumer stream destroy monitored key: 42 (in destroy_close_stream() at consumer-stream.c:265)
|
|
DEBUG1 - 16:19:25.410606620 [19216/19224]: Polling fd 44 tells it has hung up. (in consumer_thread_data_poll() at consumer.c:2694)
|
|
DEBUG1 - 16:19:25.410609179 [19216/19224]: Consumer stream destroy monitored key: 44 (in destroy_close_stream() at consumer-stream.c:265)
|
|
DEBUG1 - 16:19:25.410616494 [19216/19224]: Consumer delete channel key 1 (in consumer_del_channel() at consumer.c:363)
|
|
DEBUG3 - 16:19:25.410619622 [17803/17806]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:124)
|
|
DEBUG3 - 16:19:25.410625538 [17803/17806]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:128)
|
|
DEBUG1 - 16:19:25.410642883 [19216/19221]: Signal timer metadata thread teardown (in consumer_timer_thread() at consumer-timer.c:835)
|
|
DEBUG1 - 16:19:25.410646997 [19216/19224]: Updating poll fd array (in update_poll_array() at consumer.c:1091)
|
|
DEBUG1 - 16:19:25.410653102 [19216/19224]: polling on 2 fd (in consumer_thread_data_poll() at consumer.c:2544)
|
|
DEBUG3 - 16:19:25.420700959 [17803/17806]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:124)
|
|
DEBUG3 - 16:19:25.420715445 [17803/17806]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:128)
|
|
DEBUG3 - 16:19:25.430790351 [17803/17806]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:124)
|
|
DEBUG3 - 16:19:25.430798497 [17803/17806]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:128)
|
|
DEBUG3 - 16:19:25.440867454 [17803/17806]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:124)
|
|
DEBUG3 - 16:19:25.440873285 [17803/17806]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:128)
|
|
DEBUG3 - 16:19:25.450941137 [17803/17806]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:124)
|
|
DEBUG3 - 16:19:25.450946771 [17803/17806]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:128)
|
|
DEBUG3 - 16:19:25.460975516 [17803/17806]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:124)
|
|
DEBUG3 - 16:19:25.460981207 [17803/17806]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:128)
|
|
DEBUG3 - 16:19:25.471037780 [17803/17806]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:124)
|
|
DEBUG3 - 16:19:25.471043189 [17803/17806]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:128)
|
|
DEBUG3 - 16:19:25.481111074 [17803/17806]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:124)
|
|
DEBUG3 - 16:19:25.481116473 [17803/17806]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:128)
|
|
DEBUG3 - 16:19:25.491183127 [17803/17806]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:124)
|
|
DEBUG3 - 16:19:25.491188564 [17803/17806]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:128)
|
|
DEBUG3 - 16:19:25.501254902 [17803/17806]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:124)
|
|
DEBUG3 - 16:19:25.501260183 [17803/17806]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:128)
|
|
DEBUG3 - 16:19:25.511328479 [17803/17806]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:124)
|
|
DEBUG3 - 16:19:25.511333768 [17803/17806]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:128)
|
|
DEBUG3 - 16:19:25.521401430 [17803/17806]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:124)
|
|
DEBUG3 - 16:19:25.521406709 [17803/17806]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:128)
|
|
DEBUG3 - 16:19:25.531476772 [17803/17806]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:124)
|
|
DEBUG3 - 16:19:25.531483023 [17803/17806]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:128)
|
|
DEBUG3 - 16:19:25.541551131 [17803/17806]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:124)
|
|
DEBUG3 - 16:19:25.541557599 [17803/17806]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:128)
|
|
DEBUG3 - 16:19:25.551625031 [17803/17806]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:124)
|
|
DEBUG3 - 16:19:25.551630150 [17803/17806]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:128)
|
|
DEBUG3 - 16:19:25.561696750 [17803/17806]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:124)
|
|
DEBUG3 - 16:19:25.561701912 [17803/17806]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:128)
|
|
DEBUG3 - 16:19:25.571768231 [17803/17806]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:124)
|
|
DEBUG3 - 16:19:25.571774125 [17803/17806]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:128)
|
|
DEBUG3 - 16:19:25.581840687 [17803/17806]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:124)
|