Re: large latency on heavy NFS writeback

Re: large latency on heavy NFS writeback

[Fengguang Wu]

And here is /proc/schedstat:

version 14
timestamp 4295709123
cpu0 0 0 0 9826 0 8147092 2368880 4562614 3204914 1923746542825 1668572097374 5778212
domain0 03 519900 420205 15340 213485458 102464 0 204 420001 4427 4395 2 39589 41 0 0 4395 2445488 2355039 13841 502197903 87954 0 229 2354810 17 1 16 0 0 0 0 0 0 1349332 3751 0
domain1 03 130642 130642 0 0 0 0 0 130642 639 639 0 0 0 0 0 600 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
cpu1 0 0 0 7227 0 4666153 1649090 2544408 1195073 2765150191631 936745663460 3017063
domain0 03 496555 470765 1864 76094877 26082 0 1 470764 804 708 15 638637 138 0 0 708 1816468 1597399 51690 557807800 204737 0 256 1597143 14 4 10 0 0 0 0 0 0 1357700 9038 0
domain1 03 127585 127585 0 0 0 0 0 8622 199 199 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0

Fengguang
---
On Tue, Oct 02, 2007 at 07:19:31PM +0800, Fengguang Wu wrote:
> Ingo,
> 
> [In the hope that you are better at analyzing such problems.]
> 
> I collected some large latency numbers with you latency tracing patch.
> The system is writing to a NFS dir:
>         cp /dev/zero /mnt/
> 
> The /proc/latency_trace is:
> 
> preemption latency trace v1.1.5 on 2.6.23-rc8
> --------------------------------------------------------------------
>  latency: 2021410 us, #2/2, CPU#0 | (M:server VP:0, KP:0, SP:0 HP:0 #P:2)
>     -----------------
>     | task: migration/0-3 (uid:0 nice:-5 policy:1 rt_prio:99)
>     -----------------
>  => started at: try_to_wake_up+0x2a5/0x500 <ffffffff8103b9f5>
>  => ended at:   thread_return+0xde/0x686 <ffffffff81696b28>
>                  
>                  _------=> CPU#
>                 / _-----=> irqs-off
>                | / _----=> need-resched
>                || / _---=> hardirq/softirq
>                ||| / _--=> preempt-depth
>                |||| /
>                |||||     delay
>    cmd     pid ||||| time  |   caller
>       \   /    |||||   \   |   /
>    <...>-3     0.... 2021410us : thread_return+0xde/0x686 (thread_return+0xde/0x686)
> 
> 
> When the test continues for a long time, the system eventually locked up.
> I managed to recover it and collected a new latency_trace and sysrq-t.
> The .config, oprofile and lock_stat numbers are also attached.
> 
> Thank you,
> Fengguang

