[4.9.327 / 4.14.292 / 4.19.257] WARNING: inconsistent lock state => inconsistent {SOFTIRQ-ON-W} -> {IN-SOFTIRQ-W} usage

gistfile1.txt

### .config used: https://gist.github.com/erosca/b6f6b048f0dd4cb0296951107ec31871
###
### Culprit commits:
### v4.19.238 commit https://git.kernel.org/pub/scm/linux/kernel/git/stable/linux.git/commit/?id=242a3e0c75b6
### v4.14.276 commit https://git.kernel.org/pub/scm/linux/kernel/git/stable/linux.git/commit/?id=dd7d3a609aac
### v4.9.311 commit https://git.kernel.org/pub/scm/linux/kernel/git/stable/linux.git/commit/?id=6180bbce5273

##############################################################################################

[    7.432028] ================================
[    7.436306] WARNING: inconsistent lock state
[    7.440589] 4.19.257 #37 Not tainted
[    7.444170] --------------------------------
[    7.448449] inconsistent {SOFTIRQ-ON-W} -> {IN-SOFTIRQ-W} usage.
[    7.454469] swapper/0/0 [HC0[0]:SC1[3]:HE1:SE0] takes:
[    7.459618] (____ptrval____) (&(&xprt->transport_lock)->rlock){+.?.}, at: xs_tcp_state_change+0x588/0x9b0
[    7.469230] {SOFTIRQ-ON-W} state was registered at:
[    7.474127]   lock_acquire+0x1a4/0x5f0
[    7.477892]   _raw_spin_lock+0xd4/0x114
[    7.481741]   xprt_destroy+0x7c/0x188
[    7.485411]   xprt_put+0x34/0x40
[    7.488649]   rpc_new_client+0xfc/0x778
[    7.492495]   rpc_create_xprt+0xf4/0x284
[    7.496428]   rpc_create+0x200/0x3c8
[    7.500020]   nfs_create_rpc_client+0x2e0/0x34c
[    7.504565]   nfs4_alloc_client+0x7a0/0x9e8
[    7.508758]   nfs_get_client+0xe34/0xe48
[    7.512691]   nfs4_set_client+0x244/0x334
[    7.516710]   nfs4_create_server+0x48c/0x914
[    7.520990]   nfs4_remote_mount+0x60/0x98
[    7.525014]   mount_fs+0x68/0x244
[    7.528342]   vfs_kern_mount+0x94/0x2cc
[    7.532187]   nfs_do_root_mount+0x8c/0xc8
[    7.536205]   nfs4_try_mount+0xac/0xec
[    7.539965]   nfs_fs_mount+0x19e0/0x1e40
[    7.543898]   mount_fs+0x68/0x244
[    7.547221]   vfs_kern_mount+0x94/0x2cc
[    7.551066]   do_mount+0xd44/0x16dc
[    7.554563]   ksys_mount+0xc0/0xd0
[    7.557979]   mount_root+0xf4/0x1f0
[    7.561475]   prepare_namespace+0x174/0x184
[    7.565668]   kernel_init_freeable+0xb18/0xeec
[    7.570122]   kernel_init+0x18/0x13c
[    7.573711]   ret_from_fork+0x10/0x18
[    7.577379] irq event stamp: 28524
[    7.580792] hardirqs last  enabled at (28524): [<ffff20000942d30c>] _raw_spin_unlock_irqrestore+0xe8/0xf0
[    7.590381] hardirqs last disabled at (28523): [<ffff20000942ce38>] _raw_spin_lock_irqsave+0x38/0x120
[    7.599625] softirqs last  enabled at (28444): [<ffff2000080e167c>] _local_bh_enable+0x5c/0x68
[    7.608257] softirqs last disabled at (28445): [<ffff2000080e1fb0>] irq_exit+0x2b4/0x3dc
[    7.616361] 
[    7.616361] other info that might help us debug this:
[    7.622902]  Possible unsafe locking scenario:
[    7.622902] 
[    7.628832]        CPU0
[    7.631282]        ----
[    7.633731]   lock(&(&xprt->transport_lock)->rlock);
[    7.638706]   <Interrupt>
[    7.641330]     lock(&(&xprt->transport_lock)->rlock);
[    7.646479] 
[    7.646479]  *** DEADLOCK ***
[    7.646479] 
[    7.652414] 4 locks held by swapper/0/0:
[    7.656342]  #0: (____ptrval____) (rcu_read_lock){....}, at: netif_receive_skb_internal+0x130/0x4b4
[    7.665420]  #1: (____ptrval____) (rcu_read_lock){....}, at: ip_local_deliver_finish+0x1b8/0x934
[    7.674235]  #2: (____ptrval____) (slock-AF_INET-RPC/1){+.-.}, at: tcp_v4_rcv+0x11a8/0x22ac
[    7.682615]  #3: (____ptrval____) (k-clock-AF_INET){++.-}, at: xs_tcp_state_change+0x34/0x9b0
[    7.691164] 
[    7.691164] stack backtrace:
[    7.695536] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.19.257 #37
[    7.701727] Hardware name: Renesas H3ULCB board based on r8a7795 ES2.0+ (DT)
[    7.708788] Call trace:
[    7.711245]  dump_backtrace+0x0/0x2f8
[    7.714917]  show_stack+0x24/0x30
[    7.718240]  dump_stack+0xf0/0x138
[    7.721650]  print_usage_bug.part.20+0x52c/0x68c
[    7.726278]  mark_lock+0x7f8/0x1000
[    7.729775]  __lock_acquire+0x960/0x39f8
[    7.733707]  lock_acquire+0x1a4/0x5f0
[    7.737378]  _raw_spin_lock+0xd4/0x114
[    7.741136]  xs_tcp_state_change+0x588/0x9b0
[    7.745416]  tcp_rcv_state_process+0x1114/0x3400
[    7.750046]  tcp_v4_do_rcv+0x7f8/0x80c
[    7.753803]  tcp_v4_rcv+0x13cc/0x22ac
[    7.757476]  ip_local_deliver_finish+0x6b4/0x934
[    7.762103]  ip_local_deliver+0x174/0x4b0
[    7.766120]  ip_rcv_finish+0xe4/0xfc
[    7.769703]  ip_rcv+0xc8/0x410
[    7.772766]  __netif_receive_skb_one_core+0x110/0x14c
[    7.777828]  __netif_receive_skb+0x164/0x16c
[    7.782109]  netif_receive_skb_internal+0x398/0x4b4
[    7.786997]  napi_gro_receive+0x5a4/0x5e0
[    7.791021]  ravb_poll+0xd10/0x1474
[    7.794520]  net_rx_action+0x3a4/0xc60
[    7.798278]  __do_softirq+0x704/0x1120
[    7.802036]  irq_exit+0x2b4/0x3dc
[    7.805362]  __handle_domain_irq+0xe8/0x13c
[    7.809554]  gic_handle_irq+0x70/0xb0
[    7.813225]  el1_irq+0xb4/0x140
[    7.816375]  arch_cpu_idle+0x32c/0x648
[    7.820133]  default_idle_call+0x5c/0x74
[    7.824068]  do_idle+0x25c/0x3bc
[    7.827304]  cpu_startup_entry+0x28/0x38
[    7.831235]  rest_init+0x574/0x588
[    7.834645]  start_kernel+0x6bc/0x704
[    7.863991] VFS: Mounted root (nfs4 filesystem) on device 0:15.

