Subject: Re: iproute2 4.14.1 tc class add come to kernel-panic

From: Stephen Hemminger <[email-masked]>
Date: Mon, 29 Jan 2018 08:00:24 -0800

On Mon, 29 Jan 2018 16:18:07 +0100
"Roland Franke" <[email-masked]> wrote:

> Hello,
> 
> > To: Roland Franke ; [email-masked] 
> > Subject: Re: BUG: iproute2 4.14.1 tc class add come to kernel-panic   
> >> 
> >> tc qdisc add dev eth0 root handle 20: htb default 4 r2q 1
> >> tc class add dev eth0 parent 20: classid 20:7 htb rate 10000kbit
> >> tc qdisc add dev eth0 parent 20:7 sfq perturb 10
> >> tc class add dev eth0 parent 20:7 classid 20:1 htb rate 200kbit ceil 
> >> 10000kbit prio 0
> >> 
> >> I become an Kernel-panic with the following output:
> >> kern.err kernel: BUG: scheduling while atomic: tc/1036/0x00000200  
> >   
> 
> > Would you have a stack trace to share with us ?  
> 
> As i will be an absolute newby here, i will not know how to 
> get the stack trace out.
> When i will get some information how to get this, i can try to 
> give you this information.
> But by my last tests i made the first 3 commands on an console
> and had no error. Only by typing the last line i will get the error and
> here i get actally only the "kern.err kernel: BUG: ....." message.
> 
> Roland

It generates this with lockdep (on 4.15)