> preemption latency trace v1.1.5 on 2.6.23-rc8
> --------------------------------------------------------------------
>  latency: 1000013964 us, #65536/582887385, CPU#0 | (M:server VP:0, KP:0, SP:0 HP:0 #P:2)
>     -----------------
>     | task: trace-it-6278 (uid:0 nice:0 policy:0 rt_prio:0)
>     -----------------
> 
>                  _------=> CPU#            
>                 / _-----=> irqs-off        
>                | / _----=> need-resched    
>                || / _---=> hardirq/softirq 
>                ||| / _--=> preempt-depth   
>                |||| /                      
>                |||||     delay             
>    cmd     pid ||||| time  |   caller      
>       \   /    |||||   \   |   /           
>   <idle>-0     0.N.. 112248us : __exit_idle+0x9/0x40 (cpu_idle+0x85/0xd0)
>   <idle>-0     0.N.. 112248us : atomic_notifier_call_chain+0x9/0x20 (__exit_idle+0x33/0x40)
>   <idle>-0     0.N.. 112249us : __atomic_notifier_call_chain+0x9/0x20 (atomic_notifier_call_chain+0x16/0x20)
>   <idle>-0     0.N.. 112249us : notifier_call_chain+0x16/0x80 (__atomic_notifier_call_chain+0x12/0x20)
>   <idle>-0     0.N.. 112249us : mce_idle_callback+0x9/0x40 (notifier_call_chain+0x41/0x80)
>   <idle>-0     0.N.. 112249us : __sched_text_start+0x19/0x34a (cpu_idle+0x9d/0xd0)
>   <idle>-0     0.N.. 112250us : _spin_lock_irq+0xc/0x60 (__sched_text_start+0x10f/0x34a)
>   <idle>-0     0DN.. 112250us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
>   <idle>-0     0DN.. 112250us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
>   <idle>-0     0DN.. 112251us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
>   <idle>-0     0DN.. 112251us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
>   <idle>-0     0DN.. 112251us : _raw_spin_trylock+0x9/0x40 (_spin_lock_irq+0x3a/0x60)
>   <idle>-0     0DN.. 112252us : lock_acquired+0x16/0x220 (_spin_lock_irq+0x5a/0x60)
>   <idle>-0     0DN.. 112252us : get_lock_stats+0x9/0x40 (lock_acquired+0xff/0x220)
>   <idle>-0     0D... 112252us : __update_rq_clock+0x20/0x130 (__sched_text_start+0x125/0x34a)
>   <idle>-0     0D... 112253us : sched_clock+0x9/0x30 (__update_rq_clock+0x2f/0x130)
>   <idle>-0     0D... 112253us : put_prev_task_idle+0x9/0x10 (__sched_text_start+0x163/0x34a)
>   <idle>-0     0D... 112253us : pick_next_task_fair+0x1b/0x70 (__sched_text_start+0x17d/0x34a)
>   <idle>-0     0D... 112254us : __pick_next_entity+0x9/0x20 (pick_next_task_fair+0x39/0x70)
>   <idle>-0     0D... 112254us : update_stats_wait_end+0xa/0xb0 (pick_next_task_fair+0x47/0x70)
>   <idle>-0     0D... 112254us : add_wait_runtime+0x9/0x60 (update_stats_wait_end+0x9c/0xb0)
>   <idle>-0     0D... 112255us : sched_clock+0x9/0x30 (__sched_text_start+0x20b/0x34a)
>   <idle>-0     0D... 112255us : __phys_addr+0x9/0x40 (__sched_text_start+0x2e7/0x34a)
>   <idle>-0     0D... 112256us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
>   <idle>-0     0D... 112256us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
>   <idle>-0     0D... 112256us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
>   <idle>-0     0D... 112256us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
>   <idle>-0     0D... 112261us : __switch_to+0x16/0x2e0 (thread_return+0x0/0x686)
>    klogd-4366  0D... 112262us+: thread_return+0x72/0x686 <<idle>-0> (20 0)
>    klogd-4366  0D... 112264us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
>    klogd-4366  0D... 112265us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
>    klogd-4366  0D... 112265us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
>    klogd-4366  0D... 112265us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
>    klogd-4366  0D... 112266us : _spin_unlock_irq+0xe/0x40 (thread_return+0xd0/0x686)
>    klogd-4366  0D... 112266us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
>    klogd-4366  0D... 112266us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
>    klogd-4366  0D... 112267us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
>    klogd-4366  0D... 112267us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
>    klogd-4366  0D... 112267us : _raw_spin_unlock+0xe/0xa0 (_spin_unlock_irq+0x2b/0x40)
>    klogd-4366  0D... 112268us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0x93/0x170)
>    klogd-4366  0D... 112268us!: mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0xab/0x170)
>    klogd-4366  0.N.. 365462us!: trace_stop_sched_switched+0x21/0x310 (thread_return+0xde/0x686)
>    klogd-4366  0.N.. 459157us : _spin_lock_irq+0xc/0x60 (__sched_text_start+0x10f/0x34a)
>    klogd-4366  0DN.. 459157us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
>    klogd-4366  0DN.. 459158us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
>    klogd-4366  0DN.. 459158us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
>    klogd-4366  0DN.. 459158us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
>    klogd-4366  0DN.. 459159us : _raw_spin_trylock+0x9/0x40 (_spin_lock_irq+0x3a/0x60)
>    klogd-4366  0DN.. 459159us : lock_acquired+0x16/0x220 (_spin_lock_irq+0x5a/0x60)
>    klogd-4366  0DN.. 459159us : get_lock_stats+0x9/0x40 (lock_acquired+0xff/0x220)
>    klogd-4366  0D... 459159us : __update_rq_clock+0x20/0x130 (__sched_text_start+0x125/0x34a)
>    klogd-4366  0D... 459160us : sched_clock+0x9/0x30 (__update_rq_clock+0x2f/0x130)
>    klogd-4366  0D... 459160us : put_prev_task_fair+0x16/0xa0 (__sched_text_start+0x163/0x34a)
>    klogd-4366  0D... 459160us : update_curr+0x21/0x140 (put_prev_task_fair+0x95/0xa0)
>    klogd-4366  0D... 459161us : calc_delta_mine+0x9/0x90 (update_curr+0xc6/0x140)
>    klogd-4366  0D... 459161us : calc_delta_mine+0x9/0x90 (update_curr+0xda/0x140)
>    klogd-4366  0D... 459161us : add_wait_runtime+0x9/0x60 (update_curr+0x125/0x140)
>    klogd-4366  0D... 459162us : pick_next_task_rt+0x9/0x60 (thread_return+0x1ad/0x686)
>    klogd-4366  0D... 459162us : sched_clock+0x9/0x30 (__sched_text_start+0x1b9/0x34a)
>    klogd-4366  0D... 459162us : sched_clock+0x9/0x30 (__sched_text_start+0x20b/0x34a)
>    klogd-4366  0D... 459163us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
>    klogd-4366  0D... 459163us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
>    klogd-4366  0D... 459163us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
>    klogd-4366  0D... 459164us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
>    klogd-4366  0D... 459164us : __switch_to+0x16/0x2e0 (thread_return+0x0/0x686)
> migratio-3     0D... 459165us : thread_return+0x72/0x686 <klogd-4366> (0 199)
> migratio-3     0D... 459165us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
> migratio-3     0D... 459166us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
> migratio-3     0D... 459166us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
> migratio-3     0D... 459166us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
> migratio-3     0D... 459167us : _spin_unlock_irq+0xe/0x40 (thread_return+0xd0/0x686)
> migratio-3     0D... 459167us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
> migratio-3     0D... 459167us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
> migratio-3     0D... 459167us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
> migratio-3     0D... 459168us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
> migratio-3     0D... 459168us : _raw_spin_unlock+0xe/0xa0 (_spin_unlock_irq+0x2b/0x40)
> migratio-3     0D... 459168us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0x93/0x170)
> migratio-3     0D... 459169us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0xab/0x170)
> migratio-3     0.... 459169us : trace_stop_sched_switched+0x21/0x310 (thread_return+0xde/0x686)
> migratio-3     0.... 459169us : kthread_should_stop+0x9/0x30 (migration_thread+0x160/0x290)
> migratio-3     0.... 459170us : _spin_lock_irq+0xc/0x60 (migration_thread+0x77/0x290)
> migratio-3     0D... 459170us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
> migratio-3     0D... 459170us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
> migratio-3     0D... 459171us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
> migratio-3     0D... 459171us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
> migratio-3     0D... 459171us : _raw_spin_trylock+0x9/0x40 (_spin_lock_irq+0x3a/0x60)
> migratio-3     0D... 459172us : lock_acquired+0x16/0x220 (_spin_lock_irq+0x5a/0x60)
> migratio-3     0D... 459172us : get_lock_stats+0x9/0x40 (lock_acquired+0xff/0x220)
> migratio-3     0D... 459172us : double_lock_balance+0xc/0x70 (migration_thread+0xd0/0x290)
> migratio-3     0D... 459172us : _spin_trylock+0xe/0x50 (double_lock_balance+0x21/0x70)
> migratio-3     0D... 459173us : _raw_spin_trylock+0x9/0x40 (_spin_trylock+0x16/0x50)
> migratio-3     0D... 459173us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
> migratio-3     0D... 459173us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
> migratio-3     0D... 459174us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
> migratio-3     0D... 459174us : update_rq_clock+0x9/0x20 (migration_thread+0xd8/0x290)
> migratio-3     0D... 459174us : __update_rq_clock+0x20/0x130 (update_rq_clock+0x1e/0x20)
> migratio-3     0D... 459175us : sched_clock+0x9/0x30 (__update_rq_clock+0x2f/0x130)
> migratio-3     0D... 459175us : update_rq_clock+0x9/0x20 (migration_thread+0xe0/0x290)
> migratio-3     0D... 459175us : load_balance_rt+0xd/0x60 (migration_thread+0x217/0x290)
> migratio-3     0D... 459176us : balance_tasks+0x16/0x1c0 (load_balance_rt+0x50/0x60)
> migratio-3     0D... 459176us : load_balance_start_rt+0x9/0x70 (balance_tasks+0x4c/0x1c0)
> migratio-3     0D... 459176us : load_balance_next_rt+0xe/0x90 (balance_tasks+0x7b/0x1c0)
> migratio-3     0D... 459176us : find_next_bit+0xa/0xa0 (load_balance_next_rt+0x57/0x90)
> migratio-3     0D... 459177us : load_balance_fair+0xe/0x90 (migration_thread+0x217/0x290)
> migratio-3     0D... 459177us : balance_tasks+0x16/0x1c0 (load_balance_fair+0x5f/0x90)
> migratio-3     0D... 459177us : load_balance_start_fair+0x16/0x40 (balance_tasks+0x4c/0x1c0)
> migratio-3     0D... 459178us : rb_next+0x9/0x60 (load_balance_start_fair+0x2e/0x40)
> migratio-3     0D... 459178us : load_balance_next_fair+0x16/0x40 (balance_tasks+0x7b/0x1c0)
> migratio-3     0D... 459178us : rb_next+0x9/0x60 (load_balance_next_fair+0x2e/0x40)
> migratio-3     0D... 459179us : load_balance_next_fair+0x16/0x40 (balance_tasks+0x7b/0x1c0)
> migratio-3     0D... 459179us : rb_next+0x9/0x60 (load_balance_next_fair+0x2e/0x40)
> migratio-3     0D... 459179us : deactivate_task+0x16/0x60 (balance_tasks+0xd2/0x1c0)
> migratio-3     0D... 459179us : dequeue_task+0xe/0x30 (deactivate_task+0x38/0x60)
> migratio-3     0D... 459180us : dequeue_task_fair+0x9/0x40 (dequeue_task+0x18/0x30)
> migratio-3     0D... 459180us : dequeue_entity+0x20/0x100 (dequeue_task_fair+0x3b/0x40)
> migratio-3     0D... 459180us : update_curr+0x21/0x140 (dequeue_entity+0x35/0x100)
> migratio-3     0D... 459181us : update_stats_wait_end+0xa/0xb0 (dequeue_entity+0x5f/0x100)
> migratio-3     0D... 459181us : add_wait_runtime+0x9/0x60 (update_stats_wait_end+0x9c/0xb0)
> migratio-3     0D... 459181us : rb_erase+0xc/0x320 (dequeue_entity+0xa1/0x100)
> migratio-3     0D... 459182us : update_load_sub+0x9/0x20 (dequeue_entity+0xad/0x100)
> migratio-3     0D... 459182us : update_curr_load+0x16/0xb0 (deactivate_task+0x45/0x60)
> migratio-3     0D... 459182us : calc_delta_mine+0x9/0x90 (update_curr_load+0x92/0xb0)
> migratio-3     0D... 459182us : update_load_sub+0x9/0x20 (deactivate_task+0x53/0x60)
> migratio-3     0D... 459183us : set_task_cpu+0xc/0xe0 (balance_tasks+0xdd/0x1c0)
> migratio-3     0D... 459183us : trace_change_sched_cpu+0x20/0xf0 (set_task_cpu+0xd3/0xe0)
> migratio-3     0D... 459183us : activate_task+0x16/0x50 (balance_tasks+0xeb/0x1c0)
> migratio-3     0D... 459184us : enqueue_task+0x19/0x60 (activate_task+0x38/0x50)
> migratio-3     0D... 459184us : sched_clock+0x9/0x30 (enqueue_task+0x31/0x60)
> migratio-3     0D... 459184us : enqueue_task_fair+0x9/0x50 (enqueue_task+0x48/0x60)
> migratio-3     0D... 459184us : enqueue_entity+0x12/0x280 (enqueue_task_fair+0x49/0x50)
> migratio-3     0D... 459185us : update_curr+0x21/0x140 (enqueue_entity+0x1f/0x280)
> migratio-3     0D... 459185us : update_stats_enqueue+0x9/0x90 (enqueue_entity+0x4b/0x280)
> migratio-3     0D... 459185us : rb_insert_color+0x12/0x110 (enqueue_entity+0xab/0x280)
> migratio-3     0D... 459186us : update_load_add+0x9/0x20 (enqueue_entity+0xb8/0x280)
> migratio-3     0D... 459186us : inc_nr_running+0x16/0x50 (activate_task+0x43/0x50)
> migratio-3     0D... 459186us : update_curr_load+0x16/0xb0 (inc_nr_running+0x29/0x50)
> migratio-3     0D... 459187us : update_load_add+0x9/0x20 (inc_nr_running+0x37/0x50)
> migratio-3     0D... 459187us : check_preempt_curr_idle+0x9/0x20 (balance_tasks+0x103/0x1c0)
> migratio-3     0D... 459187us : resched_task+0x9/0x70 (check_preempt_curr_idle+0x15/0x20)
> migratio-3     0D... 459188us : __trace_start_sched_wakeup+0x19/0x1b0 (balance_tasks+0x1ad/0x1c0)
> migratio-3     0D... 459188us : __trace_start_sched_wakeup+0x4d/0x1b0 <klogd-4366> (120 -1)
> migratio-3     0D... 459188us : _spin_unlock+0xe/0x40 (migration_thread+0x125/0x290)
> migratio-3     0D... 459189us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
> migratio-3     0D... 459189us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
> migratio-3     0D... 459189us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
> migratio-3     0D... 459189us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
> migratio-3     0D... 459190us : _raw_spin_unlock+0xe/0xa0 (_spin_unlock+0x2b/0x40)
> migratio-3     0D... 459190us : _spin_unlock_irq+0xe/0x40 (migration_thread+0x145/0x290)
> migratio-3     0D... 459190us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
> migratio-3     0D... 459191us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
> migratio-3     0D... 459191us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
> migratio-3     0D... 459191us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
> migratio-3     0D... 459191us : _raw_spin_unlock+0xe/0xa0 (_spin_unlock_irq+0x2b/0x40)
> migratio-3     0D... 459192us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0x93/0x170)
> migratio-3     0D... 459192us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0xab/0x170)
> migratio-3     0.... 459192us : __sched_text_start+0x19/0x34a (migration_thread+0x14a/0x290)
> migratio-3     0.... 459193us : _spin_lock_irq+0xc/0x60 (__sched_text_start+0x10f/0x34a)
> migratio-3     0D... 459193us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
> migratio-3     0D... 459193us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
> migratio-3     0D... 459194us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
> migratio-3     0D... 459194us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
> migratio-3     0D... 459194us : _raw_spin_trylock+0x9/0x40 (_spin_lock_irq+0x3a/0x60)
> migratio-3     0D... 459194us : lock_acquired+0x16/0x220 (_spin_lock_irq+0x5a/0x60)
> migratio-3     0D... 459195us : get_lock_stats+0x9/0x40 (lock_acquired+0xff/0x220)
> migratio-3     0D... 459195us : __update_rq_clock+0x20/0x130 (__sched_text_start+0x125/0x34a)
> migratio-3     0D... 459195us : sched_clock+0x9/0x30 (__update_rq_clock+0x2f/0x130)
> migratio-3     0D... 459196us : deactivate_task+0x16/0x60 (thread_return+0x173/0x686)
> migratio-3     0D... 459196us : dequeue_task+0xe/0x30 (deactivate_task+0x38/0x60)
> migratio-3     0D... 459196us : dequeue_task_rt+0x16/0xb0 (dequeue_task+0x18/0x30)
> migratio-3     0D... 459196us : list_del+0x9/0x70 (dequeue_task_rt+0x41/0xb0)
> migratio-3     0D... 459197us : update_curr_load+0x16/0xb0 (deactivate_task+0x45/0x60)
> migratio-3     0D... 459197us : calc_delta_mine+0x9/0x90 (update_curr_load+0x92/0xb0)
> migratio-3     0D... 459197us : update_load_sub+0x9/0x20 (deactivate_task+0x53/0x60)
> migratio-3     0D... 459198us : put_prev_task_rt+0x9/0x70 (__sched_text_start+0x163/0x34a)
> migratio-3     0D... 459198us : pick_next_task_fair+0x1b/0x70 (__sched_text_start+0x17d/0x34a)
> migratio-3     0D... 459198us : __pick_next_entity+0x9/0x20 (pick_next_task_fair+0x39/0x70)
> migratio-3     0D... 459199us : update_stats_wait_end+0xa/0xb0 (pick_next_task_fair+0x47/0x70)
> migratio-3     0D... 459199us : add_wait_runtime+0x9/0x60 (update_stats_wait_end+0x9c/0xb0)
> migratio-3     0D... 459199us : sched_clock+0x9/0x30 (__sched_text_start+0x1b9/0x34a)
> migratio-3     0D... 459200us : sched_clock+0x9/0x30 (__sched_text_start+0x20b/0x34a)
> migratio-3     0D... 459200us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
> migratio-3     0D... 459200us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
> migratio-3     0D... 459200us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
> migratio-3     0D... 459201us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
> migratio-3     0D... 459201us : __switch_to+0x16/0x2e0 (thread_return+0x0/0x686)
> events/0-9     0D... 459202us : thread_return+0x72/0x686 <migratio-3> (199 -5)
> events/0-9     0D... 459202us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
> events/0-9     0D... 459203us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
> events/0-9     0D... 459203us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
> events/0-9     0D... 459203us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
> events/0-9     0D... 459204us : _spin_unlock_irq+0xe/0x40 (thread_return+0xd0/0x686)
> events/0-9     0D... 459204us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
> events/0-9     0D... 459204us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
> events/0-9     0D... 459204us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
> events/0-9     0D... 459205us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
> events/0-9     0D... 459205us : _raw_spin_unlock+0xe/0xa0 (_spin_unlock_irq+0x2b/0x40)
> events/0-9     0D... 459205us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0x93/0x170)
> events/0-9     0D... 459206us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0xab/0x170)
> events/0-9     0.... 459206us : trace_stop_sched_switched+0x21/0x310 (thread_return+0xde/0x686)
> events/0-9     0.... 459206us : _spin_lock_irqsave+0x19/0x80 (__down+0xaf/0x107)
> events/0-9     0D... 459207us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
> events/0-9     0D... 459207us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
> events/0-9     0D... 459207us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
> events/0-9     0D... 459208us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
> events/0-9     0D... 459208us : _raw_spin_trylock+0x9/0x40 (_spin_lock_irqsave+0x4a/0x80)
> events/0-9     0D... 459208us : lock_acquired+0x16/0x220 (_spin_lock_irqsave+0x6a/0x80)
> events/0-9     0D... 459209us : get_lock_stats+0x9/0x40 (lock_acquired+0xff/0x220)
> events/0-9     0D... 459209us : list_del+0x9/0x70 (__down+0xd9/0x107)
> events/0-9     0D... 459209us : __wake_up_locked+0x9/0x20 (__down+0xe6/0x107)
> events/0-9     0D... 459209us : __wake_up_common+0x16/0x80 (__wake_up_locked+0x18/0x20)
> events/0-9     0D... 459210us : _spin_unlock_irqrestore+0x16/0x60 (__down+0xf1/0x107)
> events/0-9     0D... 459210us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
> events/0-9     0D... 459210us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
> events/0-9     0D... 459211us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
> events/0-9     0D... 459211us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
> events/0-9     0D... 459211us : _raw_spin_unlock+0xe/0xa0 (_spin_unlock_irqrestore+0x36/0x60)
> events/0-9     0D... 459212us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0x93/0x170)
> events/0-9     0D... 459212us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0xab/0x170)
> events/0-9     0.... 459213us : poke_blanked_console+0x9/0xf0 (console_callback+0xbf/0x110)
> events/0-9     0.... 459213us : is_console_locked+0x9/0x20 (poke_blanked_console+0xe/0xf0)
> events/0-9     0.... 459213us : __might_sleep+0x16/0x110 (poke_blanked_console+0x33/0xf0)
> events/0-9     0.... 459214us : del_timer+0x15/0x80 (poke_blanked_console+0x3f/0xf0)
> events/0-9     0.... 459214us : release_console_sem+0x16/0x250 (console_callback+0x72/0x110)
> events/0-9     0.... 459214us : _spin_lock_irqsave+0x19/0x80 (release_console_sem+0x5f/0x250)
> events/0-9     0D... 459214us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
> events/0-9     0D... 459215us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
> events/0-9     0D... 459215us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
> events/0-9     0D... 459215us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
> events/0-9     0D... 459216us : _raw_spin_trylock+0x9/0x40 (_spin_lock_irqsave+0x4a/0x80)
> events/0-9     0D... 459216us : lock_contended+0x16/0x1f0 (_spin_lock_irqsave+0x5a/0x80)
> events/0-9     0D... 459216us : sched_clock+0x9/0x30 (lock_contended+0xd5/0x1f0)
> events/0-9     0D... 459217us : get_lock_stats+0x9/0x40 (lock_contended+0x19d/0x1f0)
> events/0-9     0D... 459217us : _raw_spin_lock+0x20/0x150 (_spin_lock_irqsave+0x62/0x80)
> events/0-9     0D... 459217us : __delay+0x9/0x20 (_raw_spin_lock+0xd8/0x150)
> events/0-9     0D... 459218us : lock_acquired+0x16/0x220 (_spin_lock_irqsave+0x6a/0x80)
> events/0-9     0D... 459218us : sched_clock+0x9/0x30 (lock_acquired+0x16d/0x220)
> events/0-9     0D... 459218us : get_lock_stats+0x9/0x40 (lock_acquired+0x18c/0x220)
> events/0-9     0D... 459219us : lock_time_inc+0x9/0x30 (lock_acquired+0x1c9/0x220)
> events/0-9     0D... 459219us : _spin_unlock_irqrestore+0x16/0x60 (release_console_sem+0x221/0x250)
> events/0-9     0D... 459219us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
> events/0-9     0D... 459220us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
> events/0-9     0D... 459220us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
> events/0-9     0D... 459221us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
> events/0-9     0D... 459221us : _raw_spin_unlock+0xe/0xa0 (_spin_unlock_irqrestore+0x36/0x60)
> events/0-9     0D... 459221us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0x93/0x170)
> events/0-9     0D... 459221us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0xab/0x170)
> events/0-9     0.... 459222us : wake_up_klogd+0x9/0x40 (release_console_sem+0x22f/0x250)
> events/0-9     0.... 459222us : _spin_lock_irq+0xc/0x60 (run_workqueue+0xb9/0x190)
> events/0-9     0D... 459222us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
> events/0-9     0D... 459223us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
> events/0-9     0D... 459223us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
> events/0-9     0D... 459223us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
> events/0-9     0D... 459224us : _raw_spin_trylock+0x9/0x40 (_spin_lock_irq+0x3a/0x60)
> events/0-9     0D... 459224us : lock_acquired+0x16/0x220 (_spin_lock_irq+0x5a/0x60)
> events/0-9     0D... 459224us : get_lock_stats+0x9/0x40 (lock_acquired+0xff/0x220)
> events/0-9     0D... 459225us : _spin_unlock_irq+0xe/0x40 (run_workqueue+0x105/0x190)
> events/0-9     0D... 459225us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
> events/0-9     0D... 459225us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
> events/0-9     0D... 459226us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
> events/0-9     0D... 459226us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
> events/0-9     0D... 459226us : _raw_spin_unlock+0xe/0xa0 (_spin_unlock_irq+0x2b/0x40)
> events/0-9     0D... 459227us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0x93/0x170)
> events/0-9     0D... 459227us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0xab/0x170)
> events/0-9     0.... 459227us : defense_work_handler+0x9/0x30 (run_workqueue+0x11e/0x190)
> events/0-9     0.... 459228us : update_defense_level+0x10/0x2a0 (defense_work_handler+0xe/0x30)
> events/0-9     0.... 459228us : si_meminfo+0xe/0x60 (update_defense_level+0x1c/0x2a0)
> events/0-9     0.... 459228us : nr_blockdev_pages+0xe/0x90 (si_meminfo+0x3d/0x60)
> events/0-9     0.... 459229us : _spin_lock+0x16/0x70 (nr_blockdev_pages+0x1a/0x90)
> events/0-9     0D... 459229us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
> events/0-9     0D... 459229us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
> events/0-9     0D... 459229us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
> events/0-9     0D... 459230us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
> events/0-9     0.... 459230us : _raw_spin_trylock+0x9/0x40 (_spin_lock+0x3d/0x70)
> events/0-9     0.... 459230us : lock_acquired+0x16/0x220 (_spin_lock+0x5d/0x70)
> events/0-9     0D... 459231us : get_lock_stats+0x9/0x40 (lock_acquired+0xff/0x220)
> events/0-9     0.... 459232us : _spin_unlock+0xe/0x40 (nr_blockdev_pages+0x81/0x90)
> events/0-9     0D... 459233us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
> events/0-9     0D... 459233us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
> events/0-9     0D... 459233us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
> events/0-9     0D... 459233us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
> events/0-9     0.... 459234us : _raw_spin_unlock+0xe/0xa0 (_spin_unlock+0x2b/0x40)
> events/0-9     0.... 459234us : local_bh_disable+0x9/0x20 (update_defense_level+0x34/0x2a0)
> events/0-9     0.... 459235us : __local_bh_disable+0x16/0xb0 (local_bh_disable+0x12/0x20)
> events/0-9     0D... 459235us : in_lock_functions+0x9/0x30 (add_preempt_count+0x18/0x50)
> events/0-9     0D.s. 459235us : trace_softirqs_off+0x9/0xe0 (__local_bh_disable+0x6f/0xb0)
> events/0-9     0..s. 459235us : _spin_lock+0x16/0x70 (update_defense_level+0x40/0x2a0)
> events/0-9     0D.s. 459236us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
> events/0-9     0D.s. 459236us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
> events/0-9     0D.s. 459236us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
> events/0-9     0D.s. 459237us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
> events/0-9     0..s. 459237us : _raw_spin_trylock+0x9/0x40 (_spin_lock+0x3d/0x70)
> events/0-9     0..s. 459237us : lock_acquired+0x16/0x220 (_spin_lock+0x5d/0x70)
> events/0-9     0D.s. 459238us : get_lock_stats+0x9/0x40 (lock_acquired+0xff/0x220)
> events/0-9     0..s. 459238us : _spin_unlock+0xe/0x40 (update_defense_level+0x73/0x2a0)
> events/0-9     0D.s. 459238us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
> events/0-9     0D.s. 459239us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
> events/0-9     0D.s. 459239us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
> events/0-9     0D.s. 459239us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
> events/0-9     0..s. 459239us : _raw_spin_unlock+0xe/0xa0 (_spin_unlock+0x2b/0x40)
> events/0-9     0..s. 459240us : _spin_lock+0x16/0x70 (update_defense_level+0x7f/0x2a0)
> events/0-9     0D.s. 459240us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
> events/0-9     0D.s. 459240us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
> events/0-9     0D.s. 459241us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
> events/0-9     0D.s. 459241us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
> events/0-9     0..s. 459241us : _raw_spin_trylock+0x9/0x40 (_spin_lock+0x3d/0x70)
> events/0-9     0..s. 459242us : lock_acquired+0x16/0x220 (_spin_lock+0x5d/0x70)
> events/0-9     0D.s. 459242us : get_lock_stats+0x9/0x40 (lock_acquired+0xff/0x220)
> events/0-9     0..s. 459242us : _spin_unlock+0xe/0x40 (update_defense_level+0xbc/0x2a0)
> events/0-9     0D.s. 459243us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
> events/0-9     0D.s. 459243us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
> events/0-9     0D.s. 459243us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
> events/0-9     0D.s. 459244us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
> events/0-9     0..s. 459244us : _raw_spin_unlock+0xe/0xa0 (_spin_unlock+0x2b/0x40)
> events/0-9     0..s. 459244us : _write_lock+0x16/0x70 (update_defense_level+0xc8/0x2a0)
> events/0-9     0D.s. 459245us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
> events/0-9     0D.s. 459245us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
> events/0-9     0D.s. 459245us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
> events/0-9     0D.s. 459246us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
> events/0-9     0..s. 459246us : _raw_write_trylock+0x9/0x50 (_write_lock+0x3d/0x70)
> events/0-9     0..s. 459246us : lock_acquired+0x16/0x220 (_write_lock+0x5d/0x70)
> events/0-9     0D.s. 459247us : get_lock_stats+0x9/0x40 (lock_acquired+0xff/0x220)
> events/0-9     0..s. 459247us : _write_unlock+0xe/0x40 (update_defense_level+0xf5/0x2a0)
> events/0-9     0D.s. 459247us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
> events/0-9     0D.s. 459248us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
> events/0-9     0D.s. 459248us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
> events/0-9     0D.s. 459248us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
> events/0-9     0..s. 459249us : _raw_write_unlock+0xe/0x90 (_write_unlock+0x2b/0x40)
> events/0-9     0..s. 459249us : local_bh_enable+0xe/0x160 (update_defense_level+0xfa/0x2a0)
> events/0-9     0D.s. 459249us : trace_softirqs_on+0x9/0xb0 (local_bh_enable+0xba/0x160)
> events/0-9     0D... 459249us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0x93/0x170)
> events/0-9     0D... 459250us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0xab/0x170)
> events/0-9     0.... 459250us : schedule_delayed_work+0x16/0x50 (defense_work_handler+0x2e/0x30)
> events/0-9     0.... 459250us : __timer_stats_timer_set_start_info+0x9/0x50 (schedule_delayed_work+0x29/0x50)
> events/0-9     0.... 459251us : queue_delayed_work+0x19/0x70 (schedule_delayed_work+0x3b/0x50)
> events/0-9     0.... 459251us : __timer_stats_timer_set_start_info+0x9/0x50 (queue_delayed_work+0x2f/0x70)
> events/0-9     0.... 459251us : queue_delayed_work_on+0x10/0xe0 (queue_delayed_work+0x63/0x70)
> events/0-9     0.... 459252us : wq_per_cpu+0x9/0x30 (queue_delayed_work_on+0x56/0xe0)
> events/0-9     0.... 459252us : __mod_timer+0x16/0xe0 (queue_delayed_work_on+0xa2/0xe0)
> events/0-9     0.... 459252us : __timer_stats_timer_set_start_info+0x9/0x50 (__mod_timer+0x25/0xe0)
> events/0-9     0.... 459252us : lock_timer_base+0x20/0x70 (__mod_timer+0x3f/0xe0)
> events/0-9     0.... 459253us : _spin_lock_irqsave+0x19/0x80 (lock_timer_base+0x3b/0x70)
> events/0-9     0D... 459253us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
> events/0-9     0D... 459253us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
> events/0-9     0D... 459254us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
> events/0-9     0D... 459254us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
> events/0-9     0D... 459254us : _raw_spin_trylock+0x9/0x40 (_spin_lock_irqsave+0x4a/0x80)
> events/0-9     0D... 459255us : lock_acquired+0x16/0x220 (_spin_lock_irqsave+0x6a/0x80)
> events/0-9     0D... 459255us : get_lock_stats+0x9/0x40 (lock_acquired+0xff/0x220)
> events/0-9     0D... 459255us : internal_add_timer+0x9/0xe0 (__mod_timer+0xbc/0xe0)
> events/0-9     0D... 459256us : __list_add+0x9/0x60 (internal_add_timer+0x3b/0xe0)
> events/0-9     0D... 459256us : _spin_unlock_irqrestore+0x16/0x60 (__mod_timer+0xc8/0xe0)
> events/0-9     0D... 459256us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
> events/0-9     0D... 459256us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
> events/0-9     0D... 459257us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
> events/0-9     0D... 459257us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
> events/0-9     0D... 459257us : _raw_spin_unlock+0xe/0xa0 (_spin_unlock_irqrestore+0x36/0x60)
> events/0-9     0D... 459258us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0x93/0x170)
> events/0-9     0D... 459258us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0xab/0x170)
> events/0-9     0.... 459258us : _spin_lock_irq+0xc/0x60 (run_workqueue+0xb9/0x190)
> events/0-9     0D... 459258us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
> events/0-9     0D... 459259us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
> events/0-9     0D... 459259us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
> events/0-9     0D... 459259us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
> events/0-9     0D... 459260us : _raw_spin_trylock+0x9/0x40 (_spin_lock_irq+0x3a/0x60)
> events/0-9     0D... 459260us : lock_acquired+0x16/0x220 (_spin_lock_irq+0x5a/0x60)
> events/0-9     0D... 459260us : get_lock_stats+0x9/0x40 (lock_acquired+0xff/0x220)
> events/0-9     0D... 459261us : _spin_unlock_irq+0xe/0x40 (run_workqueue+0x177/0x190)
> events/0-9     0D... 459261us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
> events/0-9     0D... 459261us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
> events/0-9     0D... 459262us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
> events/0-9     0D... 459262us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
> events/0-9     0D... 459262us : _raw_spin_unlock+0xe/0xa0 (_spin_unlock_irq+0x2b/0x40)
> events/0-9     0D... 459262us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0x93/0x170)
> events/0-9     0D... 459263us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0xab/0x170)
> events/0-9     0.... 459263us : prepare_to_wait+0x20/0x90 (worker_thread+0xc3/0x120)
> events/0-9     0.... 459263us : _spin_lock_irqsave+0x19/0x80 (prepare_to_wait+0x31/0x90)
> events/0-9     0D... 459264us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
> events/0-9     0D... 459264us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
> events/0-9     0D... 459264us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
> events/0-9     0D... 459264us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
> events/0-9     0D... 459265us : _raw_spin_trylock+0x9/0x40 (_spin_lock_irqsave+0x4a/0x80)
> events/0-9     0D... 459265us : lock_acquired+0x16/0x220 (_spin_lock_irqsave+0x6a/0x80)
> events/0-9     0D... 459265us : get_lock_stats+0x9/0x40 (lock_acquired+0xff/0x220)
> events/0-9     0D... 459266us : list_add+0x9/0x20 (prepare_to_wait+0x81/0x90)
> events/0-9     0D... 459266us : __list_add+0x9/0x60 (list_add+0x11/0x20)
> events/0-9     0D... 459266us : _spin_unlock_irqrestore+0x16/0x60 (prepare_to_wait+0x62/0x90)
> events/0-9     0D... 459267us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
> events/0-9     0D... 459267us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
> events/0-9     0D... 459267us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
> events/0-9     0D... 459267us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
> events/0-9     0D... 459268us : _raw_spin_unlock+0xe/0xa0 (_spin_unlock_irqrestore+0x36/0x60)
> events/0-9     0D... 459268us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0x93/0x170)
> events/0-9     0D... 459268us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0xab/0x170)
> events/0-9     0.... 459269us : kthread_should_stop+0x9/0x30 (worker_thread+0xdf/0x120)
> events/0-9     0.... 459269us : __sched_text_start+0x19/0x34a (worker_thread+0xf5/0x120)
> events/0-9     0.... 459269us : _spin_lock_irq+0xc/0x60 (__sched_text_start+0x10f/0x34a)
> events/0-9     0D... 459269us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
> events/0-9     0D... 459270us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
> events/0-9     0D... 459270us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
> events/0-9     0D... 459270us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
> events/0-9     0D... 459271us : _raw_spin_trylock+0x9/0x40 (_spin_lock_irq+0x3a/0x60)
> events/0-9     0D... 459271us : lock_acquired+0x16/0x220 (_spin_lock_irq+0x5a/0x60)
> events/0-9     0D... 459271us : get_lock_stats+0x9/0x40 (lock_acquired+0xff/0x220)
> events/0-9     0D... 459272us : __update_rq_clock+0x20/0x130 (__sched_text_start+0x125/0x34a)
> events/0-9     0D... 459272us : sched_clock+0x9/0x30 (__update_rq_clock+0x2f/0x130)
> events/0-9     0D... 459272us : deactivate_task+0x16/0x60 (thread_return+0x173/0x686)
> events/0-9     0D... 459272us : dequeue_task+0xe/0x30 (deactivate_task+0x38/0x60)
> events/0-9     0D... 459273us : dequeue_task_fair+0x9/0x40 (dequeue_task+0x18/0x30)
> events/0-9     0D... 459273us : dequeue_entity+0x20/0x100 (dequeue_task_fair+0x3b/0x40)
> events/0-9     0D... 459273us : update_curr+0x21/0x140 (dequeue_entity+0x35/0x100)
> events/0-9     0D... 459274us : calc_delta_mine+0x9/0x90 (update_curr+0xc6/0x140)
> events/0-9     0D... 459274us : calc_delta_mine+0x9/0x90 (update_curr+0xda/0x140)
> events/0-9     0D... 459274us : add_wait_runtime+0x9/0x60 (update_curr+0x125/0x140)
> events/0-9     0D... 459275us : rb_next+0x9/0x60 (dequeue_entity+0xf8/0x100)
> events/0-9     0D... 459275us : rb_erase+0xc/0x320 (dequeue_entity+0xa1/0x100)
> events/0-9     0D... 459275us : update_load_sub+0x9/0x20 (dequeue_entity+0xad/0x100)
> events/0-9     0D... 459275us : update_curr_load+0x16/0xb0 (deactivate_task+0x45/0x60)
> events/0-9     0D... 459276us : calc_delta_mine+0x9/0x90 (update_curr_load+0x92/0xb0)
> events/0-9     0D... 459276us : update_load_sub+0x9/0x20 (deactivate_task+0x53/0x60)
> events/0-9     0D... 459276us : put_prev_task_fair+0x16/0xa0 (__sched_text_start+0x163/0x34a)
> events/0-9     0D... 459277us : pick_next_task_fair+0x1b/0x70 (__sched_text_start+0x17d/0x34a)
> events/0-9     0D... 459277us : __pick_next_entity+0x9/0x20 (pick_next_task_fair+0x39/0x70)
> events/0-9     0D... 459277us : update_stats_wait_end+0xa/0xb0 (pick_next_task_fair+0x47/0x70)
> events/0-9     0D... 459277us : add_wait_runtime+0x9/0x60 (update_stats_wait_end+0x9c/0xb0)
> events/0-9     0D... 459278us : sched_clock+0x9/0x30 (__sched_text_start+0x1b9/0x34a)
> events/0-9     0D... 459278us : sched_clock+0x9/0x30 (__sched_text_start+0x20b/0x34a)
> events/0-9     0D... 459279us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
> events/0-9     0D... 459279us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
> events/0-9     0D... 459279us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
> events/0-9     0D... 459279us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
> events/0-9     0D... 459280us : __switch_to+0x16/0x2e0 (thread_return+0x0/0x686)
> kpktgend-1280  0D... 459280us : thread_return+0x72/0x686 <events/0-9> (-5 -5)
> kpktgend-1280  0D... 459281us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
> kpktgend-1280  0D... 459281us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
> kpktgend-1280  0D... 459281us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
> kpktgend-1280  0D... 459282us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
> kpktgend-1280  0D... 459282us : _spin_unlock_irq+0xe/0x40 (thread_return+0xd0/0x686)
> kpktgend-1280  0D... 459282us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
> kpktgend-1280  0D... 459283us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
> kpktgend-1280  0D... 459283us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
> kpktgend-1280  0D... 459283us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
> kpktgend-1280  0D... 459284us : _raw_spin_unlock+0xe/0xa0 (_spin_unlock_irq+0x2b/0x40)
> kpktgend-1280  0D... 459284us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0x93/0x170)
> kpktgend-1280  0D... 459284us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0xab/0x170)
> kpktgend-1280  0.... 459284us : trace_stop_sched_switched+0x21/0x310 (thread_return+0xde/0x686)
> kpktgend-1280  0.... 459285us : del_timer_sync+0xe/0x30 (schedule_timeout+0x70/0xd0)
> kpktgend-1280  0.... 459285us : try_to_del_timer_sync+0x10/0x70 (del_timer_sync+0x1d/0x30)
> kpktgend-1280  0.... 459285us : lock_timer_base+0x20/0x70 (try_to_del_timer_sync+0x22/0x70)
> kpktgend-1280  0.... 459286us : _spin_lock_irqsave+0x19/0x80 (lock_timer_base+0x3b/0x70)
> kpktgend-1280  0D... 459286us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
> kpktgend-1280  0D... 459286us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
> kpktgend-1280  0D... 459287us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
> kpktgend-1280  0D... 459287us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
> kpktgend-1280  0D... 459287us : _raw_spin_trylock+0x9/0x40 (_spin_lock_irqsave+0x4a/0x80)
> kpktgend-1280  0D... 459287us : lock_acquired+0x16/0x220 (_spin_lock_irqsave+0x6a/0x80)
> kpktgend-1280  0D... 459288us : get_lock_stats+0x9/0x40 (lock_acquired+0xff/0x220)
> kpktgend-1280  0D... 459288us : _spin_unlock_irqrestore+0x16/0x60 (try_to_del_timer_sync+0x5c/0x70)
> kpktgend-1280  0D... 459288us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
> kpktgend-1280  0D... 459289us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
> kpktgend-1280  0D... 459289us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
> kpktgend-1280  0D... 459289us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
> kpktgend-1280  0D... 459290us : _raw_spin_unlock+0xe/0xa0 (_spin_unlock_irqrestore+0x36/0x60)
> kpktgend-1280  0D... 459290us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0x93/0x170)
> kpktgend-1280  0D... 459290us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0xab/0x170)
> kpktgend-1280  0.... 459291us : finish_wait+0x19/0x80 (pktgen_thread_worker+0x1237/0x1500)
> kpktgend-1280  0.... 459291us : _spin_lock_irqsave+0x19/0x80 (finish_wait+0x41/0x80)
> kpktgend-1280  0D... 459291us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
> kpktgend-1280  0D... 459291us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
> kpktgend-1280  0D... 459292us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
> kpktgend-1280  0D... 459292us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
> kpktgend-1280  0D... 459292us : _raw_spin_trylock+0x9/0x40 (_spin_lock_irqsave+0x4a/0x80)
> kpktgend-1280  0D... 459293us : lock_acquired+0x16/0x220 (_spin_lock_irqsave+0x6a/0x80)
> kpktgend-1280  0D... 459293us : get_lock_stats+0x9/0x40 (lock_acquired+0xff/0x220)
> kpktgend-1280  0D... 459293us : _spin_unlock_irqrestore+0x16/0x60 (finish_wait+0x63/0x80)
> kpktgend-1280  0D... 459294us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
> kpktgend-1280  0D... 459294us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
> kpktgend-1280  0D... 459294us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
> kpktgend-1280  0D... 459294us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
> kpktgend-1280  0D... 459295us : _raw_spin_unlock+0xe/0xa0 (_spin_unlock_irqrestore+0x36/0x60)
> kpktgend-1280  0D... 459295us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0x93/0x170)
> kpktgend-1280  0D... 459295us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0xab/0x170)
> kpktgend-1280  0.... 459296us : kthread_should_stop+0x9/0x30 (pktgen_thread_worker+0x467/0x1500)
> kpktgend-1280  0.... 459296us : _spin_lock+0x16/0x70 (pktgen_thread_worker+0xcb/0x1500)
> kpktgend-1280  0D... 459296us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
> kpktgend-1280  0D... 459297us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
> kpktgend-1280  0D... 459297us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
> kpktgend-1280  0D... 459297us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
> kpktgend-1280  0.... 459298us : _raw_spin_trylock+0x9/0x40 (_spin_lock+0x3d/0x70)
> kpktgend-1280  0.... 459298us : lock_acquired+0x16/0x220 (_spin_lock+0x5d/0x70)
> kpktgend-1280  0D... 459298us : get_lock_stats+0x9/0x40 (lock_acquired+0xff/0x220)
> kpktgend-1280  0.... 459298us : _spin_unlock+0xe/0x40 (pktgen_thread_worker+0x1039/0x1500)
> kpktgend-1280  0D... 459299us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
> kpktgend-1280  0D... 459299us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
> kpktgend-1280  0D... 459299us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
> kpktgend-1280  0D... 459300us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
> kpktgend-1280  0.... 459300us : _raw_spin_unlock+0xe/0xa0 (_spin_unlock+0x2b/0x40)
> kpktgend-1280  0.... 459300us : prepare_to_wait+0x20/0x90 (pktgen_thread_worker+0x121d/0x1500)
> kpktgend-1280  0.... 459301us : _spin_lock_irqsave+0x19/0x80 (prepare_to_wait+0x31/0x90)
> kpktgend-1280  0D... 459301us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
> kpktgend-1280  0D... 459301us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
> kpktgend-1280  0D... 459301us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
> kpktgend-1280  0D... 459302us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
> kpktgend-1280  0D... 459302us : _raw_spin_trylock+0x9/0x40 (_spin_lock_irqsave+0x4a/0x80)
> kpktgend-1280  0D... 459302us : lock_acquired+0x16/0x220 (_spin_lock_irqsave+0x6a/0x80)
> kpktgend-1280  0D... 459303us : get_lock_stats+0x9/0x40 (lock_acquired+0xff/0x220)
> kpktgend-1280  0D... 459303us : list_add+0x9/0x20 (prepare_to_wait+0x81/0x90)
> kpktgend-1280  0D... 459303us : __list_add+0x9/0x60 (list_add+0x11/0x20)
> kpktgend-1280  0D... 459303us : _spin_unlock_irqrestore+0x16/0x60 (prepare_to_wait+0x62/0x90)
> kpktgend-1280  0D... 459304us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
> kpktgend-1280  0D... 459304us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
> kpktgend-1280  0D... 459304us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
> kpktgend-1280  0D... 459305us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
> kpktgend-1280  0D... 459305us : _raw_spin_unlock+0xe/0xa0 (_spin_unlock_irqrestore+0x36/0x60)
> kpktgend-1280  0D... 459305us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0x93/0x170)
> kpktgend-1280  0D... 459305us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0xab/0x170)
> kpktgend-1280  0.... 459306us : schedule_timeout+0x15/0xd0 (pktgen_thread_worker+0x1227/0x1500)
> kpktgend-1280  0.... 459306us : init_timer+0x9/0x50 (schedule_timeout+0x58/0xd0)
> kpktgend-1280  0.... 459306us : __mod_timer+0x16/0xe0 (schedule_timeout+0x63/0xd0)
> kpktgend-1280  0.... 459307us : __timer_stats_timer_set_start_info+0x9/0x50 (__mod_timer+0x25/0xe0)
> kpktgend-1280  0.... 459307us : lock_timer_base+0x20/0x70 (__mod_timer+0x3f/0xe0)
> kpktgend-1280  0.... 459307us : _spin_lock_irqsave+0x19/0x80 (lock_timer_base+0x3b/0x70)
> kpktgend-1280  0D... 459308us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
> kpktgend-1280  0D... 459308us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
> kpktgend-1280  0D... 459308us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
> kpktgend-1280  0D... 459308us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
> kpktgend-1280  0D... 459309us : _raw_spin_trylock+0x9/0x40 (_spin_lock_irqsave+0x4a/0x80)
> kpktgend-1280  0D... 459309us : lock_acquired+0x16/0x220 (_spin_lock_irqsave+0x6a/0x80)
> kpktgend-1280  0D... 459309us : get_lock_stats+0x9/0x40 (lock_acquired+0xff/0x220)
> kpktgend-1280  0D... 459310us : internal_add_timer+0x9/0xe0 (__mod_timer+0xbc/0xe0)
> kpktgend-1280  0D... 459310us : __list_add+0x9/0x60 (internal_add_timer+0x3b/0xe0)
> kpktgend-1280  0D... 459310us : _spin_unlock_irqrestore+0x16/0x60 (__mod_timer+0xc8/0xe0)
> kpktgend-1280  0D... 459311us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
> kpktgend-1280  0D... 459311us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
> kpktgend-1280  0D... 459311us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
> kpktgend-1280  0D... 459311us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
> kpktgend-1280  0D... 459312us : _raw_spin_unlock+0xe/0xa0 (_spin_unlock_irqrestore+0x36/0x60)
> kpktgend-1280  0D... 459312us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0x93/0x170)
> kpktgend-1280  0D... 459312us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0xab/0x170)
> kpktgend-1280  0.... 459313us : __sched_text_start+0x19/0x34a (schedule_timeout+0x68/0xd0)
> kpktgend-1280  0.... 459313us : _spin_lock_irq+0xc/0x60 (__sched_text_start+0x10f/0x34a)
> kpktgend-1280  0D... 459313us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
> kpktgend-1280  0D... 459314us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
> kpktgend-1280  0D... 459314us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
> kpktgend-1280  0D... 459314us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
> kpktgend-1280  0D... 459315us : _raw_spin_trylock+0x9/0x40 (_spin_lock_irq+0x3a/0x60)
> kpktgend-1280  0D... 459315us : lock_acquired+0x16/0x220 (_spin_lock_irq+0x5a/0x60)
> kpktgend-1280  0D... 459315us : get_lock_stats+0x9/0x40 (lock_acquired+0xff/0x220)
> kpktgend-1280  0D... 459315us : __update_rq_clock+0x20/0x130 (__sched_text_start+0x125/0x34a)
> kpktgend-1280  0D... 459316us : sched_clock+0x9/0x30 (__update_rq_clock+0x2f/0x130)
> kpktgend-1280  0D... 459316us : deactivate_task+0x16/0x60 (thread_return+0x173/0x686)
> kpktgend-1280  0D... 459316us : dequeue_task+0xe/0x30 (deactivate_task+0x38/0x60)
> kpktgend-1280  0D... 459317us : dequeue_task_fair+0x9/0x40 (dequeue_task+0x18/0x30)
> kpktgend-1280  0D... 459317us : dequeue_entity+0x20/0x100 (dequeue_task_fair+0x3b/0x40)
> kpktgend-1280  0D... 459317us : update_curr+0x21/0x140 (dequeue_entity+0x35/0x100)
> kpktgend-1280  0D... 459317us : calc_delta_mine+0x9/0x90 (update_curr+0xc6/0x140)
> kpktgend-1280  0D... 459318us : calc_delta_mine+0x9/0x90 (update_curr+0xda/0x140)
> kpktgend-1280  0D... 459318us : add_wait_runtime+0x9/0x60 (update_curr+0x125/0x140)
> kpktgend-1280  0D... 459318us : rb_next+0x9/0x60 (dequeue_entity+0xf8/0x100)
> kpktgend-1280  0D... 459319us : rb_erase+0xc/0x320 (dequeue_entity+0xa1/0x100)
> kpktgend-1280  0D... 459319us : update_load_sub+0x9/0x20 (dequeue_entity+0xad/0x100)
> kpktgend-1280  0D... 459319us : update_curr_load+0x16/0xb0 (deactivate_task+0x45/0x60)
> kpktgend-1280  0D... 459320us : calc_delta_mine+0x9/0x90 (update_curr_load+0x92/0xb0)
> kpktgend-1280  0D... 459320us : update_load_sub+0x9/0x20 (deactivate_task+0x53/0x60)
> kpktgend-1280  0D... 459320us : find_busiest_group+0x19/0x870 (thread_return+0x2eb/0x686)
> kpktgend-1280  0D... 459321us : __first_cpu+0x9/0x30 (find_busiest_group+0x556/0x870)
> kpktgend-1280  0D... 459321us : __first_cpu+0x9/0x30 (find_busiest_group+0x16f/0x870)
> kpktgend-1280  0D... 459321us : idle_cpu+0x9/0x40 (find_busiest_group+0x1d0/0x870)
> kpktgend-1280  0D... 459321us : weighted_cpuload+0x9/0x30 (find_busiest_group+0x1ec/0x870)
> kpktgend-1280  0D... 459322us : weighted_cpuload+0x9/0x30 (find_busiest_group+0x225/0x870)
> kpktgend-1280  0D... 459322us : __next_cpu+0xa/0x40 (find_busiest_group+0x233/0x870)
> kpktgend-1280  0D... 459322us : __first_cpu+0x9/0x30 (find_busiest_group+0x16f/0x870)
> kpktgend-1280  0D... 459323us : weighted_cpuload+0x9/0x30 (find_busiest_group+0x28e/0x870)
> kpktgend-1280  0D... 459323us : weighted_cpuload+0x9/0x30 (find_busiest_group+0x225/0x870)
> kpktgend-1280  0D... 459323us : __next_cpu+0xa/0x40 (find_busiest_group+0x233/0x870)
> kpktgend-1280  0D... 459323us : msecs_to_jiffies+0x9/0x40 (thread_return+0x260/0x686)
> kpktgend-1280  0D... 459324us : msecs_to_jiffies+0x9/0x40 (thread_return+0x260/0x686)
> kpktgend-1280  0D... 459324us : put_prev_task_fair+0x16/0xa0 (__sched_text_start+0x163/0x34a)
> kpktgend-1280  0D... 459324us : pick_next_task_fair+0x1b/0x70 (__sched_text_start+0x17d/0x34a)
> kpktgend-1280  0D... 459325us : pick_next_task_rt+0x9/0x60 (thread_return+0x1ad/0x686)
> kpktgend-1280  0D... 459325us : pick_next_task_fair+0x1b/0x70 (thread_return+0x1ad/0x686)
> kpktgend-1280  0D... 459325us : pick_next_task_idle+0x9/0x20 (thread_return+0x1ad/0x686)
> kpktgend-1280  0D... 459326us : sched_clock+0x9/0x30 (__sched_text_start+0x1b9/0x34a)
> kpktgend-1280  0D... 459326us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
> kpktgend-1280  0D... 459326us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
> kpktgend-1280  0D... 459327us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
> kpktgend-1280  0D... 459327us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
> kpktgend-1280  0D... 459328us : __switch_to+0x16/0x2e0 (thread_return+0x0/0x686)
>   <idle>-0     0D... 459328us : thread_return+0x72/0x686 <kpktgend-1280> (-5 20)
>   <idle>-0     0D... 459329us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
>   <idle>-0     0D... 459329us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
>   <idle>-0     0D... 459329us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
>   <idle>-0     0D... 459330us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
>   <idle>-0     0D... 459330us : _spin_unlock_irq+0xe/0x40 (thread_return+0xd0/0x686)
>   <idle>-0     0D... 459330us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
>   <idle>-0     0D... 459331us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
>   <idle>-0     0D... 459331us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
>   <idle>-0     0D... 459331us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
>   <idle>-0     0D... 459331us : _raw_spin_unlock+0xe/0xa0 (_spin_unlock_irq+0x2b/0x40)
>   <idle>-0     0D... 459332us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0x93/0x170)
>   <idle>-0     0D... 459332us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0xab/0x170)
>   <idle>-0     0.... 459332us : trace_stop_sched_switched+0x21/0x310 (thread_return+0xde/0x686)
>   <idle>-0     0D... 459333us : enter_idle+0x9/0x30 (cpu_idle+0x7b/0xd0)
>   <idle>-0     0D... 459333us : atomic_notifier_call_chain+0x9/0x20 (enter_idle+0x27/0x30)
>   <idle>-0     0D... 459333us : __atomic_notifier_call_chain+0x9/0x20 (atomic_notifier_call_chain+0x16/0x20)
>   <idle>-0     0D... 459334us : notifier_call_chain+0x16/0x80 (__atomic_notifier_call_chain+0x12/0x20)
>   <idle>-0     0D... 459334us : mce_idle_callback+0x9/0x40 (notifier_call_chain+0x41/0x80)