##########################################################################################

[    7.548549] ================================
[    7.552827] WARNING: inconsistent lock state
[    7.557112] 4.14.292 #35 Not tainted
[    7.560694] --------------------------------
[    7.564973] inconsistent {SOFTIRQ-ON-W} -> {IN-SOFTIRQ-W} usage.
[    7.570994] swapper/0/0 [HC0[0]:SC1[3]:HE1:SE0] takes:
[    7.576142]  (&(&xprt->transport_lock)->rlock){+.?.}, at: [<ffff2000095a6a48>] xs_tcp_state_change+0x740/0xb24
[    7.586196] {SOFTIRQ-ON-W} state was registered at:
[    7.591093]   lock_acquire+0x724/0x790
[    7.594857]   _raw_spin_lock+0xec/0x12c
[    7.598706]   xprt_destroy+0xc8/0x214
[    7.602379]   xprt_put+0x34/0x40
[    7.605618]   rpc_new_client+0x1a8/0x8e8
[    7.609552]   rpc_create_xprt+0x124/0x300
[    7.613573]   rpc_create+0x234/0x410
[    7.617162]   nfs_create_rpc_client+0x33c/0x38c
[    7.621709]   nfs4_alloc_client+0x8f4/0xb5c
[    7.625904]   nfs_get_client+0x10d4/0x10e8
[    7.630013]   nfs4_set_client+0x1b0/0x254
[    7.634034]   nfs4_create_server+0x4c0/0x92c
[    7.638317]   nfs4_remote_mount+0x74/0xac
[    7.642339]   mount_fs+0x80/0x27c
[    7.645666]   vfs_kern_mount+0xe0/0x3b4
[    7.649514]   nfs_do_root_mount+0x8c/0xc8
[    7.653534]   nfs4_try_mount+0xdc/0x120
[    7.657382]   nfs_fs_mount+0x1b6c/0x2038
[    7.661315]   mount_fs+0x80/0x27c
[    7.664639]   vfs_kern_mount+0xe0/0x3b4
[    7.668488]   do_mount+0x1324/0x1c90
[    7.672074]   SyS_mount+0xc0/0xd0
[    7.675403]   mount_root+0xe4/0x1c0
[    7.678903]   prepare_namespace+0x174/0x184
[    7.683098]   kernel_init_freeable+0x5b4/0x674
[    7.687556]   kernel_init+0x18/0x138
[    7.691144]   ret_from_fork+0x10/0x18
[    7.694814] irq event stamp: 24322
[    7.698228] hardirqs last  enabled at (24322): [<ffff200009679f8c>] _raw_spin_unlock_irqrestore+0x100/0x108
[    7.707990] hardirqs last disabled at (24321): [<ffff200009679a38>] _raw_spin_lock_irqsave+0x30/0x138
[    7.717233] softirqs last  enabled at (24244): [<ffff2000080e79d8>] _local_bh_enable+0x78/0x84
[    7.725865] softirqs last disabled at (24245): [<ffff2000080e9ed4>] irq_exit+0x350/0x4e0
[    7.733969] 
[    7.733969] other info that might help us debug this:
[    7.740511]  Possible unsafe locking scenario:
[    7.740511] 
[    7.746442]        CPU0
[    7.748893]        ----
[    7.751343]   lock(&(&xprt->transport_lock)->rlock);
[    7.756323]   <Interrupt>
[    7.758947]     lock(&(&xprt->transport_lock)->rlock);
[    7.764100] 
[    7.764100]  *** DEADLOCK ***
[    7.764100] 
[    7.770038] 4 locks held by swapper/0/0:
[    7.773967]  #0:  (rcu_read_lock){....}, at: [<ffff200009318d1c>] netif_receive_skb_internal+0x1b0/0x99c
[    7.783487]  #1:  (rcu_read_lock){....}, at: [<ffff2000093e0b10>] ip_local_deliver_finish+0x1e4/0xae0
[    7.792743]  #2:  (slock-AF_INET-RPC/1){+.-.}, at: [<ffff2000094757cc>] tcp_v4_rcv+0x1a04/0x2694
[    7.801567]  #3:  (k-clock-AF_INET){++.-}, at: [<ffff2000095a633c>] xs_tcp_state_change+0x34/0xb24
[    7.810559] 
[    7.810559] stack backtrace:
[    7.814931] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.14.292 #35
[    7.821123] Hardware name: Renesas H3ULCB Kingfisher board based on r8a7795 ES2.0+ (DT)
[    7.829142] Call trace:
[    7.831599]  dump_backtrace+0x0/0x320
[    7.835272]  show_stack+0x24/0x30
[    7.838598]  dump_stack+0x150/0x1b8
[    7.842097]  print_usage_bug.part.23+0x5c4/0x724
[    7.846725]  mark_lock+0x940/0x113c
[    7.850223]  __lock_acquire+0x9a8/0x2e70
[    7.854156]  lock_acquire+0x724/0x790
[    7.857827]  _raw_spin_lock+0xec/0x12c
[    7.861586]  xs_tcp_state_change+0x740/0xb24
[    7.865869]  tcp_rcv_state_process+0x1330/0x3a34
[    7.870498]  tcp_v4_do_rcv+0x9c8/0x9dc
[    7.874256]  tcp_v4_rcv+0x1c5c/0x2694
[    7.877930]  ip_local_deliver_finish+0x770/0xae0
[    7.882560]  ip_local_deliver+0x1c0/0x528
[    7.886581]  ip_rcv_finish+0x770/0x1024
[    7.890427]  ip_rcv+0xa50/0xe5c
[    7.893579]  __netif_receive_skb_core+0x1adc/0x2164
[    7.898470]  __netif_receive_skb+0x1e0/0x1e8
[    7.902752]  netif_receive_skb_internal+0x6c8/0x99c
[    7.907642]  napi_gro_receive+0x79c/0x7dc
[    7.911666]  ravb_poll+0xc98/0x1594
[    7.915165]  napi_poll+0x260/0xb6c
[    7.918577]  net_rx_action+0x2fc/0x668
[    7.922336]  __do_softirq+0xec8/0x1620
[    7.926095]  irq_exit+0x350/0x4e0
[    7.929421]  __handle_domain_irq+0x124/0x1c0
[    7.933701]  gic_handle_irq+0x70/0xb0
[    7.937372]  el1_irq+0xb4/0x140
[    7.940523]  arch_cpu_idle+0x17c/0x7fc
[    7.944282]  default_idle_call+0x74/0x8c
[    7.948216]  do_idle+0x250/0x344
[    7.951453]  cpu_startup_entry+0x28/0x38
[    7.955387]  rest_init+0x5f0/0x604
[    7.958799]  start_kernel+0x5dc/0x60c

