syzbot


inconsistent lock state in rhashtable_walk_enter

Status: closed as invalid on 2019/05/21 13:37
Subsystems: kernel
[Documentation on labels]
First crash: 2296d, last: 2296d

Sample crash report:
================================
WARNING: inconsistent lock state
5.2.0-rc1+ #1 Not tainted
--------------------------------
inconsistent {IN-SOFTIRQ-W} -> {SOFTIRQ-ON-W} usage.
syz-executor466/9166 [HC0[0]:SC0[0]:HE1:SE1] takes:
00000000d797836f (&(&crng->lock)->rlock){+.?.}, at: spin_lock include/linux/spinlock.h:338 [inline]
00000000d797836f (&(&crng->lock)->rlock){+.?.}, at: rhashtable_walk_enter+0xf9/0x390 lib/rhashtable.c:669
{IN-SOFTIRQ-W} state was registered at:
  lock_acquire+0x16f/0x3f0 kernel/locking/lockdep.c:4302
  __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
  _raw_spin_lock_irqsave+0x95/0xcd kernel/locking/spinlock.c:159
  _extract_crng+0xd8/0x270 drivers/char/random.c:1050
  extract_crng+0x5f/0x80 drivers/char/random.c:1069
  _get_random_bytes+0x168/0x400 drivers/char/random.c:1707
  get_random_bytes+0x35/0x40 drivers/char/random.c:1720
  __prandom_timer+0x68/0x110 lib/random32.c:225
  call_timer_fn+0x193/0x720 kernel/time/timer.c:1322
  expire_timers kernel/time/timer.c:1366 [inline]
  __run_timers kernel/time/timer.c:1685 [inline]
  __run_timers kernel/time/timer.c:1653 [inline]
  run_timer_softirq+0x66f/0x1740 kernel/time/timer.c:1698
  __do_softirq+0x25c/0x94c kernel/softirq.c:293
  invoke_softirq kernel/softirq.c:374 [inline]
  irq_exit+0x180/0x1d0 kernel/softirq.c:414
  exiting_irq arch/x86/include/asm/apic.h:536 [inline]
  smp_apic_timer_interrupt+0x13b/0x550 arch/x86/kernel/apic/apic.c:1067
  apic_timer_interrupt+0xf/0x20 arch/x86/entry/entry_64.S:806
  arch_local_irq_restore arch/x86/include/asm/paravirt.h:767 [inline]
  __raw_spin_unlock_irqrestore include/linux/spinlock_api_smp.h:160 [inline]
  _raw_spin_unlock_irqrestore+0x95/0xe0 kernel/locking/spinlock.c:191
  __debug_object_init+0x190/0xc30 lib/debugobjects.c:418
  debug_object_init lib/debugobjects.c:431 [inline]
  debug_object_activate+0x2b1/0x4e0 lib/debugobjects.c:512
  debug_rcu_head_queue kernel/rcu/rcu.h:176 [inline]
  __call_rcu.constprop.0+0x32/0x720 kernel/rcu/tree.c:2389
  call_rcu+0xb/0x10 kernel/rcu/tree.c:2481
  security_inode_free+0xa6/0xd0 security/security.c:908
  __destroy_inode+0x260/0x650 fs/inode.c:251
  destroy_inode+0x98/0x1c0 fs/inode.c:274
  evict+0x42e/0x680 fs/inode.c:587
  iput_final fs/inode.c:1559 [inline]
  iput+0x52b/0x8d0 fs/inode.c:1585
  dentry_unlink_inode+0x2d9/0x400 fs/dcache.c:373
  __dentry_kill+0x38b/0x600 fs/dcache.c:578
  dentry_kill+0xd7/0x5e0 fs/dcache.c:697
  shrink_dentry_list+0x2ca/0x720 fs/dcache.c:1102
  shrink_dcache_sb+0x185/0x270 fs/dcache.c:1222
  reconfigure_super+0x27e/0x920 fs/super.c:969
  do_remount fs/namespace.c:2532 [inline]
  do_mount+0x15fb/0x1c00 fs/namespace.c:3101
  ksys_mount+0xdb/0x150 fs/namespace.c:3319
  __do_sys_mount fs/namespace.c:3333 [inline]
  __se_sys_mount fs/namespace.c:3330 [inline]
  __x64_sys_mount+0xbe/0x150 fs/namespace.c:3330
  do_syscall_64+0xfd/0x680 arch/x86/entry/common.c:301
  entry_SYSCALL_64_after_hwframe+0x49/0xbe