Re: large latency on heavy NFS writeback

[Fengguang Wu]

And here is /proc/schedstat:

version 14
timestamp 4295709123
cpu0 0 0 0 9826 0 8147092 2368880 4562614 3204914 1923746542825 1668572097374 5778212
domain0 03 519900 420205 15340 213485458 102464 0 204 420001 4427 4395 2 39589 41 0 0 4395 2445488 2355039 13841 502197903 87954 0 229 2354810 17 1 16 0 0 0 0 0 0 1349332 3751 0
domain1 03 130642 130642 0 0 0 0 0 130642 639 639 0 0 0 0 0 600 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
cpu1 0 0 0 7227 0 4666153 1649090 2544408 1195073 2765150191631 936745663460 3017063
domain0 03 496555 470765 1864 76094877 26082 0 1 470764 804 708 15 638637 138 0 0 708 1816468 1597399 51690 557807800 204737 0 256 1597143 14 4 10 0 0 0 0 0 0 1357700 9038 0
domain1 03 127585 127585 0 0 0 0 0 8622 199 199 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0

Fengguang
---
On Tue, Oct 02, 2007 at 07:19:31PM +0800, Fengguang Wu wrote:
> Ingo,
> 
> [In the hope that you are better at analyzing such problems.]
> 
> I collected some large latency numbers with you latency tracing patch.
> The system is writing to a NFS dir:
>         cp /dev/zero /mnt/
> 
> The /proc/latency_trace is:
> 
> preemption latency trace v1.1.5 on 2.6.23-rc8
> --------------------------------------------------------------------
>  latency: 2021410 us, #2/2, CPU#0 | (M:server VP:0, KP:0, SP:0 HP:0 #P:2)
>     -----------------
>     | task: migration/0-3 (uid:0 nice:-5 policy:1 rt_prio:99)
>     -----------------
>  => started at: try_to_wake_up+0x2a5/0x500 <ffffffff8103b9f5>
>  => ended at:   thread_return+0xde/0x686 <ffffffff81696b28>
>                  
>                  _------=> CPU#
>                 / _-----=> irqs-off
>                | / _----=> need-resched
>                || / _---=> hardirq/softirq
>                ||| / _--=> preempt-depth
>                |||| /
>                |||||     delay
>    cmd     pid ||||| time  |   caller
>       \   /    |||||   \   |   /
>    <...>-3     0.... 2021410us : thread_return+0xde/0x686 (thread_return+0xde/0x686)
> 
> 
> When the test continues for a long time, the system eventually locked up.
> I managed to recover it and collected a new latency_trace and sysrq-t.
> The .config, oprofile and lock_stat numbers are also attached.
> 
> Thank you,
> Fengguang