[  151.355076] HTB: quantum of class 200007 is big. Consider r2q change.
[  151.371495] BUG: sleeping function called from invalid context at kernel/locking/mutex.c:747
[  151.371815] in_atomic(): 1, irqs_disabled(): 0, pid: 1135, name: tc
[  151.371875] 2 locks held by tc/1135:
[  151.371878]  #0:  (rtnl_mutex){+.+.}, at: [<ffffffff98826e5b>] rtnetlink_rcv_msg+0x23b/0x5f0
[  151.371899]  #1:  (&qdisc_tx_lock){+...}, at: [<ffffffffc07a5f0f>] htb_change_class+0x55f/0x880 [sch_htb]
[  151.371918] CPU: 2 PID: 1135 Comm: tc Not tainted 4.14.15 #2
[  151.371921] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[  151.371924] Call Trace:
[  151.371934]  dump_stack+0x7c/0xbe
[  151.371944]  ___might_sleep+0x21e/0x250
[  151.371953]  __mutex_lock+0x59/0x9a0
[  151.371960]  ? lock_acquire+0xec/0x1e0
[  151.371973]  ? __raw_spin_lock_init+0x1c/0x50
[  151.371990]  ? _rcu_barrier+0x2f/0x170
[  151.371995]  ? __lockdep_init_map+0x5c/0x1d0
[  151.371998]  _rcu_barrier+0x2f/0x170
[  151.372006]  tcf_block_put+0x7f/0xa0
[  151.372013]  sfq_destroy+0x15/0x50 [sch_sfq]
[  151.372021]  qdisc_destroy+0x6c/0xe0
[  151.372028]  htb_change_class+0x704/0x880 [sch_htb]
[  151.372050]  tc_ctl_tclass+0x193/0x3c0
[  151.372075]  rtnetlink_rcv_msg+0x270/0x5f0
[  151.372088]  ? rtnetlink_put_metrics+0x1c0/0x1c0
[  151.372096]  netlink_rcv_skb+0xde/0x110
[  151.372109]  netlink_unicast+0x1e4/0x310
[  151.372118]  netlink_sendmsg+0x2dc/0x3c0
[  151.372136]  sock_sendmsg+0x30/0x40
[  151.372142]  ___sys_sendmsg+0x2b9/0x2d0
[  151.372171]  ? __handle_mm_fault+0x7f8/0x1120
[  151.372189]  ? __do_page_fault+0x2a5/0x530
[  151.372200]  ? __sys_sendmsg+0x51/0x90
[  151.372205]  __sys_sendmsg+0x51/0x90
[  151.372225]  entry_SYSCALL_64_fastpath+0x29/0xa0
[  151.372230] RIP: 0033:0x7f7049397490
[  151.372233] RSP: 002b:00007ffd0c432f48 EFLAGS: 00000246
[  151.372445] BUG: scheduling while atomic: tc/1135/0x00000202
[  151.372524] 3 locks held by tc/1135:
[  151.372527]  #0:  (rtnl_mutex){+.+.}, at: [<ffffffff98826e5b>] rtnetlink_rcv_msg+0x23b/0x5f0
[  151.372544]  #1:  (&qdisc_tx_lock){+...}, at: [<ffffffffc07a5f0f>] htb_change_class+0x55f/0x880 [sch_htb]
[  151.372560]  #2:  (rcu_sched_state.barrier_mutex){+.+.}, at: [<ffffffff9810bbbf>] _rcu_barrier+0x2f/0x170
[  151.372575] Modules linked in: sch_sfq sch_htb ppdev input_leds serio_raw joydev parport_pc parport i2c_piix4 mac_hid ib_iser rdma_cm iw_cm ib_cm ib_core iscsi_tcp libiscsi_tcp libiscsi scsi_transport_iscsi autofs4 btrfs zstd_decompress zstd_compress xxhash raid10 raid456 libcrc32c async_raid6_recov async_memcpy async_pq async_xor async_tx xor raid6_pq raid1 raid0 multipath linear qxl drm_kms_helper syscopyarea sysfillrect sysimgblt fb_sys_fops ttm drm crct10dif_pclmul crc32_pclmul ghash_clmulni_intel aesni_intel aes_x86_64 crypto_simd cryptd glue_helper psmouse floppy pata_acpi hid_generic usbhid hid
[  151.372748] CPU: 2 PID: 1135 Comm: tc Tainted: G        W       4.14.15 #2
[  151.372751] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[  151.372753] Call Trace:
[  151.372759]  dump_stack+0x7c/0xbe
[  151.372767]  __schedule_bug+0x62/0x90
[  151.372772]  __schedule+0x7d9/0xb80
[  151.372788]  schedule+0x39/0x90
[  151.372793]  schedule_timeout+0x24d/0x5c0
[  151.372813]  ? mark_held_locks+0x71/0xa0
[  151.372825]  ? wait_for_completion+0x12e/0x1a0
[  151.372829]  wait_for_completion+0x12e/0x1a0
[  151.372835]  ? wake_up_q+0x60/0x60
[  151.372846]  _rcu_barrier+0x11a/0x170
[  151.372853]  tcf_block_put+0x7f/0xa0
[  151.372860]  sfq_destroy+0x15/0x50 [sch_sfq]
[  151.372866]  qdisc_destroy+0x6c/0xe0
[  151.372872]  htb_change_class+0x704/0x880 [sch_htb]
[  151.372894]  tc_ctl_tclass+0x193/0x3c0
[  151.372918]  rtnetlink_rcv_msg+0x270/0x5f0
[  151.372932]  ? rtnetlink_put_metrics+0x1c0/0x1c0
[  151.372940]  netlink_rcv_skb+0xde/0x110
[  151.372952]  netlink_unicast+0x1e4/0x310
[  151.372961]  netlink_sendmsg+0x2dc/0x3c0
[  151.372977]  sock_sendmsg+0x30/0x40
[  151.372983]  ___sys_sendmsg+0x2b9/0x2d0
[  151.373010]  ? __handle_mm_fault+0x7f8/0x1120
[  151.373026]  ? __do_page_fault+0x2a5/0x530
[  151.373037]  ? __sys_sendmsg+0x51/0x90
[  151.373042]  __sys_sendmsg+0x51/0x90
[  151.373061]  entry_SYSCALL_64_fastpath+0x29/0xa0
[  151.373065] RIP: 0033:0x7f7049397490
[  151.373068] RSP: 002b:00007ffd0c432f48 EFLAGS: 00000246
[  151.373306] NOHZ: local_softirq_pending 202
[  151.400331] ------------[ cut here ]------------
[  151.400342] WARNING: CPU: 2 PID: 1135 at net/core/skbuff.c:615 skb_release_head_state+0x4b/0x50
[  151.400345] Modules linked in: sch_sfq sch_htb ppdev input_leds serio_raw joydev parport_pc parport i2c_piix4 mac_hid ib_iser rdma_cm iw_cm ib_cm ib_core iscsi_tcp libiscsi_tcp libiscsi scsi_transport_iscsi autofs4 btrfs zstd_decompress zstd_compress xxhash raid10 raid456 libcrc32c async_raid6_recov async_memcpy async_pq async_xor async_tx xor raid6_pq raid1 raid0 multipath linear qxl drm_kms_helper syscopyarea sysfillrect sysimgblt fb_sys_fops ttm drm crct10dif_pclmul crc32_pclmul ghash_clmulni_intel aesni_intel aes_x86_64 crypto_simd cryptd glue_helper psmouse floppy pata_acpi hid_generic usbhid hid
[  151.400521] CPU: 2 PID: 1135 Comm: tc Tainted: G        W       4.14.15 #2
[  151.400524] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[  151.400527] task: ffff980e7b050000 task.stack: ffffa3ca00578000
[  151.400532] RIP: 0010:skb_release_head_state+0x4b/0x50
[  151.400536] RSP: 0018:ffffa3ca0057bc38 EFLAGS: 00010206
[  151.400543] RAX: ffffffff9884c9a0 RBX: ffff980e7b18c800 RCX: 0000000000000002
[  151.400546] RDX: 00000000000f0000 RSI: 00000000ffffffff RDI: 0000000000000000
[  151.400550] RBP: ffff980e72d9f800 R08: 0000000000000004 R09: 0000000000000000
[  151.400553] R10: 0000000000000001 R11: 0000000000000000 R12: 0000000000000868
[  151.400556] R13: ffff980e7b18c800 R14: 0000000000000000 R15: 0000000000000000
[  151.400560] FS:  00007f7049d82700(0000) GS:ffff980e7e200000(0000) knlGS:0000000000000000
[  151.400564] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  151.400567] CR2: 00007fb14b0f74a0 CR3: 000000003b142004 CR4: 00000000003606e0
[  151.400574] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[  151.400578] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[  151.400581] Call Trace:
[  151.400589]  skb_release_all+0xe/0x30
[  151.400594]  consume_skb+0x43/0x140
[  151.400603]  netlink_unicast+0x1ec/0x310
[  151.400613]  netlink_sendmsg+0x2dc/0x3c0
[  151.400630]  sock_sendmsg+0x30/0x40
[  151.400637]  ___sys_sendmsg+0x2b9/0x2d0
[  151.400667]  ? __handle_mm_fault+0x7f8/0x1120
[  151.400685]  ? __do_page_fault+0x2a5/0x530
[  151.400697]  ? __sys_sendmsg+0x51/0x90
[  151.400702]  __sys_sendmsg+0x51/0x90
[  151.400724]  entry_SYSCALL_64_fastpath+0x29/0xa0
[  151.400729] RIP: 0033:0x7f7049397490
[  151.400732] RSP: 002b:00007ffd0c432f48 EFLAGS: 00000246
[  151.400755] Code: 48 8b 43 60 48 85 c0 74 20 65 8b 15 b0 c2 81 67 81 e2 00 00 0f 00 75 13 48 89 df 5b ff e0 48 83 e7 fe e8 a9 27 02 00 eb cf 5b c3 <0f> ff eb e9 90 0f 1f 44 00 00 53 48 89 fb e8 a2 ff ff ff 48 83 
[  151.400935] ---[ end trace a2dc1d508339e762 ]---
[  151.400954] show_signal_msg: 5 callbacks suppressed
[  151.400957] tc[1135]: segfault at 7ffd0c434000 ip 00007f7049401af8 sp 00007ffd0c432f48 error 6
[  151.401033] BUG: scheduling while atomic: tc/1135/0x7ffffe00
[  151.401104] no locks held by tc/1135.
[  151.401107] Modules linked in: sch_sfq sch_htb ppdev input_leds serio_raw joydev parport_pc parport i2c_piix4 mac_hid ib_iser rdma_cm iw_cm ib_cm ib_core iscsi_tcp libiscsi_tcp libiscsi scsi_transport_iscsi autofs4 btrfs zstd_decompress zstd_compress xxhash raid10 raid456 libcrc32c async_raid6_recov async_memcpy async_pq async_xor async_tx xor raid6_pq raid1 raid0 multipath linear qxl drm_kms_helper syscopyarea sysfillrect sysimgblt fb_sys_fops ttm drm crct10dif_pclmul crc32_pclmul ghash_clmulni_intel aesni_intel aes_x86_64 crypto_simd cryptd glue_helper psmouse floppy pata_acpi hid_generic usbhid hid
[  151.401277] CPU: 2 PID: 1135 Comm: tc Tainted: G        W       4.14.15 #2
[  151.401281] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[  151.401284] Call Trace:
[  151.401291]  dump_stack+0x7c/0xbe
[  151.401300]  __schedule_bug+0x62/0x90
[  151.401306]  __schedule+0x7d9/0xb80
[  151.401323]  schedule+0x39/0x90
[  151.401329]  schedule_timeout+0x24d/0x5c0
[  151.401334]  ? try_to_wake_up+0x55/0x550
[  151.401351]  ? wait_for_completion+0x126/0x1a0
[  151.401366]  ? wait_for_completion+0x12e/0x1a0
[  151.401371]  wait_for_completion+0x12e/0x1a0
[  151.401377]  ? wake_up_q+0x60/0x60
[  151.401389]  call_usermodehelper_exec+0x143/0x170
[  151.401402]  ? wait_for_completion+0x49/0x1a0
[  151.401415]  do_coredump+0xb8a/0x10e0
[  151.401466]  get_signal+0x3d0/0x8f0
[  151.401488]  do_signal+0x36/0x700
[  151.401493]  ? force_sig_info+0xca/0xe0
[  151.401504]  ? force_sig_info_fault+0x97/0xf0
[  151.401519]  ? __bad_area_nosemaphore+0x168/0x1a0
[  151.401537]  exit_to_usermode_loop+0x80/0xc0
[  151.401543]  ? async_page_fault+0x36/0x60
[  151.401550]  prepare_exit_to_usermode+0x7a/0x90
[  151.401557]  retint_user+0x8/0x18
[  151.401562] RIP: 0033:0x7f7049401af8
[  151.401565] RSP: 002b:00007ffd0c432f48 EFLAGS: 00010207
[  151.401571] RAX: 0000000000000000 RBX: 000000000064cb00 RCX: 0000000000006fd0
[  151.401575] RDX: 0000000000008000 RSI: 00007ffd0c43afd0 RDI: 00007ffd0c434000
[  151.401578] RBP: 000000005a6f436a R08: 0000000000000014 R09: 0000000000000000
[  151.401581] R10: 00000000000005e7 R11: 0000000000000246 R12: 00007ffd0c432f90
[  151.401584] R13: 00007ffd0c432fd0 R14: 0000000000655aa0 R15: 0000000000000000

