syzbot


inconsistent lock state in xprt_disconnect_done

Status: auto-obsoleted due to no activity on 2022/12/23 11:50
Reported-by: syzbot+1f4408d3941322a6de1f@syzkaller.appspotmail.com
First crash: 728d, last: 607d

Sample crash report:
autofs4:pid:10847:autofs4_fill_super: called with bogus options
EXT4-fs (loop4): mounted filesystem without journal. Opts: ,errors=continue
EXT4-fs (loop3): mounted filesystem without journal. Opts: ,errors=continue
================================
WARNING: inconsistent lock state
4.14.291-syzkaller #0 Not tainted
--------------------------------
inconsistent {SOFTIRQ-ON-W} -> {IN-SOFTIRQ-W} usage.
ksoftirqd/0/8 [HC0[0]:SC1[5]:HE1:SE0] takes:
 (&(&xprt->transport_lock)->rlock){+.?.}, at: [<ffffffff86726fc9>] spin_lock_bh include/linux/spinlock.h:322 [inline]
 (&(&xprt->transport_lock)->rlock){+.?.}, at: [<ffffffff86726fc9>] xprt_disconnect_done+0x19/0x40 net/sunrpc/xprt.c:664
{SOFTIRQ-ON-W} state was registered at:
  lock_acquire+0x170/0x3f0 kernel/locking/lockdep.c:3998
  __raw_spin_lock include/linux/spinlock_api_smp.h:142 [inline]
  _raw_spin_lock+0x2a/0x40 kernel/locking/spinlock.c:152
  spin_lock include/linux/spinlock.h:317 [inline]
  xprt_destroy+0x68/0x1c0 net/sunrpc/xprt.c:1528
  xprt_destroy_kref net/sunrpc/xprt.c:1542 [inline]
  kref_put include/linux/kref.h:70 [inline]
  xprt_put+0x32/0x40 net/sunrpc/xprt.c:1566
  xprt_switch_free_entries net/sunrpc/xprtmultipath.c:124 [inline]
  xprt_switch_free net/sunrpc/xprtmultipath.c:135 [inline]
  kref_put include/linux/kref.h:70 [inline]
  xprt_switch_put+0x1ae/0x290 net/sunrpc/xprtmultipath.c:161
  rpc_free_client+0x105/0x190 net/sunrpc/clnt.c:885
  rpc_free_auth net/sunrpc/clnt.c:910 [inline]
  rpc_release_client+0xc4/0x130 net/sunrpc/clnt.c:927
  rpc_shutdown_client+0xd9/0x1a0 net/sunrpc/clnt.c:862
  rpc_create_xprt+0x2b3/0x340 net/sunrpc/clnt.c:481
  rpc_create+0x2db/0x4f0 net/sunrpc/clnt.c:587
  nfs_create_rpc_client+0x2ec/0x3b0 fs/nfs/client.c:528
  nfs_init_client fs/nfs/client.c:639 [inline]
  nfs_init_client+0x62/0xf0 fs/nfs/client.c:626
  nfs_get_client+0xdc2/0x10c0 fs/nfs/client.c:430
  nfs_init_server+0x21d/0xd20 fs/nfs/client.c:675
  nfs_create_server+0x7a/0x490 fs/nfs/client.c:958
  nfs_try_mount+0x122/0x750 fs/nfs/super.c:1879
  nfs_fs_mount+0x1530/0x2b10 fs/nfs/super.c:2692
  mount_fs+0x92/0x2a0 fs/super.c:1237
  vfs_kern_mount.part.0+0x5b/0x470 fs/namespace.c:1046
  vfs_kern_mount fs/namespace.c:1036 [inline]
  do_new_mount fs/namespace.c:2572 [inline]
  do_mount+0xe65/0x2a30 fs/namespace.c:2905
  SYSC_mount fs/namespace.c:3121 [inline]
  SyS_mount+0xa8/0x120 fs/namespace.c:3098
  do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
  entry_SYSCALL_64_after_hwframe+0x46/0xbb