##############################################################################################

[    7.012383] =================================
[    7.016763] [ INFO: inconsistent lock state ]
[    7.021150] 4.9.327 #36 Not tainted
[    7.024661] ---------------------------------
[    7.029044] inconsistent {SOFTIRQ-ON-W} -> {IN-SOFTIRQ-W} usage.
[    7.035080] swapper/0/0 [HC0[0]:SC1[3]:HE1:SE0] takes:
[    7.040244]  (&(&xprt->transport_lock)->rlock){+.?...}, at: [<ffff200009427cfc>] xs_tcp_state_change+0x72c/0xa18
[    7.050526] {SOFTIRQ-ON-W} state was registered at:
[    7.055440]   mark_lock+0x6ac/0x11f0
[    7.059044]   __lock_acquire+0xab4/0x2f58
[    7.063081]   lock_acquire+0x774/0x818
[    7.066859]   _raw_spin_lock+0xec/0x12c
[    7.070725]   xprt_destroy+0x68/0x144
[    7.074414]   xprt_put+0x44/0x50
[    7.077670]   rpc_new_client+0x1a8/0x920
[    7.081621]   rpc_create_xprt+0x164/0x340
[    7.085658]   rpc_create+0x270/0x44c
[    7.089264]   nfs_create_rpc_client+0x33c/0x38c
[    7.093824]   nfs4_alloc_client+0x928/0xb80
[    7.098036]   nfs_get_client+0xf9c/0xfac
[    7.101985]   nfs4_set_client+0x16c/0x208
[    7.106020]   nfs4_create_server+0x508/0x970
[    7.110322]   nfs4_remote_mount+0x74/0xac
[    7.114362]   mount_fs+0x80/0x270
[    7.117706]   vfs_kern_mount+0x90/0x284
[    7.121569]   nfs_do_root_mount+0x8c/0xc8
[    7.125606]   nfs4_try_mount+0xdc/0x120
[    7.129470]   nfs_fs_mount+0x1b44/0x1fc0
[    7.133419]   mount_fs+0x80/0x270
[    7.136761]   vfs_kern_mount+0x90/0x284
[    7.140623]   do_mount+0x13b4/0x1d0c
[    7.144226]   SyS_mount+0xc0/0xd0
[    7.147573]   mount_root+0xdc/0x1b8
[    7.151088]   prepare_namespace+0x16c/0x17c
[    7.155299]   kernel_init_freeable+0x748/0x808
[    7.159774]   kernel_init+0x18/0x12c
[    7.163377]   ret_from_fork+0x10/0x30
[    7.167062] irq event stamp: 23428
[    7.170492] hardirqs last  enabled at (23428): [<ffff2000094d247c>] _raw_spin_unlock_irqrestore+0x100/0x108
[    7.180288] hardirqs last disabled at (23427): [<ffff2000094d1f28>] _raw_spin_lock_irqsave+0x30/0x138
[    7.189563] softirqs last  enabled at (23330): [<ffff2000080e416c>] _local_bh_enable+0xb4/0xc0
[    7.198228] softirqs last disabled at (23331): [<ffff2000080e4e38>] irq_exit+0x38c/0x548
[    7.206365] 
[    7.206365] other info that might help us debug this:
[    7.212939]  Possible unsafe locking scenario:
[    7.212939] 
[    7.218903]        CPU0
[    7.221369]        ----
[    7.223835]   lock(&(&xprt->transport_lock)->rlock);
[    7.228844]   <Interrupt>
[    7.231484]     lock(&(&xprt->transport_lock)->rlock);
[    7.236667] 
[    7.236667]  *** DEADLOCK ***
[    7.236667] 
[    7.242655] 4 locks held by swapper/0/0:
[    7.246600]  #0:  (rcu_read_lock){......}, at: [<ffff2000091b7a38>] netif_receive_skb_internal+0x134/0x510
[    7.256352]  #1:  (rcu_read_lock){......}, at: [<ffff20000926e3d4>] ip_local_deliver_finish+0x1e4/0xad8
[    7.265842]  #2:  (slock-AF_INET-RPC/1){+.-...}, at: [<ffff2000093022f8>] tcp_v4_rcv+0x1c94/0x2964
[    7.274909]  #3:  (clock-AF_INET){++.-..}, at: [<ffff200009427604>] xs_tcp_state_change+0x34/0xa18
[    7.283961] 
[    7.283961] stack backtrace:
[    7.288367] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.9.327 #36
[    7.294487] Hardware name: Renesas H3ULCB board based on r8a7795 (DT)
[    7.300956] Call trace:
[    7.303430] [<ffff200008099434>] dump_backtrace+0x0/0x514
[    7.308860] [<ffff20000809996c>] show_stack+0x24/0x30
[    7.313942] [<ffff2000094bac44>] dump_stack+0x13c/0x19c
[    7.319197] [<ffff2000094b3884>] print_usage_bug.part.22+0x5c0/0x720
[    7.325582] [<ffff2000081d0490>] mark_lock+0x978/0x11f0
[    7.330837] [<ffff2000081d20bc>] __lock_acquire+0x9e0/0x2f58
[    7.336526] [<ffff2000081d5c90>] lock_acquire+0x774/0x818
[    7.341954] [<ffff2000094d2250>] _raw_spin_lock+0xec/0x12c
[    7.347468] [<ffff200009427cfc>] xs_tcp_state_change+0x72c/0xa18
[    7.353505] [<ffff2000092d56fc>] tcp_rcv_state_process+0x12c8/0x375c
[    7.359890] [<ffff2000092f8058>] tcp_v4_do_rcv+0xa18/0xa2c
[    7.365405] [<ffff20000930259c>] tcp_v4_rcv+0x1f38/0x2964
[    7.370832] [<ffff20000926e958>] ip_local_deliver_finish+0x768/0xad8
[    7.377217] [<ffff20000927035c>] ip_local_deliver+0x1cc/0x53c
[    7.382992] [<ffff20000926f44c>] ip_rcv_finish+0x784/0x1028
[    7.388593] [<ffff200009271128>] ip_rcv+0xa5c/0xe28
[    7.393500] [<ffff2000091b3314>] __netif_receive_skb_core+0x1b54/0x2124
[    7.400146] [<ffff2000091b78fc>] __netif_receive_skb+0x2c0/0x2c8
[    7.406183] [<ffff2000091b7b44>] netif_receive_skb_internal+0x240/0x510
[    7.412828] [<ffff2000091bc388>] napi_gro_receive+0x788/0x7c8
[    7.418607] [<ffff200008e85ad8>] ravb_poll+0xc64/0x15dc
[    7.423861] [<ffff2000091b9d64>] net_rx_action+0x3e0/0xf14
[    7.429375] [<ffff200008082c04>] __do_softirq+0x1084/0x16fc
[    7.434976] [<ffff2000080e4e38>] irq_exit+0x38c/0x548
[    7.440060] [<ffff2000081fda58>] __handle_domain_irq+0x124/0x1c0
[    7.446096] [<ffff200008081974>] gic_handle_irq+0x6c/0xa8
[    7.451523] Exception stack(0xffff200009ce3d10 to 0xffff200009ce3e40)
[    7.457994] 3d00:                                   ffff200009cfc6e4 0000000000000007
[    7.465875] 3d20: 0000000000000000 0000000000000000 0000000000000000 ffffffffffffe4d8
[    7.473756] 3d40: 00000000000016a0 ffffffffffffe4d8 ffff200009cfd500 ffff200009ce0000
[    7.481636] 3d60: 0000000000001620 ffff1000daaba74d 00000000f76a9153 00000000374194c9
[    7.489516] 3d80: 00000000d876d493 0000000027cf0475 00000000510e5ee6 000000003e6f44cf
[    7.497397] 3da0: 00000000451e6d1b ffff200009ce0000 0000000000000008 0000000000000000
[    7.505278] 3dc0: dfff200000000000 0000000000000001 ffff200009ceb368 ffff200009ceb000
[    7.513158] 3de0: ffff04000139d66d 0000000000000000 ffff200009ce0000 ffff200009ce3e40
[    7.521039] 3e00: ffff20000808c2a8 ffff200009ce3e40 ffff20000808c2ac 0000000010000045
[    7.528919] 3e20: 0000000000000000 0000000000000008 ffffffffffffffff ffff20000808c2a8
[    7.536799] [<ffff200008084930>] el1_irq+0xb0/0x140
[    7.541707] [<ffff20000808c2ac>] arch_cpu_idle+0x3dc/0x7a8
[    7.547221] [<ffff2000094d1bd8>] default_idle_call+0x74/0x7c
[    7.552910] [<ffff2000081b6d10>] cpu_startup_entry+0x250/0x338
[    7.558774] [<ffff2000094bec48>] rest_init+0x328/0x338
[    7.563942] [<ffff200009a1147c>] start_kernel+0x5d4/0x604
[    7.569371] [<ffff200009a101e0>] __primary_switched+0x64/0x68
[    7.616954] VFS: Mounted root (nfs4 filesystem) on device 0:14.

#############################################################################################