[  168.036082] ========================================================
[  168.037902] WARNING: possible irq lock inversion dependency detected
[  168.039397] 4.14.15 #2 Tainted: G        W      
[  168.040574] --------------------------------------------------------
[  168.041051] swapper/3/0 just changed the state of lock:
[  168.041520]  (&qdisc_tx_lock){+.-.}, at: [<ffffffff98811e2a>] __dev_queue_xmit+0x24a/0x9a0
[  168.042009] but this lock took another, SOFTIRQ-unsafe lock in the past:
[  168.042486]  (rcu_sched_state.barrier_mutex){+.+.}
[  168.042488] 
               
               and interrupts could create inverse lock ordering between them.

[  168.044723] 
               other info that might help us debug this:
[  168.045509]  Possible interrupt unsafe locking scenario:

[  168.046288]        CPU0                    CPU1
[  168.046649]        ----                    ----
[  168.047009]   lock(rcu_sched_state.barrier_mutex);
[  168.047372]                                local_irq_disable();
[  168.047742]                                lock(&qdisc_tx_lock);
[  168.048112]                                lock(rcu_sched_state.barrier_mutex);
[  168.048504]   <Interrupt>
[  168.048871]     lock(&qdisc_tx_lock);
[  168.049240] 
                *** DEADLOCK ***