irq event stamp: 781956
hardirqs last  enabled at (781956): [<ffffffff81321821>] __local_bh_enable_ip+0xc1/0x170 kernel/softirq.c:190
hardirqs last disabled at (781955): [<ffffffff813217e9>] __local_bh_enable_ip+0x89/0x170 kernel/softirq.c:167
softirqs last  enabled at (781806): [<ffffffff8760068b>] __do_softirq+0x68b/0x9ff kernel/softirq.c:314
softirqs last disabled at (781811): [<ffffffff81321920>] run_ksoftirqd+0x50/0x1a0 kernel/softirq.c:670

other info that might help us debug this:
 Possible unsafe locking scenario:

       CPU0
       ----
  lock(&(&xprt->transport_lock)->rlock);
  <Interrupt>
    lock(&(&xprt->transport_lock)->rlock);

 *** DEADLOCK ***

4 locks held by ksoftirqd/0/8:
 #0:  (rcu_read_lock){....}, at: [<ffffffff85c36e42>] __write_once_size include/linux/compiler.h:212 [inline]
 #0:  (rcu_read_lock){....}, at: [<ffffffff85c36e42>] __skb_unlink include/linux/skbuff.h:1918 [inline]
 #0:  (rcu_read_lock){....}, at: [<ffffffff85c36e42>] __skb_dequeue include/linux/skbuff.h:1934 [inline]
 #0:  (rcu_read_lock){....}, at: [<ffffffff85c36e42>] process_backlog+0x1c2/0x6f0 net/core/dev.c:5193
 #1:  (rcu_read_lock){....}, at: [<ffffffff860cca6a>] __skb_pull include/linux/skbuff.h:2151 [inline]
 #1:  (rcu_read_lock){....}, at: [<ffffffff860cca6a>] ip_local_deliver_finish+0x12a/0xab0 net/ipv4/ip_input.c:194
 #2:  (slock-AF_INET-RPC){+.-.}, at: [<ffffffff861717e8>] spin_lock include/linux/spinlock.h:317 [inline]
 #2:  (slock-AF_INET-RPC){+.-.}, at: [<ffffffff861717e8>] tcp_v4_err+0x3d8/0x1820 net/ipv4/tcp_ipv4.c:404
 #3:  (k-clock-AF_INET){++.-}, at: [<ffffffff86731df5>] xs_tcp_state_change+0x25/0x7e0 net/sunrpc/xprtsock.c:1568