irq event stamp: 10455
hardirqs last  enabled at (10455): [<ffffffff871c977b>] __raw_spin_unlock_irqrestore include/linux/spinlock_api_smp.h:160 [inline]
hardirqs last  enabled at (10455): [<ffffffff871c977b>] _raw_spin_unlock_irqrestore+0x6b/0xe0 kernel/locking/spinlock.c:191
hardirqs last disabled at (10454): [<ffffffff871c9a0f>] __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:108 [inline]
hardirqs last disabled at (10454): [<ffffffff871c9a0f>] _raw_spin_lock_irqsave+0x6f/0xcd kernel/locking/spinlock.c:159
softirqs last  enabled at (10444): [<ffffffff857af216>] spin_unlock_bh include/linux/spinlock.h:383 [inline]
softirqs last  enabled at (10444): [<ffffffff857af216>] release_sock+0x156/0x1c0 net/core/sock.c:2945
softirqs last disabled at (10442): [<ffffffff857af0e0>] spin_lock_bh include/linux/spinlock.h:343 [inline]
softirqs last disabled at (10442): [<ffffffff857af0e0>] release_sock+0x20/0x1c0 net/core/sock.c:2932

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

       CPU0
       ----
  lock(&(&crng->lock)->rlock);
  <Interrupt>
    lock(&(&crng->lock)->rlock);

 *** DEADLOCK ***

3 locks held by syz-executor466/9166:
 #0: 00000000e426c751 (sock_diag_mutex){+.+.}, at: sock_diag_rcv+0x1c/0x40 net/core/sock_diag.c:273
 #1: 0000000007ed3648 (sock_diag_table_mutex){+.+.}, at: __sock_diag_cmd net/core/sock_diag.c:227 [inline]
 #1: 0000000007ed3648 (sock_diag_table_mutex){+.+.}, at: sock_diag_rcv_msg+0x19d/0x410 net/core/sock_diag.c:263
 #2: 000000007bc38978 (nlk_cb_mutex-SOCK_DIAG){+.+.}, at: __netlink_dump_start+0x10c/0x7d0 net/netlink/af_netlink.c:2325

stack backtrace:
CPU: 0 PID: 9166 Comm: syz-executor466 Not tainted 5.2.0-rc1+ #1
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
 __dump_stack lib/dump_stack.c:77 [inline]
 dump_stack+0x172/0x1f0 lib/dump_stack.c:113
 print_usage_bug.cold+0x393/0x4a2 kernel/locking/lockdep.c:2934
 valid_state kernel/locking/lockdep.c:2947 [inline]
 mark_lock_irq kernel/locking/lockdep.c:3137 [inline]
 mark_lock+0xd46/0x1370 kernel/locking/lockdep.c:3512
 mark_irqflags kernel/locking/lockdep.c:3408 [inline]
 __lock_acquire+0x12df/0x5490 kernel/locking/lockdep.c:3744
 lock_acquire+0x16f/0x3f0 kernel/locking/lockdep.c:4302
 __raw_spin_lock include/linux/spinlock_api_smp.h:142 [inline]
 _raw_spin_lock+0x2f/0x40 kernel/locking/spinlock.c:151
 spin_lock include/linux/spinlock.h:338 [inline]
 rhashtable_walk_enter+0xf9/0x390 lib/rhashtable.c:669
 __tipc_dump_start+0x1fa/0x3c0 net/tipc/socket.c:3414
 tipc_dump_start+0x70/0x90 net/tipc/socket.c:3396
 __netlink_dump_start+0x4f8/0x7d0 net/netlink/af_netlink.c:2351
 netlink_dump_start include/linux/netlink.h:226 [inline]
 tipc_sock_diag_handler_dump+0x1d9/0x270 net/tipc/diag.c:91
 __sock_diag_cmd net/core/sock_diag.c:232 [inline]
 sock_diag_rcv_msg+0x319/0x410 net/core/sock_diag.c:263
 netlink_rcv_skb+0x177/0x450 net/netlink/af_netlink.c:2486
 sock_diag_rcv+0x2b/0x40 net/core/sock_diag.c:274
 netlink_unicast_kernel net/netlink/af_netlink.c:1311 [inline]
 netlink_unicast+0x531/0x710 net/netlink/af_netlink.c:1337
 netlink_sendmsg+0x8ae/0xd70 net/netlink/af_netlink.c:1926
 sock_sendmsg_nosec net/socket.c:652 [inline]
 sock_sendmsg+0xd7/0x130 net/socket.c:671
 ___sys_sendmsg+0x803/0x920 net/socket.c:2292
 __sys_sendmsg+0x105/0x1d0 net/socket.c:2330
 __do_sys_sendmsg net/socket.c:2339 [inline]
 __se_sys_sendmsg net/socket.c:2337 [inline]
 __x64_sys_sendmsg+0x78/0xb0 net/socket.c:2337
 do_syscall_64+0xfd/0x680 arch/x86/entry/common.c:301
 entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x440219
Code: 18 89 d0 c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 00 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 0f 83 fb 13 fc ff c3 66 2e 0f 1f 84 00 00 00 00
RSP: 002b:00007ffd34aa7b58 EFLAGS: 00000246 ORIG_RAX: 000000000000002e
RAX: ffffffffffffffda RBX: 00000000004002c8 RCX: 0000000000440219
RDX: 0000000000000000 RSI: 0000000020000040 RDI: 0000000000000003
RBP: 00000000006ca018 R08: 0000000000000000 R09: 00000000004002c8
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000401aa0
R13: 0000000000401b30 R14: 0000000000000000 R15: 0000000000000000

Crashes (1):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2019/05/21 04:46 upstream f49aa1de9836 8285069f .config console log report syz C ci-upstream-kasan-gce-smack-root
* Struck through repros no longer work on HEAD.