> preemption latency trace v1.1.5 on 2.6.23-rc8
> --------------------------------------------------------------------
>  latency: 1000013964 us, #65536/582887385, CPU#0 | (M:server VP:0, KP:0, SP:0 HP:0 #P:2)
>     -----------------
>     | task: trace-it-6278 (uid:0 nice:0 policy:0 rt_prio:0)
>     -----------------
> 
>                  _------=> CPU#            
>                 / _-----=> irqs-off        
>                | / _----=> need-resched    
>                || / _---=> hardirq/softirq 
>                ||| / _--=> preempt-depth   
>                |||| /                      
>                |||||     delay             
>    cmd     pid ||||| time  |   caller      
>       \   /    |||||   \   |   /           
>   <idle>-0     0.N.. 112248us : __exit_idle+0x9/0x40 (cpu_idle+0x85/0xd0)
>   <idle>-0     0.N.. 112248us : atomic_notifier_call_chain+0x9/0x20 (__exit_idle+0x33/0x40)
>   <idle>-0     0.N.. 112249us : __atomic_notifier_call_chain+0x9/0x20 (atomic_notifier_call_chain+0x16/0x20)
>   <idle>-0     0.N.. 112249us : notifier_call_chain+0x16/0x80 (__atomic_notifier_call_chain+0x12/0x20)
>   <idle>-0     0.N.. 112249us : mce_idle_callback+0x9/0x40 (notifier_call_chain+0x41/0x80)
>   <idle>-0     0.N.. 112249us : __sched_text_start+0x19/0x34a (cpu_idle+0x9d/0xd0)
>   <idle>-0     0.N.. 112250us : _spin_lock_irq+0xc/0x60 (__sched_text_start+0x10f/0x34a)
>   <idle>-0     0DN.. 112250us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
>   <idle>-0     0DN.. 112250us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
>   <idle>-0     0DN.. 112251us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
>   <idle>-0     0DN.. 112251us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
>   <idle>-0     0DN.. 112251us : _raw_spin_trylock+0x9/0x40 (_spin_lock_irq+0x3a/0x60)
>   <idle>-0     0DN.. 112252us : lock_acquired+0x16/0x220 (_spin_lock_irq+0x5a/0x60)
>   <idle>-0     0DN.. 112252us : get_lock_stats+0x9/0x40 (lock_acquired+0xff/0x220)
>   <idle>-0     0D... 112252us : __update_rq_clock+0x20/0x130 (__sched_text_start+0x125/0x34a)
>   <idle>-0     0D... 112253us : sched_clock+0x9/0x30 (__update_rq_clock+0x2f/0x130)
>   <idle>-0     0D... 112253us : put_prev_task_idle+0x9/0x10 (__sched_text_start+0x163/0x34a)
>   <idle>-0     0D... 112253us : pick_next_task_fair+0x1b/0x70 (__sched_text_start+0x17d/0x34a)
>   <idle>-0     0D... 112254us : __pick_next_entity+0x9/0x20 (pick_next_task_fair+0x39/0x70)
>   <idle>-0     0D... 112254us : update_stats_wait_end+0xa/0xb0 (pick_next_task_fair+0x47/0x70)
>   <idle>-0     0D... 112254us : add_wait_runtime+0x9/0x60 (update_stats_wait_end+0x9c/0xb0)
>   <idle>-0     0D... 112255us : sched_clock+0x9/0x30 (__sched_text_start+0x20b/0x34a)
>   <idle>-0     0D... 112255us : __phys_addr+0x9/0x40 (__sched_text_start+0x2e7/0x34a)
>   <idle>-0     0D... 112256us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
>   <idle>-0     0D... 112256us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
>   <idle>-0     0D... 112256us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
>   <idle>-0     0D... 112256us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
>   <idle>-0     0D... 112261us : __switch_to+0x16/0x2e0 (thread_return+0x0/0x686)
>    klogd-4366  0D... 112262us+: thread_return+0x72/0x686 <<idle>-0> (20 0)
>    klogd-4366  0D... 112264us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
>    klogd-4366  0D... 112265us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
>    klogd-4366  0D... 112265us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
>    klogd-4366  0D... 112265us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
>    klogd-4366  0D... 112266us : _spin_unlock_irq+0xe/0x40 (thread_return+0xd0/0x686)
>    klogd-4366  0D... 112266us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
>    klogd-4366  0D... 112266us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
>    klogd-4366  0D... 112267us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
>    klogd-4366  0D... 112267us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
>    klogd-4366  0D... 112267us : _raw_spin_unlock+0xe/0xa0 (_spin_unlock_irq+0x2b/0x40)
>    klogd-4366  0D... 112268us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0x93/0x170)
>    klogd-4366  0D... 112268us!: mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0xab/0x170)
>    klogd-4366  0.N.. 365462us!: trace_stop_sched_switched+0x21/0x310 (thread_return+0xde/0x686)
>    klogd-4366  0.N.. 459157us : _spin_lock_irq+0xc/0x60 (__sched_text_start+0x10f/0x34a)
>    klogd-4366  0DN.. 459157us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
>    klogd-4366  0DN.. 459158us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
>    klogd-4366  0DN.. 459158us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
>    klogd-4366  0DN.. 459158us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
>    klogd-4366  0DN.. 459159us : _raw_spin_trylock+0x9/0x40 (_spin_lock_irq+0x3a/0x60)
>    klogd-4366  0DN.. 459159us : lock_acquired+0x16/0x220 (_spin_lock_irq+0x5a/0x60)
>    klogd-4366  0DN.. 459159us : get_lock_stats+0x9/0x40 (lock_acquired+0xff/0x220)
>    klogd-4366  0D... 459159us : __update_rq_clock+0x20/0x130 (__sched_text_start+0x125/0x34a)
>    klogd-4366  0D... 459160us : sched_clock+0x9/0x30 (__update_rq_clock+0x2f/0x130)
>    klogd-4366  0D... 459160us : put_prev_task_fair+0x16/0xa0 (__sched_text_start+0x163/0x34a)
>    klogd-4366  0D... 459160us : update_curr+0x21/0x140 (put_prev_task_fair+0x95/0xa0)
>    klogd-4366  0D... 459161us : calc_delta_mine+0x9/0x90 (update_curr+0xc6/0x140)
>    klogd-4366  0D... 459161us : calc_delta_mine+0x9/0x90 (update_curr+0xda/0x140)
>    klogd-4366  0D... 459161us : add_wait_runtime+0x9/0x60 (update_curr+0x125/0x140)
>    klogd-4366  0D... 459162us : pick_next_task_rt+0x9/0x60 (thread_return+0x1ad/0x686)
>    klogd-4366  0D... 459162us : sched_clock+0x9/0x30 (__sched_text_start+0x1b9/0x34a)
>    klogd-4366  0D... 459162us : sched_clock+0x9/0x30 (__sched_text_start+0x20b/0x34a)
>    klogd-4366  0D... 459163us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
>    klogd-4366  0D... 459163us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
>    klogd-4366  0D... 459163us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
>    klogd-4366  0D... 459164us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
>    klogd-4366  0D... 459164us : __switch_to+0x16/0x2e0 (thread_return+0x0/0x686)
> migratio-3     0D... 459165us : thread_return+0x72/0x686 <klogd-4366> (0 199)
> migratio-3     0D... 459165us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
> migratio-3     0D... 459166us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
> migratio-3     0D... 459166us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
> migratio-3     0D... 459166us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
> migratio-3     0D... 459167us : _spin_unlock_irq+0xe/0x40 (thread_return+0xd0/0x686)
> migratio-3     0D... 459167us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
> migratio-3     0D... 459167us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
> migratio-3     0D... 459167us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
> migratio-3     0D... 459168us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
> migratio-3     0D... 459168us : _raw_spin_unlock+0xe/0xa0 (_spin_unlock_irq+0x2b/0x40)
> migratio-3     0D... 459168us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0x93/0x170)
> migratio-3     0D... 459169us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0xab/0x170)
> migratio-3     0.... 459169us : trace_stop_sched_switched+0x21/0x310 (thread_return+0xde/0x686)
> migratio-3     0.... 459169us : kthread_should_stop+0x9/0x30 (migration_thread+0x160/0x290)
> migratio-3     0.... 459170us : _spin_lock_irq+0xc/0x60 (migration_thread+0x77/0x290)
> migratio-3     0D... 459170us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
> migratio-3     0D... 459170us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
> migratio-3     0D... 459171us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
> migratio-3     0D... 459171us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
> migratio-3     0D... 459171us : _raw_spin_trylock+0x9/0x40 (_spin_lock_irq+0x3a/0x60)
> migratio-3     0D... 459172us : lock_acquired+0x16/0x220 (_spin_lock_irq+0x5a/0x60)
> migratio-3     0D... 459172us : get_lock_stats+0x9/0x40 (lock_acquired+0xff/0x220)
> migratio-3     0D... 459172us : double_lock_balance+0xc/0x70 (migration_thread+0xd0/0x290)
> migratio-3     0D... 459172us : _spin_trylock+0xe/0x50 (double_lock_balance+0x21/0x70)
> migratio-3     0D... 459173us : _raw_spin_trylock+0x9/0x40 (_spin_trylock+0x16/0x50)
> migratio-3     0D... 459173us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
> migratio-3     0D... 459173us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
> migratio-3     0D... 459174us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
> migratio-3     0D... 459174us : update_rq_clock+0x9/0x20 (migration_thread+0xd8/0x290)
> migratio-3     0D... 459174us : __update_rq_clock+0x20/0x130 (update_rq_clock+0x1e/0x20)
> migratio-3     0D... 459175us : sched_clock+0x9/0x30 (__update_rq_clock+0x2f/0x130)
> migratio-3     0D... 459175us : update_rq_clock+0x9/0x20 (migration_thread+0xe0/0x290)
> migratio-3     0D... 459175us : load_balance_rt+0xd/0x60 (migration_thread+0x217/0x290)
> migratio-3     0D... 459176us : balance_tasks+0x16/0x1c0 (load_balance_rt+0x50/0x60)
> migratio-3     0D... 459176us : load_balance_start_rt+0x9/0x70 (balance_tasks+0x4c/0x1c0)
> migratio-3     0D... 459176us : load_balance_next_rt+0xe/0x90 (balance_tasks+0x7b/0x1c0)
> migratio-3     0D... 459176us : find_next_bit+0xa/0xa0 (load_balance_next_rt+0x57/0x90)
> migratio-3     0D... 459177us : load_balance_fair+0xe/0x90 (migration_thread+0x217/0x290)
> migratio-3     0D... 459177us : balance_tasks+0x16/0x1c0 (load_balance_fair+0x5f/0x90)
> migratio-3     0D... 459177us : load_balance_start_fair+0x16/0x40 (balance_tasks+0x4c/0x1c0)
> migratio-3     0D... 459178us : rb_next+0x9/0x60 (load_balance_start_fair+0x2e/0x40)
> migratio-3     0D... 459178us : load_balance_next_fair+0x16/0x40 (balance_tasks+0x7b/0x1c0)
> migratio-3     0D... 459178us : rb_next+0x9/0x60 (load_balance_next_fair+0x2e/0x40)
> migratio-3     0D... 459179us : load_balance_next_fair+0x16/0x40 (balance_tasks+0x7b/0x1c0)
> migratio-3     0D... 459179us : rb_next+0x9/0x60 (load_balance_next_fair+0x2e/0x40)
> migratio-3     0D... 459179us : deactivate_task+0x16/0x60 (balance_tasks+0xd2/0x1c0)
> migratio-3     0D... 459179us : dequeue_task+0xe/0x30 (deactivate_task+0x38/0x60)
> migratio-3     0D... 459180us : dequeue_task_fair+0x9/0x40 (dequeue_task+0x18/0x30)
> migratio-3     0D... 459180us : dequeue_entity+0x20/0x100 (dequeue_task_fair+0x3b/0x40)
> migratio-3     0D... 459180us : update_curr+0x21/0x140 (dequeue_entity+0x35/0x100)
> migratio-3     0D... 459181us : update_stats_wait_end+0xa/0xb0 (dequeue_entity+0x5f/0x100)
> migratio-3     0D... 459181us : add_wait_runtime+0x9/0x60 (update_stats_wait_end+0x9c/0xb0)
> migratio-3     0D... 459181us : rb_erase+0xc/0x320 (dequeue_entity+0xa1/0x100)
> migratio-3     0D... 459182us : update_load_sub+0x9/0x20 (dequeue_entity+0xad/0x100)
> migratio-3     0D... 459182us : update_curr_load+0x16/0xb0 (deactivate_task+0x45/0x60)
> migratio-3     0D... 459182us : calc_delta_mine+0x9/0x90 (update_curr_load+0x92/0xb0)
> migratio-3     0D... 459182us : update_load_sub+0x9/0x20 (deactivate_task+0x53/0x60)
> migratio-3     0D... 459183us : set_task_cpu+0xc/0xe0 (balance_tasks+0xdd/0x1c0)
> migratio-3     0D... 459183us : trace_change_sched_cpu+0x20/0xf0 (set_task_cpu+0xd3/0xe0)
> migratio-3     0D... 459183us : activate_task+0x16/0x50 (balance_tasks+0xeb/0x1c0)
> migratio-3     0D... 459184us : enqueue_task+0x19/0x60 (activate_task+0x38/0x50)
> migratio-3     0D... 459184us : sched_clock+0x9/0x30 (enqueue_task+0x31/0x60)
> migratio-3     0D... 459184us : enqueue_task_fair+0x9/0x50 (enqueue_task+0x48/0x60)
> migratio-3     0D... 459184us : enqueue_entity+0x12/0x280 (enqueue_task_fair+0x49/0x50)
> migratio-3     0D... 459185us : update_curr+0x21/0x140 (enqueue_entity+0x1f/0x280)
> migratio-3     0D... 459185us : update_stats_enqueue+0x9/0x90 (enqueue_entity+0x4b/0x280)
> migratio-3     0D... 459185us : rb_insert_color+0x12/0x110 (enqueue_entity+0xab/0x280)
> migratio-3     0D... 459186us : update_load_add+0x9/0x20 (enqueue_entity+0xb8/0x280)
> migratio-3     0D... 459186us : inc_nr_running+0x16/0x50 (activate_task+0x43/0x50)
> migratio-3     0D... 459186us : update_curr_load+0x16/0xb0 (inc_nr_running+0x29/0x50)
> migratio-3     0D... 459187us : update_load_add+0x9/0x20 (inc_nr_running+0x37/0x50)
> migratio-3     0D... 459187us : check_preempt_curr_idle+0x9/0x20 (balance_tasks+0x103/0x1c0)
> migratio-3     0D... 459187us : resched_task+0x9/0x70 (check_preempt_curr_idle+0x15/0x20)
> migratio-3     0D... 459188us : __trace_start_sched_wakeup+0x19/0x1b0 (balance_tasks+0x1ad/0x1c0)
> migratio-3     0D... 459188us : __trace_start_sched_wakeup+0x4d/0x1b0 <klogd-4366> (120 -1)
> migratio-3     0D... 459188us : _spin_unlock+0xe/0x40 (migration_thread+0x125/0x290)
> migratio-3     0D... 459189us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
> migratio-3     0D... 459189us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
> migratio-3     0D... 459189us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
> migratio-3     0D... 459189us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
> migratio-3     0D... 459190us : _raw_spin_unlock+0xe/0xa0 (_spin_unlock+0x2b/0x40)
> migratio-3     0D... 459190us : _spin_unlock_irq+0xe/0x40 (migration_thread+0x145/0x290)
> migratio-3     0D... 459190us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
> migratio-3     0D... 459191us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
> migratio-3     0D... 459191us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
> migratio-3     0D... 459191us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
> migratio-3     0D... 459191us : _raw_spin_unlock+0xe/0xa0 (_spin_unlock_irq+0x2b/0x40)
> migratio-3     0D... 459192us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0x93/0x170)
> migratio-3     0D... 459192us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0xab/0x170)
> migratio-3     0.... 459192us : __sched_text_start+0x19/0x34a (migration_thread+0x14a/0x290)
> migratio-3     0.... 459193us : _spin_lock_irq+0xc/0x60 (__sched_text_start+0x10f/0x34a)
> migratio-3     0D... 459193us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
> migratio-3     0D... 459193us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
> migratio-3     0D... 459194us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
> migratio-3     0D... 459194us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
> migratio-3     0D... 459194us : _raw_spin_trylock+0x9/0x40 (_spin_lock_irq+0x3a/0x60)
> migratio-3     0D... 459194us : lock_acquired+0x16/0x220 (_spin_lock_irq+0x5a/0x60)
> migratio-3     0D... 459195us : get_lock_stats+0x9/0x40 (lock_acquired+0xff/0x220)
> migratio-3     0D... 459195us : __update_rq_clock+0x20/0x130 (__sched_text_start+0x125/0x34a)
> migratio-3     0D... 459195us : sched_clock+0x9/0x30 (__update_rq_clock+0x2f/0x130)
> migratio-3     0D... 459196us : deactivate_task+0x16/0x60 (thread_return+0x173/0x686)
> migratio-3     0D... 459196us : dequeue_task+0xe/0x30 (deactivate_task+0x38/0x60)
> migratio-3     0D... 459196us : dequeue_task_rt+0x16/0xb0 (dequeue_task+0x18/0x30)
> migratio-3     0D... 459196us : list_del+0x9/0x70 (dequeue_task_rt+0x41/0xb0)
> migratio-3     0D... 459197us : update_curr_load+0x16/0xb0 (deactivate_task+0x45/0x60)
> migratio-3     0D... 459197us : calc_delta_mine+0x9/0x90 (update_curr_load+0x92/0xb0)
> migratio-3     0D... 459197us : update_load_sub+0x9/0x20 (deactivate_task+0x53/0x60)
> migratio-3     0D... 459198us : put_prev_task_rt+0x9/0x70 (__sched_text_start+0x163/0x34a)
> migratio-3     0D... 459198us : pick_next_task_fair+0x1b/0x70 (__sched_text_start+0x17d/0x34a)
> migratio-3     0D... 459198us : __pick_next_entity+0x9/0x20 (pick_next_task_fair+0x39/0x70)
> migratio-3     0D... 459199us : update_stats_wait_end+0xa/0xb0 (pick_next_task_fair+0x47/0x70)
> migratio-3     0D... 459199us : add_wait_runtime+0x9/0x60 (update_stats_wait_end+0x9c/0xb0)
> migratio-3     0D... 459199us : sched_clock+0x9/0x30 (__sched_text_start+0x1b9/0x34a)
> migratio-3     0D... 459200us : sched_clock+0x9/0x30 (__sched_text_start+0x20b/0x34a)
> migratio-3     0D... 459200us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
> migratio-3     0D... 459200us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
> migratio-3     0D... 459200us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
> migratio-3     0D... 459201us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
> migratio-3     0D... 459201us : __switch_to+0x16/0x2e0 (thread_return+0x0/0x686)
> events/0-9     0D... 459202us : thread_return+0x72/0x686 <migratio-3> (199 -5)
> events/0-9     0D... 459202us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
> events/0-9     0D... 459203us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
> events/0-9     0D... 459203us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
> events/0-9     0D... 459203us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
> events/0-9     0D... 459204us : _spin_unlock_irq+0xe/0x40 (thread_return+0xd0/0x686)
> events/0-9     0D... 459204us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
> events/0-9     0D... 459204us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
> events/0-9     0D... 459204us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
> events/0-9     0D... 459205us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
> events/0-9     0D... 459205us : _raw_spin_unlock+0xe/0xa0 (_spin_unlock_irq+0x2b/0x40)
> events/0-9     0D... 459205us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0x93/0x170)
> events/0-9     0D... 459206us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0xab/0x170)
> events/0-9     0.... 459206us : trace_stop_sched_switched+0x21/0x310 (thread_return+0xde/0x686)
> events/0-9     0.... 459206us : _spin_lock_irqsave+0x19/0x80 (__down+0xaf/0x107)
> events/0-9     0D... 459207us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
> events/0-9     0D... 459207us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
> events/0-9     0D... 459207us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
> events/0-9     0D... 459208us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
> events/0-9     0D... 459208us : _raw_spin_trylock+0x9/0x40 (_spin_lock_irqsave+0x4a/0x80)
> events/0-9     0D... 459208us : lock_acquired+0x16/0x220 (_spin_lock_irqsave+0x6a/0x80)
> events/0-9     0D... 459209us : get_lock_stats+0x9/0x40 (lock_acquired+0xff/0x220)
> events/0-9     0D... 459209us : list_del+0x9/0x70 (__down+0xd9/0x107)
> events/0-9     0D... 459209us : __wake_up_locked+0x9/0x20 (__down+0xe6/0x107)
> events/0-9     0D... 459209us : __wake_up_common+0x16/0x80 (__wake_up_locked+0x18/0x20)
> events/0-9     0D... 459210us : _spin_unlock_irqrestore+0x16/0x60 (__down+0xf1/0x107)
> events/0-9     0D... 459210us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
> events/0-9     0D... 459210us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
> events/0-9     0D... 459211us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
> events/0-9     0D... 459211us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
> events/0-9     0D... 459211us : _raw_spin_unlock+0xe/0xa0 (_spin_unlock_irqrestore+0x36/0x60)
> events/0-9     0D... 459212us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0x93/0x170)
> events/0-9     0D... 459212us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0xab/0x170)
> events/0-9     0.... 459213us : poke_blanked_console+0x9/0xf0 (console_callback+0xbf/0x110)
> events/0-9     0.... 459213us : is_console_locked+0x9/0x20 (poke_blanked_console+0xe/0xf0)
> events/0-9     0.... 459213us : __might_sleep+0x16/0x110 (poke_blanked_console+0x33/0xf0)
> events/0-9     0.... 459214us : del_timer+0x15/0x80 (poke_blanked_console+0x3f/0xf0)
> events/0-9     0.... 459214us : release_console_sem+0x16/0x250 (console_callback+0x72/0x110)
> events/0-9     0.... 459214us : _spin_lock_irqsave+0x19/0x80 (release_console_sem+0x5f/0x250)
> events/0-9     0D... 459214us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
> events/0-9     0D... 459215us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
> events/0-9     0D... 459215us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
> events/0-9     0D... 459215us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
> events/0-9     0D... 459216us : _raw_spin_trylock+0x9/0x40 (_spin_lock_irqsave+0x4a/0x80)
> events/0-9     0D... 459216us : lock_contended+0x16/0x1f0 (_spin_lock_irqsave+0x5a/0x80)
> events/0-9     0D... 459216us : sched_clock+0x9/0x30 (lock_contended+0xd5/0x1f0)
> events/0-9     0D... 459217us : get_lock_stats+0x9/0x40 (lock_contended+0x19d/0x1f0)
> events/0-9     0D... 459217us : _raw_spin_lock+0x20/0x150 (_spin_lock_irqsave+0x62/0x80)
> events/0-9     0D... 459217us : __delay+0x9/0x20 (_raw_spin_lock+0xd8/0x150)
> events/0-9     0D... 459218us : lock_acquired+0x16/0x220 (_spin_lock_irqsave+0x6a/0x80)
> events/0-9     0D... 459218us : sched_clock+0x9/0x30 (lock_acquired+0x16d/0x220)
> events/0-9     0D... 459218us : get_lock_stats+0x9/0x40 (lock_acquired+0x18c/0x220)
> events/0-9     0D... 459219us : lock_time_inc+0x9/0x30 (lock_acquired+0x1c9/0x220)
> events/0-9     0D... 459219us : _spin_unlock_irqrestore+0x16/0x60 (release_console_sem+0x221/0x250)
> events/0-9     0D... 459219us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
> events/0-9     0D... 459220us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
> events/0-9     0D... 459220us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
> events/0-9     0D... 459221us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
> events/0-9     0D... 459221us : _raw_spin_unlock+0xe/0xa0 (_spin_unlock_irqrestore+0x36/0x60)
> events/0-9     0D... 459221us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0x93/0x170)
> events/0-9     0D... 459221us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0xab/0x170)
> events/0-9     0.... 459222us : wake_up_klogd+0x9/0x40 (release_console_sem+0x22f/0x250)
> events/0-9     0.... 459222us : _spin_lock_irq+0xc/0x60 (run_workqueue+0xb9/0x190)
> events/0-9     0D... 459222us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
> events/0-9     0D... 459223us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
> events/0-9     0D... 459223us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
> events/0-9     0D... 459223us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
> events/0-9     0D... 459224us : _raw_spin_trylock+0x9/0x40 (_spin_lock_irq+0x3a/0x60)
> events/0-9     0D... 459224us : lock_acquired+0x16/0x220 (_spin_lock_irq+0x5a/0x60)
> events/0-9     0D... 459224us : get_lock_stats+0x9/0x40 (lock_acquired+0xff/0x220)
> events/0-9     0D... 459225us : _spin_unlock_irq+0xe/0x40 (run_workqueue+0x105/0x190)
> events/0-9     0D... 459225us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
> events/0-9     0D... 459225us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
> events/0-9     0D... 459226us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
> events/0-9     0D... 459226us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
> events/0-9     0D... 459226us : _raw_spin_unlock+0xe/0xa0 (_spin_unlock_irq+0x2b/0x40)
> events/0-9     0D... 459227us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0x93/0x170)
> events/0-9     0D... 459227us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0xab/0x170)
> events/0-9     0.... 459227us : defense_work_handler+0x9/0x30 (run_workqueue+0x11e/0x190)
> events/0-9     0.... 459228us : update_defense_level+0x10/0x2a0 (defense_work_handler+0xe/0x30)
> events/0-9     0.... 459228us : si_meminfo+0xe/0x60 (update_defense_level+0x1c/0x2a0)
> events/0-9     0.... 459228us : nr_blockdev_pages+0xe/0x90 (si_meminfo+0x3d/0x60)
> events/0-9     0.... 459229us : _spin_lock+0x16/0x70 (nr_blockdev_pages+0x1a/0x90)
> events/0-9     0D... 459229us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
> events/0-9     0D... 459229us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
> events/0-9     0D... 459229us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
> events/0-9     0D... 459230us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
> events/0-9     0.... 459230us : _raw_spin_trylock+0x9/0x40 (_spin_lock+0x3d/0x70)
> events/0-9     0.... 459230us : lock_acquired+0x16/0x220 (_spin_lock+0x5d/0x70)
> events/0-9     0D... 459231us : get_lock_stats+0x9/0x40 (lock_acquired+0xff/0x220)
> events/0-9     0.... 459232us : _spin_unlock+0xe/0x40 (nr_blockdev_pages+0x81/0x90)
> events/0-9     0D... 459233us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
> events/0-9     0D... 459233us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
> events/0-9     0D... 459233us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
> events/0-9     0D... 459233us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
> events/0-9     0.... 459234us : _raw_spin_unlock+0xe/0xa0 (_spin_unlock+0x2b/0x40)
> events/0-9     0.... 459234us : local_bh_disable+0x9/0x20 (update_defense_level+0x34/0x2a0)
> events/0-9     0.... 459235us : __local_bh_disable+0x16/0xb0 (local_bh_disable+0x12/0x20)
> events/0-9     0D... 459235us : in_lock_functions+0x9/0x30 (add_preempt_count+0x18/0x50)
> events/0-9     0D.s. 459235us : trace_softirqs_off+0x9/0xe0 (__local_bh_disable+0x6f/0xb0)
> events/0-9     0..s. 459235us : _spin_lock+0x16/0x70 (update_defense_level+0x40/0x2a0)
> events/0-9     0D.s. 459236us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
> events/0-9     0D.s. 459236us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
> events/0-9     0D.s. 459236us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
> events/0-9     0D.s. 459237us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
> events/0-9     0..s. 459237us : _raw_spin_trylock+0x9/0x40 (_spin_lock+0x3d/0x70)
> events/0-9     0..s. 459237us : lock_acquired+0x16/0x220 (_spin_lock+0x5d/0x70)
> events/0-9     0D.s. 459238us : get_lock_stats+0x9/0x40 (lock_acquired+0xff/0x220)
> events/0-9     0..s. 459238us : _spin_unlock+0xe/0x40 (update_defense_level+0x73/0x2a0)
> events/0-9     0D.s. 459238us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
> events/0-9     0D.s. 459239us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
> events/0-9     0D.s. 459239us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
> events/0-9     0D.s. 459239us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
> events/0-9     0..s. 459239us : _raw_spin_unlock+0xe/0xa0 (_spin_unlock+0x2b/0x40)
> events/0-9     0..s. 459240us : _spin_lock+0x16/0x70 (update_defense_level+0x7f/0x2a0)
> events/0-9     0D.s. 459240us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
> events/0-9     0D.s. 459240us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
> events/0-9     0D.s. 459241us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
> events/0-9     0D.s. 459241us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
> events/0-9     0..s. 459241us : _raw_spin_trylock+0x9/0x40 (_spin_lock+0x3d/0x70)
> events/0-9     0..s. 459242us : lock_acquired+0x16/0x220 (_spin_lock+0x5d/0x70)
> events/0-9     0D.s. 459242us : get_lock_stats+0x9/0x40 (lock_acquired+0xff/0x220)
> events/0-9     0..s. 459242us : _spin_unlock+0xe/0x40 (update_defense_level+0xbc/0x2a0)
> events/0-9     0D.s. 459243us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
> events/0-9     0D.s. 459243us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
> events/0-9     0D.s. 459243us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
> events/0-9     0D.s. 459244us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
> events/0-9     0..s. 459244us : _raw_spin_unlock+0xe/0xa0 (_spin_unlock+0x2b/0x40)
> events/0-9     0..s. 459244us : _write_lock+0x16/0x70 (update_defense_level+0xc8/0x2a0)
> events/0-9     0D.s. 459245us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
> events/0-9     0D.s. 459245us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
> events/0-9     0D.s. 459245us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
> events/0-9     0D.s. 459246us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
> events/0-9     0..s. 459246us : _raw_write_trylock+0x9/0x50 (_write_lock+0x3d/0x70)
> events/0-9     0..s. 459246us : lock_acquired+0x16/0x220 (_write_lock+0x5d/0x70)
> events/0-9     0D.s. 459247us : get_lock_stats+0x9/0x40 (lock_acquired+0xff/0x220)
> events/0-9     0..s. 459247us : _write_unlock+0xe/0x40 (update_defense_level+0xf5/0x2a0)
> events/0-9     0D.s. 459247us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
> events/0-9     0D.s. 459248us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
> events/0-9     0D.s. 459248us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
> events/0-9     0D.s. 459248us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
> events/0-9     0..s. 459249us : _raw_write_unlock+0xe/0x90 (_write_unlock+0x2b/0x40)
> events/0-9     0..s. 459249us : local_bh_enable+0xe/0x160 (update_defense_level+0xfa/0x2a0)
> events/0-9     0D.s. 459249us : trace_softirqs_on+0x9/0xb0 (local_bh_enable+0xba/0x160)
> events/0-9     0D... 459249us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0x93/0x170)
> events/0-9     0D... 459250us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0xab/0x170)
> events/0-9     0.... 459250us : schedule_delayed_work+0x16/0x50 (defense_work_handler+0x2e/0x30)
> events/0-9     0.... 459250us : __timer_stats_timer_set_start_info+0x9/0x50 (schedule_delayed_work+0x29/0x50)
> events/0-9     0.... 459251us : queue_delayed_work+0x19/0x70 (schedule_delayed_work+0x3b/0x50)
> events/0-9     0.... 459251us : __timer_stats_timer_set_start_info+0x9/0x50 (queue_delayed_work+0x2f/0x70)
> events/0-9     0.... 459251us : queue_delayed_work_on+0x10/0xe0 (queue_delayed_work+0x63/0x70)
> events/0-9     0.... 459252us : wq_per_cpu+0x9/0x30 (queue_delayed_work_on+0x56/0xe0)
> events/0-9     0.... 459252us : __mod_timer+0x16/0xe0 (queue_delayed_work_on+0xa2/0xe0)
> events/0-9     0.... 459252us : __timer_stats_timer_set_start_info+0x9/0x50 (__mod_timer+0x25/0xe0)
> events/0-9     0.... 459252us : lock_timer_base+0x20/0x70 (__mod_timer+0x3f/0xe0)
> events/0-9     0.... 459253us : _spin_lock_irqsave+0x19/0x80 (lock_timer_base+0x3b/0x70)
> events/0-9     0D... 459253us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
> events/0-9     0D... 459253us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
> events/0-9     0D... 459254us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
> events/0-9     0D... 459254us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
> events/0-9     0D... 459254us : _raw_spin_trylock+0x9/0x40 (_spin_lock_irqsave+0x4a/0x80)
> events/0-9     0D... 459255us : lock_acquired+0x16/0x220 (_spin_lock_irqsave+0x6a/0x80)
> events/0-9     0D... 459255us : get_lock_stats+0x9/0x40 (lock_acquired+0xff/0x220)
> events/0-9     0D... 459255us : internal_add_timer+0x9/0xe0 (__mod_timer+0xbc/0xe0)
> events/0-9     0D... 459256us : __list_add+0x9/0x60 (internal_add_timer+0x3b/0xe0)
> events/0-9     0D... 459256us : _spin_unlock_irqrestore+0x16/0x60 (__mod_timer+0xc8/0xe0)
> events/0-9     0D... 459256us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
> events/0-9     0D... 459256us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
> events/0-9     0D... 459257us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
> events/0-9     0D... 459257us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
> events/0-9     0D... 459257us : _raw_spin_unlock+0xe/0xa0 (_spin_unlock_irqrestore+0x36/0x60)
> events/0-9     0D... 459258us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0x93/0x170)
> events/0-9     0D... 459258us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0xab/0x170)
> events/0-9     0.... 459258us : _spin_lock_irq+0xc/0x60 (run_workqueue+0xb9/0x190)
> events/0-9     0D... 459258us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
> events/0-9     0D... 459259us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
> events/0-9     0D... 459259us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
> events/0-9     0D... 459259us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
> events/0-9     0D... 459260us : _raw_spin_trylock+0x9/0x40 (_spin_lock_irq+0x3a/0x60)
> events/0-9     0D... 459260us : lock_acquired+0x16/0x220 (_spin_lock_irq+0x5a/0x60)
> events/0-9     0D... 459260us : get_lock_stats+0x9/0x40 (lock_acquired+0xff/0x220)
> events/0-9     0D... 459261us : _spin_unlock_irq+0xe/0x40 (run_workqueue+0x177/0x190)
> events/0-9     0D... 459261us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
> events/0-9     0D... 459261us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
> events/0-9     0D... 459262us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
> events/0-9     0D... 459262us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
> events/0-9     0D... 459262us : _raw_spin_unlock+0xe/0xa0 (_spin_unlock_irq+0x2b/0x40)
> events/0-9     0D... 459262us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0x93/0x170)
> events/0-9     0D... 459263us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0xab/0x170)
> events/0-9     0.... 459263us : prepare_to_wait+0x20/0x90 (worker_thread+0xc3/0x120)
> events/0-9     0.... 459263us : _spin_lock_irqsave+0x19/0x80 (prepare_to_wait+0x31/0x90)
> events/0-9     0D... 459264us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
> events/0-9     0D... 459264us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
> events/0-9     0D... 459264us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
> events/0-9     0D... 459264us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
> events/0-9     0D... 459265us : _raw_spin_trylock+0x9/0x40 (_spin_lock_irqsave+0x4a/0x80)
> events/0-9     0D... 459265us : lock_acquired+0x16/0x220 (_spin_lock_irqsave+0x6a/0x80)
> events/0-9     0D... 459265us : get_lock_stats+0x9/0x40 (lock_acquired+0xff/0x220)
> events/0-9     0D... 459266us : list_add+0x9/0x20 (prepare_to_wait+0x81/0x90)
> events/0-9     0D... 459266us : __list_add+0x9/0x60 (list_add+0x11/0x20)
> events/0-9     0D... 459266us : _spin_unlock_irqrestore+0x16/0x60 (prepare_to_wait+0x62/0x90)
> events/0-9     0D... 459267us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
> events/0-9     0D... 459267us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
> events/0-9     0D... 459267us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
> events/0-9     0D... 459267us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
> events/0-9     0D... 459268us : _raw_spin_unlock+0xe/0xa0 (_spin_unlock_irqrestore+0x36/0x60)
> events/0-9     0D... 459268us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0x93/0x170)
> events/0-9     0D... 459268us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0xab/0x170)
> events/0-9     0.... 459269us : kthread_should_stop+0x9/0x30 (worker_thread+0xdf/0x120)
> events/0-9     0.... 459269us : __sched_text_start+0x19/0x34a (worker_thread+0xf5/0x120)
> events/0-9     0.... 459269us : _spin_lock_irq+0xc/0x60 (__sched_text_start+0x10f/0x34a)
> events/0-9     0D... 459269us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
> events/0-9     0D... 459270us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
> events/0-9     0D... 459270us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
> events/0-9     0D... 459270us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
> events/0-9     0D... 459271us : _raw_spin_trylock+0x9/0x40 (_spin_lock_irq+0x3a/0x60)
> events/0-9     0D... 459271us : lock_acquired+0x16/0x220 (_spin_lock_irq+0x5a/0x60)
> events/0-9     0D... 459271us : get_lock_stats+0x9/0x40 (lock_acquired+0xff/0x220)
> events/0-9     0D... 459272us : __update_rq_clock+0x20/0x130 (__sched_text_start+0x125/0x34a)
> events/0-9     0D... 459272us : sched_clock+0x9/0x30 (__update_rq_clock+0x2f/0x130)
> events/0-9     0D... 459272us : deactivate_task+0x16/0x60 (thread_return+0x173/0x686)
> events/0-9     0D... 459272us : dequeue_task+0xe/0x30 (deactivate_task+0x38/0x60)
> events/0-9     0D... 459273us : dequeue_task_fair+0x9/0x40 (dequeue_task+0x18/0x30)
> events/0-9     0D... 459273us : dequeue_entity+0x20/0x100 (dequeue_task_fair+0x3b/0x40)
> events/0-9     0D... 459273us : update_curr+0x21/0x140 (dequeue_entity+0x35/0x100)
> events/0-9     0D... 459274us : calc_delta_mine+0x9/0x90 (update_curr+0xc6/0x140)
> events/0-9     0D... 459274us : calc_delta_mine+0x9/0x90 (update_curr+0xda/0x140)
> events/0-9     0D... 459274us : add_wait_runtime+0x9/0x60 (update_curr+0x125/0x140)
> events/0-9     0D... 459275us : rb_next+0x9/0x60 (dequeue_entity+0xf8/0x100)
> events/0-9     0D... 459275us : rb_erase+0xc/0x320 (dequeue_entity+0xa1/0x100)
> events/0-9     0D... 459275us : update_load_sub+0x9/0x20 (dequeue_entity+0xad/0x100)
> events/0-9     0D... 459275us : update_curr_load+0x16/0xb0 (deactivate_task+0x45/0x60)
> events/0-9     0D... 459276us : calc_delta_mine+0x9/0x90 (update_curr_load+0x92/0xb0)
> events/0-9     0D... 459276us : update_load_sub+0x9/0x20 (deactivate_task+0x53/0x60)
> events/0-9     0D... 459276us : put_prev_task_fair+0x16/0xa0 (__sched_text_start+0x163/0x34a)
> events/0-9     0D... 459277us : pick_next_task_fair+0x1b/0x70 (__sched_text_start+0x17d/0x34a)
> events/0-9     0D... 459277us : __pick_next_entity+0x9/0x20 (pick_next_task_fair+0x39/0x70)
> events/0-9     0D... 459277us : update_stats_wait_end+0xa/0xb0 (pick_next_task_fair+0x47/0x70)
> events/0-9     0D... 459277us : add_wait_runtime+0x9/0x60 (update_stats_wait_end+0x9c/0xb0)
> events/0-9     0D... 459278us : sched_clock+0x9/0x30 (__sched_text_start+0x1b9/0x34a)
> events/0-9     0D... 459278us : sched_clock+0x9/0x30 (__sched_text_start+0x20b/0x34a)
> events/0-9     0D... 459279us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
> events/0-9     0D... 459279us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
> events/0-9     0D... 459279us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
> events/0-9     0D... 459279us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
> events/0-9     0D... 459280us : __switch_to+0x16/0x2e0 (thread_return+0x0/0x686)
> kpktgend-1280  0D... 459280us : thread_return+0x72/0x686 <events/0-9> (-5 -5)
> kpktgend-1280  0D... 459281us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
> kpktgend-1280  0D... 459281us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
> kpktgend-1280  0D... 459281us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
> kpktgend-1280  0D... 459282us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
> kpktgend-1280  0D... 459282us : _spin_unlock_irq+0xe/0x40 (thread_return+0xd0/0x686)
> kpktgend-1280  0D... 459282us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
> kpktgend-1280  0D... 459283us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
> kpktgend-1280  0D... 459283us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
> kpktgend-1280  0D... 459283us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
> kpktgend-1280  0D... 459284us : _raw_spin_unlock+0xe/0xa0 (_spin_unlock_irq+0x2b/0x40)
> kpktgend-1280  0D... 459284us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0x93/0x170)
> kpktgend-1280  0D... 459284us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0xab/0x170)
> kpktgend-1280  0.... 459284us : trace_stop_sched_switched+0x21/0x310 (thread_return+0xde/0x686)
> kpktgend-1280  0.... 459285us : del_timer_sync+0xe/0x30 (schedule_timeout+0x70/0xd0)
> kpktgend-1280  0.... 459285us : try_to_del_timer_sync+0x10/0x70 (del_timer_sync+0x1d/0x30)
> kpktgend-1280  0.... 459285us : lock_timer_base+0x20/0x70 (try_to_del_timer_sync+0x22/0x70)
> kpktgend-1280  0.... 459286us : _spin_lock_irqsave+0x19/0x80 (lock_timer_base+0x3b/0x70)
> kpktgend-1280  0D... 459286us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
> kpktgend-1280  0D... 459286us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
> kpktgend-1280  0D... 459287us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
> kpktgend-1280  0D... 459287us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
> kpktgend-1280  0D... 459287us : _raw_spin_trylock+0x9/0x40 (_spin_lock_irqsave+0x4a/0x80)
> kpktgend-1280  0D... 459287us : lock_acquired+0x16/0x220 (_spin_lock_irqsave+0x6a/0x80)
> kpktgend-1280  0D... 459288us : get_lock_stats+0x9/0x40 (lock_acquired+0xff/0x220)
> kpktgend-1280  0D... 459288us : _spin_unlock_irqrestore+0x16/0x60 (try_to_del_timer_sync+0x5c/0x70)
> kpktgend-1280  0D... 459288us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
> kpktgend-1280  0D... 459289us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
> kpktgend-1280  0D... 459289us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
> kpktgend-1280  0D... 459289us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
> kpktgend-1280  0D... 459290us : _raw_spin_unlock+0xe/0xa0 (_spin_unlock_irqrestore+0x36/0x60)
> kpktgend-1280  0D... 459290us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0x93/0x170)
> kpktgend-1280  0D... 459290us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0xab/0x170)
> kpktgend-1280  0.... 459291us : finish_wait+0x19/0x80 (pktgen_thread_worker+0x1237/0x1500)
> kpktgend-1280  0.... 459291us : _spin_lock_irqsave+0x19/0x80 (finish_wait+0x41/0x80)
> kpktgend-1280  0D... 459291us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
> kpktgend-1280  0D... 459291us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
> kpktgend-1280  0D... 459292us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
> kpktgend-1280  0D... 459292us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
> kpktgend-1280  0D... 459292us : _raw_spin_trylock+0x9/0x40 (_spin_lock_irqsave+0x4a/0x80)
> kpktgend-1280  0D... 459293us : lock_acquired+0x16/0x220 (_spin_lock_irqsave+0x6a/0x80)
> kpktgend-1280  0D... 459293us : get_lock_stats+0x9/0x40 (lock_acquired+0xff/0x220)
> kpktgend-1280  0D... 459293us : _spin_unlock_irqrestore+0x16/0x60 (finish_wait+0x63/0x80)
> kpktgend-1280  0D... 459294us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
> kpktgend-1280  0D... 459294us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
> kpktgend-1280  0D... 459294us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
> kpktgend-1280  0D... 459294us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
> kpktgend-1280  0D... 459295us : _raw_spin_unlock+0xe/0xa0 (_spin_unlock_irqrestore+0x36/0x60)
> kpktgend-1280  0D... 459295us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0x93/0x170)
> kpktgend-1280  0D... 459295us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0xab/0x170)
> kpktgend-1280  0.... 459296us : kthread_should_stop+0x9/0x30 (pktgen_thread_worker+0x467/0x1500)
> kpktgend-1280  0.... 459296us : _spin_lock+0x16/0x70 (pktgen_thread_worker+0xcb/0x1500)
> kpktgend-1280  0D... 459296us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
> kpktgend-1280  0D... 459297us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
> kpktgend-1280  0D... 459297us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
> kpktgend-1280  0D... 459297us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
> kpktgend-1280  0.... 459298us : _raw_spin_trylock+0x9/0x40 (_spin_lock+0x3d/0x70)
> kpktgend-1280  0.... 459298us : lock_acquired+0x16/0x220 (_spin_lock+0x5d/0x70)
> kpktgend-1280  0D... 459298us : get_lock_stats+0x9/0x40 (lock_acquired+0xff/0x220)
> kpktgend-1280  0.... 459298us : _spin_unlock+0xe/0x40 (pktgen_thread_worker+0x1039/0x1500)
> kpktgend-1280  0D... 459299us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
> kpktgend-1280  0D... 459299us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
> kpktgend-1280  0D... 459299us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
> kpktgend-1280  0D... 459300us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
> kpktgend-1280  0.... 459300us : _raw_spin_unlock+0xe/0xa0 (_spin_unlock+0x2b/0x40)
> kpktgend-1280  0.... 459300us : prepare_to_wait+0x20/0x90 (pktgen_thread_worker+0x121d/0x1500)
> kpktgend-1280  0.... 459301us : _spin_lock_irqsave+0x19/0x80 (prepare_to_wait+0x31/0x90)
> kpktgend-1280  0D... 459301us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
> kpktgend-1280  0D... 459301us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
> kpktgend-1280  0D... 459301us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
> kpktgend-1280  0D... 459302us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
> kpktgend-1280  0D... 459302us : _raw_spin_trylock+0x9/0x40 (_spin_lock_irqsave+0x4a/0x80)
> kpktgend-1280  0D... 459302us : lock_acquired+0x16/0x220 (_spin_lock_irqsave+0x6a/0x80)
> kpktgend-1280  0D... 459303us : get_lock_stats+0x9/0x40 (lock_acquired+0xff/0x220)
> kpktgend-1280  0D... 459303us : list_add+0x9/0x20 (prepare_to_wait+0x81/0x90)
> kpktgend-1280  0D... 459303us : __list_add+0x9/0x60 (list_add+0x11/0x20)
> kpktgend-1280  0D... 459303us : _spin_unlock_irqrestore+0x16/0x60 (prepare_to_wait+0x62/0x90)
> kpktgend-1280  0D... 459304us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
> kpktgend-1280  0D... 459304us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
> kpktgend-1280  0D... 459304us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
> kpktgend-1280  0D... 459305us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
> kpktgend-1280  0D... 459305us : _raw_spin_unlock+0xe/0xa0 (_spin_unlock_irqrestore+0x36/0x60)
> kpktgend-1280  0D... 459305us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0x93/0x170)
> kpktgend-1280  0D... 459305us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0xab/0x170)
> kpktgend-1280  0.... 459306us : schedule_timeout+0x15/0xd0 (pktgen_thread_worker+0x1227/0x1500)
> kpktgend-1280  0.... 459306us : init_timer+0x9/0x50 (schedule_timeout+0x58/0xd0)
> kpktgend-1280  0.... 459306us : __mod_timer+0x16/0xe0 (schedule_timeout+0x63/0xd0)
> kpktgend-1280  0.... 459307us : __timer_stats_timer_set_start_info+0x9/0x50 (__mod_timer+0x25/0xe0)
> kpktgend-1280  0.... 459307us : lock_timer_base+0x20/0x70 (__mod_timer+0x3f/0xe0)
> kpktgend-1280  0.... 459307us : _spin_lock_irqsave+0x19/0x80 (lock_timer_base+0x3b/0x70)
> kpktgend-1280  0D... 459308us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
> kpktgend-1280  0D... 459308us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
> kpktgend-1280  0D... 459308us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
> kpktgend-1280  0D... 459308us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
> kpktgend-1280  0D... 459309us : _raw_spin_trylock+0x9/0x40 (_spin_lock_irqsave+0x4a/0x80)
> kpktgend-1280  0D... 459309us : lock_acquired+0x16/0x220 (_spin_lock_irqsave+0x6a/0x80)
> kpktgend-1280  0D... 459309us : get_lock_stats+0x9/0x40 (lock_acquired+0xff/0x220)
> kpktgend-1280  0D... 459310us : internal_add_timer+0x9/0xe0 (__mod_timer+0xbc/0xe0)
> kpktgend-1280  0D... 459310us : __list_add+0x9/0x60 (internal_add_timer+0x3b/0xe0)
> kpktgend-1280  0D... 459310us : _spin_unlock_irqrestore+0x16/0x60 (__mod_timer+0xc8/0xe0)
> kpktgend-1280  0D... 459311us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
> kpktgend-1280  0D... 459311us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
> kpktgend-1280  0D... 459311us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
> kpktgend-1280  0D... 459311us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
> kpktgend-1280  0D... 459312us : _raw_spin_unlock+0xe/0xa0 (_spin_unlock_irqrestore+0x36/0x60)
> kpktgend-1280  0D... 459312us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0x93/0x170)
> kpktgend-1280  0D... 459312us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0xab/0x170)
> kpktgend-1280  0.... 459313us : __sched_text_start+0x19/0x34a (schedule_timeout+0x68/0xd0)
> kpktgend-1280  0.... 459313us : _spin_lock_irq+0xc/0x60 (__sched_text_start+0x10f/0x34a)
> kpktgend-1280  0D... 459313us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
> kpktgend-1280  0D... 459314us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
> kpktgend-1280  0D... 459314us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
> kpktgend-1280  0D... 459314us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
> kpktgend-1280  0D... 459315us : _raw_spin_trylock+0x9/0x40 (_spin_lock_irq+0x3a/0x60)
> kpktgend-1280  0D... 459315us : lock_acquired+0x16/0x220 (_spin_lock_irq+0x5a/0x60)
> kpktgend-1280  0D... 459315us : get_lock_stats+0x9/0x40 (lock_acquired+0xff/0x220)
> kpktgend-1280  0D... 459315us : __update_rq_clock+0x20/0x130 (__sched_text_start+0x125/0x34a)
> kpktgend-1280  0D... 459316us : sched_clock+0x9/0x30 (__update_rq_clock+0x2f/0x130)
> kpktgend-1280  0D... 459316us : deactivate_task+0x16/0x60 (thread_return+0x173/0x686)
> kpktgend-1280  0D... 459316us : dequeue_task+0xe/0x30 (deactivate_task+0x38/0x60)
> kpktgend-1280  0D... 459317us : dequeue_task_fair+0x9/0x40 (dequeue_task+0x18/0x30)
> kpktgend-1280  0D... 459317us : dequeue_entity+0x20/0x100 (dequeue_task_fair+0x3b/0x40)
> kpktgend-1280  0D... 459317us : update_curr+0x21/0x140 (dequeue_entity+0x35/0x100)
> kpktgend-1280  0D... 459317us : calc_delta_mine+0x9/0x90 (update_curr+0xc6/0x140)
> kpktgend-1280  0D... 459318us : calc_delta_mine+0x9/0x90 (update_curr+0xda/0x140)
> kpktgend-1280  0D... 459318us : add_wait_runtime+0x9/0x60 (update_curr+0x125/0x140)
> kpktgend-1280  0D... 459318us : rb_next+0x9/0x60 (dequeue_entity+0xf8/0x100)
> kpktgend-1280  0D... 459319us : rb_erase+0xc/0x320 (dequeue_entity+0xa1/0x100)
> kpktgend-1280  0D... 459319us : update_load_sub+0x9/0x20 (dequeue_entity+0xad/0x100)
> kpktgend-1280  0D... 459319us : update_curr_load+0x16/0xb0 (deactivate_task+0x45/0x60)
> kpktgend-1280  0D... 459320us : calc_delta_mine+0x9/0x90 (update_curr_load+0x92/0xb0)
> kpktgend-1280  0D... 459320us : update_load_sub+0x9/0x20 (deactivate_task+0x53/0x60)
> kpktgend-1280  0D... 459320us : find_busiest_group+0x19/0x870 (thread_return+0x2eb/0x686)
> kpktgend-1280  0D... 459321us : __first_cpu+0x9/0x30 (find_busiest_group+0x556/0x870)
> kpktgend-1280  0D... 459321us : __first_cpu+0x9/0x30 (find_busiest_group+0x16f/0x870)
> kpktgend-1280  0D... 459321us : idle_cpu+0x9/0x40 (find_busiest_group+0x1d0/0x870)
> kpktgend-1280  0D... 459321us : weighted_cpuload+0x9/0x30 (find_busiest_group+0x1ec/0x870)
> kpktgend-1280  0D... 459322us : weighted_cpuload+0x9/0x30 (find_busiest_group+0x225/0x870)
> kpktgend-1280  0D... 459322us : __next_cpu+0xa/0x40 (find_busiest_group+0x233/0x870)
> kpktgend-1280  0D... 459322us : __first_cpu+0x9/0x30 (find_busiest_group+0x16f/0x870)
> kpktgend-1280  0D... 459323us : weighted_cpuload+0x9/0x30 (find_busiest_group+0x28e/0x870)
> kpktgend-1280  0D... 459323us : weighted_cpuload+0x9/0x30 (find_busiest_group+0x225/0x870)
> kpktgend-1280  0D... 459323us : __next_cpu+0xa/0x40 (find_busiest_group+0x233/0x870)
> kpktgend-1280  0D... 459323us : msecs_to_jiffies+0x9/0x40 (thread_return+0x260/0x686)
> kpktgend-1280  0D... 459324us : msecs_to_jiffies+0x9/0x40 (thread_return+0x260/0x686)
> kpktgend-1280  0D... 459324us : put_prev_task_fair+0x16/0xa0 (__sched_text_start+0x163/0x34a)
> kpktgend-1280  0D... 459324us : pick_next_task_fair+0x1b/0x70 (__sched_text_start+0x17d/0x34a)
> kpktgend-1280  0D... 459325us : pick_next_task_rt+0x9/0x60 (thread_return+0x1ad/0x686)
> kpktgend-1280  0D... 459325us : pick_next_task_fair+0x1b/0x70 (thread_return+0x1ad/0x686)
> kpktgend-1280  0D... 459325us : pick_next_task_idle+0x9/0x20 (thread_return+0x1ad/0x686)
> kpktgend-1280  0D... 459326us : sched_clock+0x9/0x30 (__sched_text_start+0x1b9/0x34a)
> kpktgend-1280  0D... 459326us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
> kpktgend-1280  0D... 459326us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
> kpktgend-1280  0D... 459327us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
> kpktgend-1280  0D... 459327us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
> kpktgend-1280  0D... 459328us : __switch_to+0x16/0x2e0 (thread_return+0x0/0x686)
>   <idle>-0     0D... 459328us : thread_return+0x72/0x686 <kpktgend-1280> (-5 20)
>   <idle>-0     0D... 459329us : __lock_acquire+0x16/0x1120 (lock_acquire+0x65/0x90)
>   <idle>-0     0D... 459329us : very_verbose+0x9/0x10 (__lock_acquire+0x8b/0x1120)
>   <idle>-0     0D... 459329us : sched_clock+0x9/0x30 (__lock_acquire+0xf0/0x1120)
>   <idle>-0     0D... 459330us : very_verbose+0x9/0x10 (__lock_acquire+0x54d/0x1120)
>   <idle>-0     0D... 459330us : _spin_unlock_irq+0xe/0x40 (thread_return+0xd0/0x686)
>   <idle>-0     0D... 459330us : lock_release_holdtime+0x16/0x80 (lock_release+0x120/0x1c0)
>   <idle>-0     0D... 459331us : sched_clock+0x9/0x30 (lock_release_holdtime+0x35/0x80)
>   <idle>-0     0D... 459331us : get_lock_stats+0x9/0x40 (lock_release_holdtime+0x45/0x80)
>   <idle>-0     0D... 459331us : lock_time_inc+0x9/0x30 (lock_release_holdtime+0x6f/0x80)
>   <idle>-0     0D... 459331us : _raw_spin_unlock+0xe/0xa0 (_spin_unlock_irq+0x2b/0x40)
>   <idle>-0     0D... 459332us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0x93/0x170)
>   <idle>-0     0D... 459332us : mark_held_locks+0x10/0x90 (trace_hardirqs_on_caller+0xab/0x170)
>   <idle>-0     0.... 459332us : trace_stop_sched_switched+0x21/0x310 (thread_return+0xde/0x686)
>   <idle>-0     0D... 459333us : enter_idle+0x9/0x30 (cpu_idle+0x7b/0xd0)
>   <idle>-0     0D... 459333us : atomic_notifier_call_chain+0x9/0x20 (enter_idle+0x27/0x30)
>   <idle>-0     0D... 459333us : __atomic_notifier_call_chain+0x9/0x20 (atomic_notifier_call_chain+0x16/0x20)
>   <idle>-0     0D... 459334us : notifier_call_chain+0x16/0x80 (__atomic_notifier_call_chain+0x12/0x20)
>   <idle>-0     0D... 459334us : mce_idle_callback+0x9/0x40 (notifier_call_chain+0x41/0x80)