stack backtrace:
CPU: 0 PID: 8 Comm: ksoftirqd/0 Not tainted 4.14.291-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 07/22/2022
Call Trace:
 __dump_stack lib/dump_stack.c:17 [inline]
 dump_stack+0x1b2/0x281 lib/dump_stack.c:58
 print_usage_bug.cold+0x42e/0x570 kernel/locking/lockdep.c:2589
 valid_state kernel/locking/lockdep.c:2602 [inline]
 mark_lock_irq kernel/locking/lockdep.c:2796 [inline]
 mark_lock+0xb4d/0x1050 kernel/locking/lockdep.c:3194
 mark_irqflags kernel/locking/lockdep.c:3072 [inline]
 __lock_acquire+0xc81/0x3f20 kernel/locking/lockdep.c:3448
 lock_acquire+0x170/0x3f0 kernel/locking/lockdep.c:3998
 __raw_spin_lock_bh include/linux/spinlock_api_smp.h:135 [inline]
 _raw_spin_lock_bh+0x2f/0x40 kernel/locking/spinlock.c:176
 spin_lock_bh include/linux/spinlock.h:322 [inline]
 xprt_disconnect_done+0x19/0x40 net/sunrpc/xprt.c:664
 xs_sock_mark_closed net/sunrpc/xprtsock.c:811 [inline]
 xs_tcp_state_change+0x3c4/0x7e0 net/sunrpc/xprtsock.c:1637
 tcp_done+0x14f/0x210 net/ipv4/tcp.c:3427
 tcp_v4_err+0x7dd/0x1820 net/ipv4/tcp_ipv4.c:523
 icmp_socket_deliver+0x1a7/0x330 net/ipv4/icmp.c:838
 icmp_unreach+0x268/0xae0 net/ipv4/icmp.c:955
 icmp_rcv+0xb7f/0x1240 net/ipv4/icmp.c:1136
 ip_local_deliver_finish+0x3f2/0xab0 net/ipv4/ip_input.c:216
 NF_HOOK include/linux/netfilter.h:250 [inline]
 ip_local_deliver+0x167/0x460 net/ipv4/ip_input.c:257
 dst_input include/net/dst.h:476 [inline]
 ip_rcv_finish+0x6e3/0x19f0 net/ipv4/ip_input.c:396
 NF_HOOK include/linux/netfilter.h:250 [inline]
 ip_rcv+0x8a7/0xf10 net/ipv4/ip_input.c:493
 __netif_receive_skb_core+0x15ee/0x2a30 net/core/dev.c:4474
 __netif_receive_skb+0x27/0x1a0 net/core/dev.c:4512
 process_backlog+0x218/0x6f0 net/core/dev.c:5195
 napi_poll net/core/dev.c:5604 [inline]
 net_rx_action+0x466/0xfd0 net/core/dev.c:5670
 __do_softirq+0x24d/0x9ff kernel/softirq.c:288
 run_ksoftirqd+0x50/0x1a0 kernel/softirq.c:670
 smpboot_thread_fn+0x5c1/0x920 kernel/smpboot.c:164
 kthread+0x30d/0x420 kernel/kthread.c:232
 ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404