[  168.050329] 4 locks held by swapper/3/0:
[  168.050693]  #0:  (rcu_read_lock){....}, at: [<ffffffff9881355a>] netif_receive_skb_internal+0x2a/0x360
[  168.051082]  #1:  (rcu_read_lock){....}, at: [<ffffffff9885e836>] ip_local_deliver_finish+0x26/0x1f0
[  168.051472]  #2:  (rcu_read_lock_bh){....}, at: [<ffffffff9886389c>] ip_finish_output2+0xac/0x650
[  168.051868]  #3:  (rcu_read_lock_bh){....}, at: [<ffffffff98811c3e>] __dev_queue_xmit+0x5e/0x9a0
[  168.052266] 
               the shortest dependencies between 2nd lock and 1st lock:
[  168.053089]  -> (rcu_sched_state.barrier_mutex){+.+.} ops: 3 {
[  168.053504]     HARDIRQ-ON-W at:
[  168.053900]                       lock_acquire+0xec/0x1e0
[  168.054301]                       __mutex_lock+0x92/0x9a0
[  168.054698]                       _rcu_barrier+0x2f/0x170
[  168.055094]                       slab_caches_to_rcu_destroy_workfn+0x95/0xe0
[  168.055522]                       process_one_work+0x204/0x650
[  168.055922]                       worker_thread+0x4d/0x3e0
[  168.056316]                       kthread+0x10a/0x140
[  168.056717]                       ret_from_fork+0x3a/0x50
[  168.057107]     SOFTIRQ-ON-W at:
[  168.057494]                       lock_acquire+0xec/0x1e0
[  168.057886]                       __mutex_lock+0x92/0x9a0
[  168.058267]                       _rcu_barrier+0x2f/0x170
[  168.058641]                       slab_caches_to_rcu_destroy_workfn+0x95/0xe0
[  168.059016]                       process_one_work+0x204/0x650
[  168.059386]                       worker_thread+0x4d/0x3e0
[  168.059751]                       kthread+0x10a/0x140
[  168.060109]                       ret_from_fork+0x3a/0x50
[  168.060468]     INITIAL USE at:
[  168.060808]                      lock_acquire+0xec/0x1e0
[  168.061147]                      __mutex_lock+0x92/0x9a0
[  168.061484]                      _rcu_barrier+0x2f/0x170
[  168.061825]                      slab_caches_to_rcu_destroy_workfn+0x95/0xe0
[  168.062166]                      process_one_work+0x204/0x650
[  168.062502]                      worker_thread+0x4d/0x3e0
[  168.062843]                      kthread+0x10a/0x140
[  168.063180]                      ret_from_fork+0x3a/0x50
[  168.063514]   }
[  168.063857]   ... key      at: [<ffffffff992798b0>] rcu_sched_state+0x8530/0x8800
[  168.064200]   ... acquired at:
[  168.064554]    __mutex_lock+0x92/0x9a0
[  168.064897]    _rcu_barrier+0x2f/0x170
[  168.065236]    tcf_block_put+0x7f/0xa0
[  168.065599]    sfq_destroy+0x15/0x50 [sch_sfq]
[  168.065940]    qdisc_destroy+0x6c/0xe0
[  168.066277]    htb_change_class+0x704/0x880 [sch_htb]
[  168.066618]    tc_ctl_tclass+0x193/0x3c0
[  168.066960]    rtnetlink_rcv_msg+0x270/0x5f0
[  168.067306]    netlink_rcv_skb+0xde/0x110
[  168.067653]    netlink_unicast+0x1e4/0x310
[  168.067999]    netlink_sendmsg+0x2dc/0x3c0
[  168.068332]    sock_sendmsg+0x30/0x40
[  168.068713]    ___sys_sendmsg+0x2b9/0x2d0
[  168.069036]    __sys_sendmsg+0x51/0x90
[  168.069357]    entry_SYSCALL_64_fastpath+0x29/0xa0

