/sys/kernel/debug/tracing # cat trace # tracer: function_graph # # CPU DURATION FUNCTION CALLS # | | | | | | | 0) | __request_module() { 0) 0.256 us | current_is_async(); 0) | security_kernel_module_request() { 0) 0.307 us | integrity_kernel_module_request(); 0) 0.625 us | } 0) | kmem_cache_alloc_trace() { 0) | _cond_resched() { 0) 0.123 us | rcu_all_qs(); 0) 0.355 us | } 0) 0.122 us | should_failslab(); 0) | _cond_resched() { 0) 0.120 us | rcu_all_qs(); 0) 0.355 us | } 0) 0.120 us | memcg_kmem_put_cache(); 0) 1.563 us | } 0) | kstrdup() { 0) | __kmalloc_track_caller() { 0) 0.115 us | kmalloc_slab(); 0) | _cond_resched() { 0) 0.118 us | rcu_all_qs(); 0) 0.348 us | } 0) 0.119 us | should_failslab(); 0) | _cond_resched() { 0) 0.115 us | rcu_all_qs(); 0) 0.345 us | } 0) 0.119 us | memcg_kmem_put_cache(); 0) 1.757 us | } 0) 2.040 us | } 0) | call_usermodehelper_setup() { 0) | kmem_cache_alloc_trace() { 0) | _cond_resched() { 0) 0.116 us | rcu_all_qs(); 0) 0.345 us | } 0) 0.117 us | should_failslab(); 0) | _cond_resched() { 0) 0.118 us | rcu_all_qs(); 0) 0.347 us | } 0) 0.123 us | memcg_kmem_put_cache(); 0) 1.792 us | } 0) 2.023 us | } 0) | call_usermodehelper_exec() { 0) | queue_work_on() { 0) | __queue_work() { 0) 0.126 us | get_work_pool(); 0) 0.183 us | _raw_spin_lock(); 0) | insert_work() { 0) 0.121 us | get_pwq.isra.0(); 0) | wake_up_process() { 0) | try_to_wake_up() { 0) 0.227 us | _raw_spin_lock_irqsave(); 0) | select_task_rq_fair() { 0) 0.133 us | available_idle_cpu(); 0) 0.166 us | update_cfs_rq_h_load(); 0) | select_idle_sibling() { 0) 0.137 us | available_idle_cpu(); 0) 0.371 us | } 0) 1.299 us | } 0) 0.133 us | _raw_spin_lock(); 0) 0.148 us | update_rq_clock(); 0) | ttwu_do_activate() { 0) | activate_task() { 0) | enqueue_task_fair() { 0) | enqueue_entity() { 0) 0.123 us | update_curr(); 0) | __update_load_avg_se() { 0) 0.118 us | __accumulate_pelt_segments(); 0) 0.420 us | } 0) 0.125 us | __update_load_avg_cfs_rq(); 0) 0.122 us | update_cfs_group(); 0) 0.138 us | account_entity_enqueue(); 0) 0.120 us | place_entity(); 0) 0.119 us | __enqueue_entity(); 0) 2.146 us | } 0) 0.115 us | hrtick_update(); 0) 2.624 us | } 0) 2.890 us | } 0) | ttwu_do_wakeup() { 0) | check_preempt_curr() { 0) 0.130 us | resched_curr(); 0) 0.417 us | } 0) 1.034 us | } 0) 4.269 us | } 0) 0.410 us | _raw_spin_unlock_irqrestore(); 0) 7.466 us | } 0) 7.702 us | } 0) 8.164 us | } 0) 9.079 us | } 0) 9.370 us | } 0) | wait_for_completion_killable() { 0) | _cond_resched() { 0) 0.118 us | rcu_all_qs(); 0) 0.365 us | } 0) 0.122 us | _raw_spin_lock_irq(); 0) | schedule_timeout() { 0) | schedule() { 0) | rcu_note_context_switch() { 0) 0.147 us | rcu_qs(); 0) 0.384 us | } 0) 0.124 us | _raw_spin_lock(); 0) 0.144 us | update_rq_clock(); 0) | deactivate_task() { 0) | dequeue_task_fair() { 0) | dequeue_entity() { 0) | update_curr() { 0) 0.121 us | update_min_vruntime(); 0) 0.132 us | cpuacct_charge(); 0) | __cgroup_account_cputime() { 0) 0.124 us | cgroup_rstat_updated(); 0) 0.354 us | } 0) 1.088 us | } 0) 0.127 us | __update_load_avg_se(); 0) 0.136 us | __update_load_avg_cfs_rq(); 0) 0.118 us | clear_buddies(); 0) 0.124 us | account_entity_dequeue(); 0) 0.120 us | update_cfs_group(); 0) 0.128 us | update_min_vruntime(); 0) 2.780 us | } 0) 0.114 us | hrtick_update(); 0) 3.242 us | } 0) 3.503 us | } 0) | pick_next_task_fair() { 0) 0.121 us | __msecs_to_jiffies(); 0) 0.389 us | } 0) | pick_next_task_idle() { 0) | put_prev_task_fair() { 0) | put_prev_entity() { 0) 0.122 us | check_cfs_rq_runtime(); 0) 0.355 us | } 0) 0.581 us | } 0) 0.123 us | __update_idle_core(); 0) 1.055 us | } 0) 0.118 us | enter_lazy_tlb(); 2) | finish_task_switch() { 2) | __mmdrop() { 2) | pgd_free() { 2) 0.248 us | _raw_spin_lock(); 2) | free_pages() { 2) | free_pages.part.0() { 2) | __free_pages() { 2) | __free_pages_ok() { 2) | free_one_page() { 2) 0.213 us | _raw_spin_lock(); 2) 0.219 us | __mod_zone_page_state(); 2) 1.102 us | } 2) 1.839 us | } 2) 2.337 us | } 2) 2.672 us | } 2) 2.986 us | } 2) 4.044 us | } 2) 0.218 us | destroy_context_ldt(); 2) | kmem_cache_free() { 2) 0.416 us | ___cache_free(); 2) 1.051 us | } 2) 6.234 us | } 2) 8.542 us | } 2) * 13308.49 us | } /* schedule */ 2) * 13308.85 us | } /* schedule_timeout */ 2) 0.235 us | _raw_spin_lock_irq(); 2) * 13310.47 us | } /* wait_for_completion_killable */ 2) | free_modprobe_argv() { 2) | kfree() { 2) 0.213 us | ___cache_free(); 2) 0.657 us | } 2) | kfree() { 2) 0.153 us | ___cache_free(); 2) 0.557 us | } 2) 1.732 us | } 2) | kfree() { 2) 0.207 us | ___cache_free(); 2) 0.734 us | } 2) | __wake_up() { 2) | __wake_up_common_lock() { 2) 0.265 us | _raw_spin_lock_irqsave(); 2) 0.199 us | __wake_up_common(); 2) 0.214 us | _raw_spin_unlock_irqrestore(); 2) 1.333 us | } 2) 1.648 us | } 2) * 13325.51 us | } /* call_usermodehelper_exec */ 2) | __wake_up() { 2) | __wake_up_common_lock() { 2) 0.195 us | _raw_spin_lock_irqsave(); 2) 0.200 us | __wake_up_common(); 2) 0.189 us | _raw_spin_unlock_irqrestore(); 2) 1.274 us | } 2) 1.629 us | } 2) * 13337.37 us | } /* __request_module */ 2) | __request_module() { 2) 0.279 us | current_is_async(); 2) | security_kernel_module_request() { 2) 0.310 us | integrity_kernel_module_request(); 2) 0.799 us | } 2) | kmem_cache_alloc_trace() { 2) | _cond_resched() { 2) 0.209 us | rcu_all_qs(); 2) 0.598 us | } 2) 0.208 us | should_failslab(); 2) | _cond_resched() { 2) 0.202 us | rcu_all_qs(); 2) 0.597 us | } 2) 0.206 us | memcg_kmem_put_cache(); 2) 2.596 us | } 2) | kstrdup() { 2) | __kmalloc_track_caller() { 2) 0.209 us | kmalloc_slab(); 2) | _cond_resched() { 2) 0.200 us | rcu_all_qs(); 2) 0.598 us | } 2) 0.399 us | should_failslab(); 2) | _cond_resched() { 2) 0.179 us | rcu_all_qs(); 2) 0.491 us | } 2) 0.174 us | memcg_kmem_put_cache(); 2) 3.004 us | } 2) 3.424 us | } 2) | call_usermodehelper_setup() { 2) | kmem_cache_alloc_trace() { 2) | _cond_resched() { 2) 0.171 us | rcu_all_qs(); 2) 0.816 us | } 2) 0.173 us | should_failslab(); 2) | _cond_resched() { 2) 0.188 us | rcu_all_qs(); 2) 0.544 us | } 2) 0.205 us | memcg_kmem_put_cache(); 2) 2.728 us | } 2) 3.100 us | } 2) | call_usermodehelper_exec() { 2) | queue_work_on() { 2) | __queue_work() { 2) 0.213 us | get_work_pool(); 2) 0.206 us | _raw_spin_lock(); 2) | insert_work() { 2) 0.194 us | get_pwq.isra.0(); 2) | wake_up_process() { 2) | try_to_wake_up() { 2) 0.248 us | _raw_spin_lock_irqsave(); 2) | select_task_rq_fair() { 2) 0.205 us | available_idle_cpu(); 2) 0.252 us | update_cfs_rq_h_load(); 2) | select_idle_sibling() { 2) 0.277 us | available_idle_cpu(); 2) 0.666 us | } 2) 2.074 us | } 2) 0.213 us | _raw_spin_lock(); 2) 0.240 us | update_rq_clock(); 2) | ttwu_do_activate() { 2) | activate_task() { 2) | enqueue_task_fair() { 2) | enqueue_entity() { 2) 0.209 us | update_curr(); 2) | __update_load_avg_se() { 2) 0.198 us | __accumulate_pelt_segments(); 2) 0.715 us | } 2) 0.221 us | __update_load_avg_cfs_rq(); 2) 0.205 us | update_cfs_group(); 2) 0.274 us | account_entity_enqueue(); 2) 0.209 us | place_entity(); 2) 0.211 us | __enqueue_entity(); 2) 3.718 us | } 2) 0.208 us | hrtick_update(); 2) 4.568 us | } 2) 5.005 us | } 2) | ttwu_do_wakeup() { 2) | check_preempt_curr() { 2) 0.222 us | resched_curr(); 2) 0.700 us | } 2) 1.473 us | } 2) 7.098 us | } 2) 0.218 us | _raw_spin_unlock_irqrestore(); 2) + 11.605 us | } 2) + 11.947 us | } 2) + 12.730 us | } 2) + 14.091 us | } 2) + 14.527 us | } 2) | wait_for_completion_killable() { 2) | _cond_resched() { 2) 0.210 us | rcu_all_qs(); 2) 0.636 us | } 2) 0.241 us | _raw_spin_lock_irq(); 2) | schedule_timeout() { 2) | schedule() { 2) | rcu_note_context_switch() { 2) 0.217 us | rcu_qs(); 2) 0.618 us | } 2) 0.200 us | _raw_spin_lock(); 2) 0.213 us | update_rq_clock(); 2) | deactivate_task() { 2) | dequeue_task_fair() { 2) | dequeue_entity() { 2) | update_curr() { 2) 0.196 us | update_min_vruntime(); 2) 0.239 us | cpuacct_charge(); 2) | __cgroup_account_cputime() { 2) 0.202 us | cgroup_rstat_updated(); 2) 0.638 us | } 2) 1.946 us | } 2) 0.210 us | __update_load_avg_se(); 2) 0.213 us | __update_load_avg_cfs_rq(); 2) 0.200 us | clear_buddies(); 2) 0.212 us | account_entity_dequeue(); 2) 0.203 us | update_cfs_group(); 2) 0.207 us | update_min_vruntime(); 2) 5.029 us | } 2) 0.194 us | hrtick_update(); 2) 5.793 us | } 2) 6.205 us | } 2) | pick_next_task_fair() { 2) | update_blocked_averages() { 2) 0.149 us | _raw_spin_lock_irqsave(); 2) 0.205 us | update_rq_clock(); 2) 0.167 us | __update_load_avg_cfs_rq(); 2) 0.206 us | update_rt_rq_load_avg(); 2) 0.184 us | update_dl_rq_load_avg(); 2) 0.183 us | _raw_spin_unlock_irqrestore(); 2) 2.510 us | } 2) | load_balance() { 2) | find_busiest_group() { 2) 0.172 us | update_nohz_stats(); 2) 0.176 us | idle_cpu(); 2) 0.207 us | update_nohz_stats(); 2) 1.818 us | } 2) 2.339 us | } 2) 0.171 us | __msecs_to_jiffies(); 2) | load_balance() { 2) | find_busiest_group() { 2) 0.211 us | update_nohz_stats(); 2) 0.203 us | update_nohz_stats(); 2) 0.190 us | idle_cpu(); 2) 0.216 us | update_nohz_stats(); 2) 0.222 us | update_nohz_stats(); 2) 2.711 us | } 2) 0.228 us | _raw_spin_lock_irqsave(); 2) 0.262 us | update_rq_clock(); 2) 0.233 us | can_migrate_task(); 2) 0.322 us | can_migrate_task(); 2) 0.222 us | update_cfs_rq_h_load(); 2) | deactivate_task() { 2) | dequeue_task_fair() { 2) | dequeue_entity() { 2) | update_curr() { 2) 0.209 us | update_min_vruntime(); 2) 0.259 us | cpuacct_charge(); 2) | __cgroup_account_cputime() { 2) 0.193 us | cgroup_rstat_updated(); 2) 0.738 us | } 2) 2.022 us | } 2) 0.223 us | __update_load_avg_se(); 2) 0.213 us | __update_load_avg_cfs_rq(); 2) 0.202 us | clear_buddies(); 2) 0.215 us | account_entity_dequeue(); 2) 0.204 us | update_cfs_group(); 2) 0.202 us | update_min_vruntime(); 2) 4.891 us | } 2) 0.205 us | hrtick_update(); 2) 5.711 us | } 2) 6.143 us | } 2) | set_task_cpu() { 2) | migrate_task_rq_fair() { 2) | detach_entity_cfs_rq() { 2) 0.215 us | __update_load_avg_se(); 2) 0.204 us | __update_load_avg_cfs_rq(); 2) 0.219 us | propagate_entity_cfs_rq.isra.0(); 2) 1.433 us | } 2) 1.814 us | } 2) 0.195 us | set_task_rq_fair(); 2) 2.664 us | } 2) 0.202 us | _raw_spin_lock(); 2) 0.219 us | update_rq_clock(); 2) | attach_task() { 2) | activate_task() { 2) | enqueue_task_fair() { 2) | enqueue_entity() { 2) | update_curr() { 2) 0.225 us | update_min_vruntime(); 2) 0.202 us | cpuacct_charge(); 2) | __cgroup_account_cputime() { 2) 0.196 us | cgroup_rstat_updated(); 2) 0.569 us | } 2) 2.120 us | } 2) 0.208 us | __update_load_avg_cfs_rq(); 2) 0.219 us | attach_entity_load_avg(); 2) 0.203 us | update_cfs_group(); 2) 0.184 us | account_entity_enqueue(); 2) 0.217 us | __enqueue_entity(); 2) 4.678 us | } 2) 0.177 us | hrtick_update(); 2) 5.408 us | } 2) 5.795 us | } 2) | check_preempt_curr() { 2) | check_preempt_wakeup() { 2) 0.205 us | update_curr(); 2) 0.201 us | wakeup_preempt_entity.isra.0(); 2) 0.970 us | } 2) 1.359 us | } 2) 7.688 us | } 2) + 23.511 us | } 2) 0.201 us | __msecs_to_jiffies(); 2) 0.205 us | _raw_spin_lock(); 2) 0.197 us | check_cfs_rq_runtime(); 2) | pick_next_entity() { 2) 0.198 us | clear_buddies(); 2) 0.600 us | } 2) | put_prev_entity() { 2) 0.188 us | check_cfs_rq_runtime(); 2) 0.583 us | } 2) | set_next_entity() { 2) 0.209 us | __update_load_avg_se(); 2) 0.215 us | __update_load_avg_cfs_rq(); 2) 1.053 us | } 2) + 33.704 us | } 2) | switch_mm_irqs_off() { 2) 0.607 us | load_new_mm_cr3(); 2) 2.798 us | } 3) 5.150 us | finish_task_switch(); -------------------------------------------------------------------------------- Ctrl-C hit, notice the delay -------------------------------------------------------------------------------- 3) $ 54568382 us | } /* schedule */ 3) $ 54568383 us | } /* schedule_timeout */ 3) 1.011 us | _raw_spin_lock_irq(); 3) $ 54568388 us | } /* wait_for_completion_killable */ 3) | __wake_up() { 3) | __wake_up_common_lock() { 3) 0.911 us | _raw_spin_lock_irqsave(); 3) 1.015 us | __wake_up_common(); 3) 0.958 us | _raw_spin_unlock_irqrestore(); 3) 6.186 us | } 3) 7.650 us | } 3) $ 54568414 us | } /* call_usermodehelper_exec */ 3) | __wake_up() { 3) | __wake_up_common_lock() { 3) 0.720 us | _raw_spin_lock_irqsave(); 3) 0.826 us | __wake_up_common(); 3) 0.850 us | _raw_spin_unlock_irqrestore(); 3) 5.655 us | } 3) 7.309 us | } 3) $ 54568437 us | } /* __request_module */