EXT4-fs error (device loop3): ext4_append:77: inode #2: comm syz-executor.3: Logical block already allocated
EXT4-fs error (device loop4): ext4_append:77: inode #2: comm syz-executor.4: Logical block already allocated
overlayfs: unrecognized mount option "index=ogf" or missing value
FAT-fs (loop2): bogus number of reserved sectors
device hsr0 entered promiscuous mode
FAT-fs (loop2): Can't find a valid FAT filesystem
IPv6: ADDRCONF(NETDEV_UP): hsr0: link is not ready
IPv6: ADDRCONF(NETDEV_CHANGE): hsr0: link becomes ready
overlayfs: unrecognized mount option "index=ogf" or missing value
FAT-fs (loop2): bogus number of reserved sectors
FAT-fs (loop2): Can't find a valid FAT filesystem
device hsr0 left promiscuous mode
FAT-fs (loop1): bogus number of reserved sectors
FAT-fs (loop1): Can't find a valid FAT filesystem
FAT-fs (loop4): bogus number of reserved sectors
FAT-fs (loop4): Can't find a valid FAT filesystem
device hsr0 entered promiscuous mode
IPv6: ADDRCONF(NETDEV_UP): hsr0: link is not ready
IPv6: ADDRCONF(NETDEV_CHANGE): hsr0: link becomes ready
device hsr0 entered promiscuous mode
IPv6: ADDRCONF(NETDEV_UP): hsr0: link is not ready
IPv6: ADDRCONF(NETDEV_CHANGE): hsr0: link becomes ready
device hsr0 entered promiscuous mode
IPv6: ADDRCONF(NETDEV_UP): hsr0: link is not ready
IPv6: ADDRCONF(NETDEV_CHANGE): hsr0: link becomes ready
FAT-fs (loop4): bogus number of reserved sectors
FAT-fs (loop4): Can't find a valid FAT filesystem
FAT-fs (loop2): bogus number of reserved sectors
overlayfs: unrecognized mount option "index=ogf" or missing value
FAT-fs (loop2): Can't find a valid FAT filesystem
device hsr0 left promiscuous mode
device hsr0 entered promiscuous mode
IPv6: ADDRCONF(NETDEV_UP): hsr0: link is not ready
FAT-fs (loop1): bogus number of reserved sectors
IPv6: ADDRCONF(NETDEV_CHANGE): hsr0: link becomes ready
FAT-fs (loop1): Can't find a valid FAT filesystem
device hsr0 left promiscuous mode
device hsr0 left promiscuous mode
device hsr0 entered promiscuous mode
IPv6: ADDRCONF(NETDEV_UP): hsr0: link is not ready
IPv6: ADDRCONF(NETDEV_CHANGE): hsr0: link becomes ready
device hsr0 entered promiscuous mode
IPv6: ADDRCONF(NETDEV_UP): hsr0: link is not ready
IPv6: ADDRCONF(NETDEV_CHANGE): hsr0: link becomes ready
device hsr0 left promiscuous mode
FAT-fs (loop4): bogus number of reserved sectors
device hsr0 entered promiscuous mode
FAT-fs (loop1): bogus number of reserved sectors
IPv6: ADDRCONF(NETDEV_UP): hsr0: link is not ready
FAT-fs (loop4): Can't find a valid FAT filesystem
FAT-fs (loop1): Can't find a valid FAT filesystem
IPv6: ADDRCONF(NETDEV_CHANGE): hsr0: link becomes ready
FAT-fs (loop2): bogus number of reserved sectors
FAT-fs (loop2): Can't find a valid FAT filesystem
device hsr0 left promiscuous mode
device hsr0 entered promiscuous mode
IPv6: ADDRCONF(NETDEV_UP): hsr0: link is not ready
IPv6: ADDRCONF(NETDEV_CHANGE): hsr0: link becomes ready
device hsr0 left promiscuous mode
device hsr0 entered promiscuous mode
IPv6: ADDRCONF(NETDEV_UP): hsr0: link is not ready
IPv6: ADDRCONF(NETDEV_CHANGE): hsr0: link becomes ready
unregister_netdevice: waiting for ip6gre0 to become free. Usage count = -1
FAT-fs (loop3): bogus number of reserved sectors
FAT-fs (loop3): Can't find a valid FAT filesystem
device hsr0 entered promiscuous mode
FAT-fs (loop0): bogus number of reserved sectors
IPv6: ADDRCONF(NETDEV_UP): hsr0: link is not ready
IPv6: ADDRCONF(NETDEV_CHANGE): hsr0: link becomes ready
FAT-fs (loop0): Can't find a valid FAT filesystem
device hsr0 entered promiscuous mode
IPv6: ADDRCONF(NETDEV_UP): hsr0: link is not ready
IPv6: ADDRCONF(NETDEV_CHANGE): hsr0: link becomes ready
FAT-fs (loop3): bogus number of reserved sectors
FAT-fs (loop3): Can't find a valid FAT filesystem
device hsr0 left promiscuous mode
device hsr0 entered promiscuous mode
IPv6: ADDRCONF(NETDEV_UP): hsr0: link is not ready
IPv6: ADDRCONF(NETDEV_CHANGE): hsr0: link becomes ready
FAT-fs (loop0): bogus number of reserved sectors
FAT-fs (loop0): Can't find a valid FAT filesystem
device hsr0 left promiscuous mode
device hsr0 entered promiscuous mode
FAT-fs (loop3): bogus number of reserved sectors
FAT-fs (loop3): Can't find a valid FAT filesystem
IPv6: ADDRCONF(NETDEV_UP): hsr0: link is not ready
IPv6: ADDRCONF(NETDEV_CHANGE): hsr0: link becomes ready
device hsr0 left promiscuous mode
FAT-fs (loop5): bogus number of reserved sectors
FAT-fs (loop5): Can't find a valid FAT filesystem
device hsr0 entered promiscuous mode
IPv6: ADDRCONF(NETDEV_UP): hsr0: link is not ready
IPv6: ADDRCONF(NETDEV_CHANGE): hsr0: link becomes ready
FAT-fs (loop0): bogus number of reserved sectors
FAT-fs (loop0): Can't find a valid FAT filesystem
device hsr0 left promiscuous mode
device hsr0 entered promiscuous mode
IPv6: ADDRCONF(NETDEV_UP): hsr0: link is not ready
IPv6: ADDRCONF(NETDEV_CHANGE): hsr0: link becomes ready
device hsr0 entered promiscuous mode
IPv6: ADDRCONF(NETDEV_UP): hsr0: link is not ready
IPv6: ADDRCONF(NETDEV_CHANGE): hsr0: link becomes ready
ip_tables: iptables: counters copy to user failed while replacing table
ip_tables: iptables: counters copy to user failed while replacing table
FAT-fs (loop5): bogus number of reserved sectors
FAT-fs (loop5): Can't find a valid FAT filesystem
ip_tables: iptables: counters copy to user failed while replacing table
device hsr0 left promiscuous mode
device hsr0 entered promiscuous mode
IPv6: ADDRCONF(NETDEV_UP): hsr0: link is not ready
IPv6: ADDRCONF(NETDEV_CHANGE): hsr0: link becomes ready
FAT-fs (loop5): bogus number of reserved sectors
FAT-fs (loop5): Can't find a valid FAT filesystem
ip_tables: iptables: counters copy to user failed while replacing table
ip_tables: iptables: counters copy to user failed while replacing table
device hsr0 left promiscuous mode
device hsr0 entered promiscuous mode
ip_tables: iptables: counters copy to user failed while replacing table
IPv6: ADDRCONF(NETDEV_UP): hsr0: link is not ready
ip_tables: iptables: counters copy to user failed while replacing table
IPv6: ADDRCONF(NETDEV_CHANGE): hsr0: link becomes ready
TCP: request_sock_TCPv6: Possible SYN flooding on port 20002. Sending cookies.  Check SNMP counters.
TCP: request_sock_TCPv6: Possible SYN flooding on port 20002. Sending cookies.  Check SNMP counters.
TCP: request_sock_TCPv6: Possible SYN flooding on port 20002. Sending cookies.  Check SNMP counters.
TCP: request_sock_TCPv6: Possible SYN flooding on port 20002. Sending cookies.  Check SNMP counters.
TCP: request_sock_TCPv6: Possible SYN flooding on port 20002. Sending cookies.  Check SNMP counters.
TCP: request_sock_TCPv6: Possible SYN flooding on port 20002. Sending cookies.  Check SNMP counters.
TCP: request_sock_TCPv6: Possible SYN flooding on port 20002. Sending cookies.  Check SNMP counters.
TCP: request_sock_TCPv6: Possible SYN flooding on port 20002. Sending cookies.  Check SNMP counters.
TCP: request_sock_TCPv6: Possible SYN flooding on port 20002. Sending cookies.  Check SNMP counters.
TCP: request_sock_TCPv6: Possible SYN flooding on port 20002. Sending cookies.  Check SNMP counters.
TCP: request_sock_TCPv6: Possible SYN flooding on port 20002. Sending cookies.  Check SNMP counters.
TCP: request_sock_TCPv6: Possible SYN flooding on port 20002. Sending cookies.  Check SNMP counters.
EXT4-fs (loop2): mounted filesystem without journal. Opts: ,errors=continue
TCP: request_sock_TCPv6: Possible SYN flooding on port 20002. Sending cookies.  Check SNMP counters.

Crashes (4):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2022/08/25 11:50 linux-4.14.y e548869f356f 514514f6 .config console log report info [disk image] [vmlinux] ci2-linux-4-14 inconsistent lock state in xprt_disconnect_done
2022/08/08 15:39 linux-4.14.y b641242202ed da700653 .config console log report info ci2-linux-4-14 inconsistent lock state in xprt_disconnect_done
2022/05/23 22:29 linux-4.14.y dffb5c6ff09c e7f9308d .config console log report info ci2-linux-4-14 inconsistent lock state in xprt_disconnect_done
2022/04/26 20:59 linux-4.14.y 15a1c6b6f516 1fa34c1b .config console log report info ci2-linux-4-14 inconsistent lock state in xprt_disconnect_done
* Struck through repros no longer work on HEAD.