[  168.069974] -> (&qdisc_tx_lock){+.-.} ops: 5 {
[  168.070283]    HARDIRQ-ON-W at:
[  168.070587]                     lock_acquire+0xec/0x1e0
[  168.070901]                     _raw_spin_lock_bh+0x38/0x70
[  168.071212]                     htb_change_class+0x55f/0x880 [sch_htb]
[  168.071526]                     tc_ctl_tclass+0x193/0x3c0
[  168.071838]                     rtnetlink_rcv_msg+0x270/0x5f0
[  168.072148]                     netlink_rcv_skb+0xde/0x110
[  168.072466]                     netlink_unicast+0x1e4/0x310
[  168.072774]                     netlink_sendmsg+0x2dc/0x3c0
[  168.073080]                     sock_sendmsg+0x30/0x40
[  168.073384]                     ___sys_sendmsg+0x2b9/0x2d0
[  168.073703]                     __sys_sendmsg+0x51/0x90
[  168.074005]                     entry_SYSCALL_64_fastpath+0x29/0xa0
[  168.074312]    IN-SOFTIRQ-W at:
[  168.074615]                     lock_acquire+0xec/0x1e0
[  168.074948]                     _raw_spin_lock+0x30/0x70
[  168.075260]                     __dev_queue_xmit+0x24a/0x9a0
[  168.075567]                     ip_finish_output2+0x4c6/0x650
[  168.075877]                     ip_output+0x7c/0x250
[  168.076183]                     tcp_v4_send_synack+0x8e/0x120
[  168.076497]                     tcp_conn_request+0xaf4/0xc80
[  168.076804]                     tcp_rcv_state_process+0x233/0xf30
[  168.077114]                     tcp_v4_do_rcv+0xae/0x1c0
[  168.077419]                     tcp_v4_rcv+0xa2e/0xa80
[  168.077720]                     ip_local_deliver_finish+0x97/0x1f0
[  168.078024]                     ip_local_deliver+0x71/0x210
[  168.078329]                     ip_rcv+0x271/0x4c0
[  168.078631]                     __netif_receive_skb_core+0x79c/0xd20
[  168.078937]                     netif_receive_skb_internal+0x1a7/0x360
[  168.079241]                     napi_gro_receive+0x137/0x1b0
[  168.079539]                     receive_buf+0x444/0x1730
[  168.079837]                     virtnet_poll+0x119/0x290
[  168.080136]                     net_rx_action+0x1fd/0x410
[  168.080444]                     __do_softirq+0xc8/0x49a
[  168.080743]                     irq_exit+0xc1/0xd0
[  168.081039]                     do_IRQ+0x60/0x110
[  168.081333]                     ret_from_intr+0x0/0x22
[  168.081624]                     native_safe_halt+0x2/0x10
[  168.081917]                     default_idle+0x1d/0x1a0
[  168.082209]                     do_idle+0x170/0x200
[  168.082501]                     cpu_startup_entry+0x6f/0x80
[  168.082797]                     start_secondary+0x197/0x1f0
[  168.083093]                     secondary_startup_64+0xa5/0xb0
[  168.083404]    INITIAL USE at:
[  168.083697]                    lock_acquire+0xec/0x1e0
[  168.083995]                    _raw_spin_lock_bh+0x38/0x70
[  168.084293]                    htb_change_class+0x55f/0x880 [sch_htb]
[  168.084614]                    tc_ctl_tclass+0x193/0x3c0
[  168.084922]                    rtnetlink_rcv_msg+0x270/0x5f0
[  168.085218]                    netlink_rcv_skb+0xde/0x110
[  168.085514]                    netlink_unicast+0x1e4/0x310
[  168.085807]                    netlink_sendmsg+0x2dc/0x3c0
[  168.086096]                    sock_sendmsg+0x30/0x40
[  168.086384]                    ___sys_sendmsg+0x2b9/0x2d0
[  168.086673]                    __sys_sendmsg+0x51/0x90
[  168.086963]                    entry_SYSCALL_64_fastpath+0x29/0xa0
[  168.087256]  }
[  168.087544]  ... key      at: [<ffffffff9a7cc448>] qdisc_tx_lock+0x0/0x8
[  168.087845]  ... acquired at:
[  168.088144]    mark_lock+0x30a/0x5c0
[  168.088448]    __lock_acquire+0x3a5/0x1510
[  168.088743]    lock_acquire+0xec/0x1e0
[  168.089035]    _raw_spin_lock+0x30/0x70
[  168.089328]    __dev_queue_xmit+0x24a/0x9a0
[  168.089621]    ip_finish_output2+0x4c6/0x650
[  168.089915]    ip_output+0x7c/0x250
[  168.090207]    tcp_v4_send_synack+0x8e/0x120
[  168.090500]    tcp_conn_request+0xaf4/0xc80
[  168.090794]    tcp_rcv_state_process+0x233/0xf30
[  168.091089]    tcp_v4_do_rcv+0xae/0x1c0
[  168.091382]    tcp_v4_rcv+0xa2e/0xa80
[  168.091675]    ip_local_deliver_finish+0x97/0x1f0
[  168.091971]    ip_local_deliver+0x71/0x210
[  168.092265]    ip_rcv+0x271/0x4c0
[  168.092561]    __netif_receive_skb_core+0x79c/0xd20
[  168.092857]    netif_receive_skb_internal+0x1a7/0x360
[  168.093154]    napi_gro_receive+0x137/0x1b0
[  168.093448]    receive_buf+0x444/0x1730
[  168.093758]    virtnet_poll+0x119/0x290
[  168.094050]    net_rx_action+0x1fd/0x410
[  168.094355]    __do_softirq+0xc8/0x49a
[  168.094647]    irq_exit+0xc1/0xd0
[  168.094937]    do_IRQ+0x60/0x110
[  168.095227]    ret_from_intr+0x0/0x22
[  168.095518]    native_safe_halt+0x2/0x10
[  168.095809]    default_idle+0x1d/0x1a0
[  168.096099]    do_idle+0x170/0x200
[  168.096395]    cpu_startup_entry+0x6f/0x80
[  168.096687]    start_secondary+0x197/0x1f0
[  168.096978]    secondary_startup_64+0xa5/0xb0

[  168.097552] 
               stack backtrace:
[  168.098105] CPU: 3 PID: 0 Comm: swapper/3 Tainted: G        W       4.14.15 #2
[  168.098393] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[  168.098690] Call Trace:
[  168.098986]  <IRQ>
[  168.099278]  dump_stack+0x7c/0xbe
[  168.099574]  print_irq_inversion_bug.part.43+0x198/0x1a3
[  168.099877]  check_usage_forwards+0x17a/0x180
[  168.100182]  ? __save_stack_trace+0x82/0x100
[  168.100493]  ? secondary_startup_64+0xa5/0xb0
[  168.100799]  ? check_usage_backwards+0x180/0x180
[  168.101106]  ? mark_lock+0x30a/0x5c0
[  168.101410]  mark_lock+0x30a/0x5c0
[  168.101709]  __lock_acquire+0x3a5/0x1510
[  168.102005]  ? __lock_acquire+0xc21/0x1510
[  168.102303]  ? lock_acquire+0xec/0x1e0
[  168.102598]  lock_acquire+0xec/0x1e0
[  168.102893]  ? __dev_queue_xmit+0x24a/0x9a0
[  168.103191]  _raw_spin_lock+0x30/0x70
[  168.103488]  ? __dev_queue_xmit+0x24a/0x9a0
[  168.103803]  __dev_queue_xmit+0x24a/0x9a0
[  168.104124]  ip_finish_output2+0x4c6/0x650
[  168.104437]  ? ip_output+0x7c/0x250
[  168.104733]  ip_output+0x7c/0x250
[  168.105028]  ? tcp_make_synack+0x38b/0x4b0
[  168.105325]  tcp_v4_send_synack+0x8e/0x120
[  168.105623]  ? _raw_spin_unlock+0x24/0x30
[  168.105920]  ? inet_ehash_insert+0xfa/0x170
[  168.106218]  tcp_conn_request+0xaf4/0xc80
[  168.106519]  ? tcp_rcv_state_process+0x233/0xf30
[  168.106818]  tcp_rcv_state_process+0x233/0xf30
[  168.107119]  ? tcp_v4_do_rcv+0xae/0x1c0
[  168.107416]  tcp_v4_do_rcv+0xae/0x1c0
[  168.107713]  tcp_v4_rcv+0xa2e/0xa80
[  168.108010]  ip_local_deliver_finish+0x97/0x1f0
[  168.108310]  ip_local_deliver+0x71/0x210
[  168.108614]  ip_rcv+0x271/0x4c0
[  168.108953]  ? packet_rcv+0x3d/0x3a0
[  168.109261]  __netif_receive_skb_core+0x79c/0xd20
[  168.109564]  ? lock_acquire+0xec/0x1e0
[  168.109867]  ? dev_gro_receive+0x26b/0x5c0
[  168.110172]  ? netif_receive_skb_internal+0x2a/0x360
[  168.110480]  ? netif_receive_skb_internal+0x1a7/0x360
[  168.110892]  ? netif_receive_skb_internal+0x56/0x360
[  168.111197]  netif_receive_skb_internal+0x1a7/0x360
[  168.111503]  napi_gro_receive+0x137/0x1b0
[  168.111806]  receive_buf+0x444/0x1730
[  168.112115]  ? __lock_acquire+0x2e7/0x1510
[  168.112439]  ? vring_unmap_one+0x16/0x70
[  168.112754]  ? detach_buf+0x68/0x110
[  168.113052]  virtnet_poll+0x119/0x290
[  168.113339]  ? __wake_up_common_lock+0x89/0xc0
[  168.113675]  net_rx_action+0x1fd/0x410
[  168.113970]  ? credit_entropy_bits+0x313/0x350
[  168.114262]  __do_softirq+0xc8/0x49a
[  168.114551]  irq_exit+0xc1/0xd0
[  168.114837]  do_IRQ+0x60/0x110
[  168.115121]  common_interrupt+0xa2/0xa2
[  168.115404]  </IRQ>
[  168.115684] RIP: 0010:native_safe_halt+0x2/0x10
[  168.115969] RSP: 0018:ffffa3ca001ffec8 EFLAGS: 00000206 ORIG_RAX: ffffffffffffff2e
[  168.116267] RAX: ffff980e7db91b40 RBX: ffff980e7db91b40 RCX: 0000000000000000
[  168.116578] RDX: 0000000000000001 RSI: 0000000000000001 RDI: ffff980e7db91b40
[  168.116886] RBP: 0000000000000003 R08: 0000000000000001 R09: 0000000000000000
[  168.117194] R10: 0000000000000000 R11: 0000000000000000 R12: ffff980e7db91b40
[  168.117501] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
[  168.117811]  default_idle+0x1d/0x1a0
[  168.118116]  do_idle+0x170/0x200
[  168.118419]  cpu_startup_entry+0x6f/0x80
[  168.118725]  start_secondary+0x197/0x1f0
[  168.119029]  secondary_startup_64+0xa5/0xb0