syzbot


inconsistent lock state in sync_info_debugfs_show
Status: upstream: reported on 2022/01/27 16:33
Reported-by: syzbot+007bfe0f3330f6e1e7d1@syzkaller.appspotmail.com
First crash: 124d, last: 28d

Sample crash report:
================================
WARNING: inconsistent lock state
5.18.0-rc4-syzkaller-00083-g259b897e5a79 #0 Not tainted
--------------------------------
inconsistent {IN-HARDIRQ-W} -> {HARDIRQ-ON-W} usage.
syz-executor.5/8079 [HC0[0]:SC0[0]:HE0:SE1] takes:
ffffffff8d2f4018 (sync_timeline_list_lock){?...}-{2:2}, at: spin_lock_irq include/linux/spinlock.h:374 [inline]
ffffffff8d2f4018 (sync_timeline_list_lock){?...}-{2:2}, at: sync_info_debugfs_show+0x90/0x510 drivers/dma-buf/sync_debug.c:147
{IN-HARDIRQ-W} state was registered at:
  lock_acquire+0x1a7/0x400 kernel/locking/lockdep.c:5641
  __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
  _raw_spin_lock_irqsave+0xd1/0x120 kernel/locking/spinlock.c:162
  sync_timeline_debug_remove+0x28/0x140 drivers/dma-buf/sync_debug.c:31
  sync_timeline_free drivers/dma-buf/sw_sync.c:104 [inline]
  kref_put include/linux/kref.h:65 [inline]
  sync_timeline_put drivers/dma-buf/sw_sync.c:116 [inline]
  timeline_fence_release+0x200/0x250 drivers/dma-buf/sw_sync.c:144
  kref_put include/linux/kref.h:65 [inline]
  dma_fence_put include/linux/dma-fence.h:276 [inline]
  dma_fence_array_release+0x134/0x240 drivers/dma-buf/dma-fence-array.c:120
  irq_work_single+0xd3/0x240 kernel/irq_work.c:211
  irq_work_run_list kernel/irq_work.c:242 [inline]
  irq_work_run+0x189/0x350 kernel/irq_work.c:251
  __sysvec_irq_work+0x62/0x70 arch/x86/kernel/irq_work.c:22
  sysvec_irq_work+0x8c/0xb0 arch/x86/kernel/irq_work.c:17
  asm_sysvec_irq_work+0x12/0x20
  __raw_spin_unlock_irq include/linux/spinlock_api_smp.h:160 [inline]
  _raw_spin_unlock_irq+0x25/0x40 kernel/locking/spinlock.c:202
  spin_unlock_irq include/linux/spinlock.h:399 [inline]
  sw_sync_debugfs_release+0x14d/0x1d0 drivers/dma-buf/sw_sync.c:321
  __fput+0x3b9/0x820 fs/file_table.c:317
  task_work_run+0x146/0x1c0 kernel/task_work.c:164
  resume_user_mode_work include/linux/resume_user_mode.h:49 [inline]
  exit_to_user_mode_loop+0x134/0x160 kernel/entry/common.c:169
  exit_to_user_mode_prepare+0xad/0x110 kernel/entry/common.c:201
  __syscall_exit_to_user_mode_work kernel/entry/common.c:283 [inline]
  syscall_exit_to_user_mode+0x2e/0x70 kernel/entry/common.c:294
  entry_SYSCALL_64_after_hwframe+0x44/0xae
irq event stamp: 156
hardirqs last  enabled at (155): [<ffffffff81d60f8c>] ___slab_alloc+0xb7c/0xcd0 mm/slub.c:2961
hardirqs last disabled at (156): [<ffffffff8a2136f9>] __raw_spin_lock_irq include/linux/spinlock_api_smp.h:117 [inline]
hardirqs last disabled at (156): [<ffffffff8a2136f9>] _raw_spin_lock_irq+0xa9/0x110 kernel/locking/spinlock.c:170
softirqs last  enabled at (0): [<ffffffff814ec0b5>] copy_process+0x1445/0x3f70 kernel/fork.c:2179
softirqs last disabled at (0): [<0000000000000000>] 0x0

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

       CPU0
       ----
  lock(sync_timeline_list_lock);
  <Interrupt>
    lock(sync_timeline_list_lock);

 *** DEADLOCK ***

3 locks held by syz-executor.5/8079:
 #0: ffff8880792c1268 (&f->f_pos_lock){+.+.}-{3:3}, at: __fdget_pos+0x247/0x2e0 fs/file.c:1063
 #1: ffff88807552d9e0 (&p->lock){+.+.}-{3:3}, at: seq_read_iter+0xad/0xd30 fs/seq_file.c:182
 #2: ffffffff8d2f4018 (sync_timeline_list_lock){?...}-{2:2}, at: spin_lock_irq include/linux/spinlock.h:374 [inline]
 #2: ffffffff8d2f4018 (sync_timeline_list_lock){?...}-{2:2}, at: sync_info_debugfs_show+0x90/0x510 drivers/dma-buf/sync_debug.c:147

stack backtrace:
CPU: 1 PID: 8079 Comm: syz-executor.5 Not tainted 5.18.0-rc4-syzkaller-00083-g259b897e5a79 #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
 <TASK>
 __dump_stack lib/dump_stack.c:88 [inline]
 dump_stack_lvl+0x1e3/0x2cb lib/dump_stack.c:106
 mark_lock_irq+0xb20/0xf00
 mark_lock+0x21c/0x350 kernel/locking/lockdep.c:4607
 mark_held_locks kernel/locking/lockdep.c:4208 [inline]
 __trace_hardirqs_on_caller kernel/locking/lockdep.c:4226 [inline]
 lockdep_hardirqs_on_prepare+0x280/0x7b0 kernel/locking/lockdep.c:4294
 trace_hardirqs_on+0x6f/0x80 kernel/trace/trace_preemptirq.c:49
 __raw_spin_unlock_irq include/linux/spinlock_api_smp.h:159 [inline]
 _raw_spin_unlock_irq+0x1f/0x40 kernel/locking/spinlock.c:202
 spin_unlock_irq include/linux/spinlock.h:399 [inline]
 sync_print_obj drivers/dma-buf/sync_debug.c:118 [inline]
 sync_info_debugfs_show+0x17e/0x510 drivers/dma-buf/sync_debug.c:153
 seq_read_iter+0x43a/0xd30 fs/seq_file.c:230
 seq_read+0x3d4/0x500 fs/seq_file.c:162
 vfs_read+0x2ea/0xd10 fs/read_write.c:480
 ksys_read+0x19b/0x2c0 fs/read_write.c:620
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x2b/0x70 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7f341f8890e9
Code: ff ff c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 40 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 73 01 c3 48 c7 c1 b8 ff ff ff f7 d8 64 89 01 48
RSP: 002b:00007f3420a93168 EFLAGS: 00000246 ORIG_RAX: 0000000000000000
RAX: ffffffffffffffda RBX: 00007f341f99bf60 RCX: 00007f341f8890e9
RDX: 0000000000002020 RSI: 0000000020001a00 RDI: 0000000000000004
RBP: 00007f341f8e308d R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 00007ffe30709bcf R14: 00007f3420a93300 R15: 0000000000022000
 </TASK>

Crashes (11):
Manager Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Title
ci-upstream-kasan-gce-smack-root 2022/04/28 20:40 upstream 259b897e5a79 e9076525 .config log report info inconsistent lock state in sync_info_debugfs_show
ci-upstream-kasan-gce-smack-root 2022/04/25 22:40 upstream d615b5416f8a 152baedd .config log report info inconsistent lock state in sync_info_debugfs_show
ci-upstream-kasan-gce-root 2022/04/18 22:26 upstream b2d229d4ddb1 8bcc32a6 .config log report info inconsistent lock state in sync_info_debugfs_show
ci-upstream-kasan-gce-selinux-root 2022/03/17 22:02 upstream 551acdc3c3d2 e2d91b1d .config log report info inconsistent lock state in sync_info_debugfs_show
ci-upstream-kasan-gce-root 2022/03/04 03:05 upstream 38f80f42147f 45a13a73 .config log report info inconsistent lock state in sync_info_debugfs_show
ci-qemu-upstream 2022/02/14 08:37 upstream 754e0b0e3560 8b9ca619 .config log report info inconsistent lock state in sync_info_debugfs_show
ci-upstream-kasan-gce-selinux-root 2022/01/23 16:24 upstream 1c52283265a4 214351e1 .config log report info inconsistent lock state in sync_info_debugfs_show
ci-qemu-upstream-386 2022/02/16 11:00 upstream c5d9ae265b10 8b9ca619 .config log report info inconsistent lock state in sync_info_debugfs_show
ci-qemu-upstream-386 2022/02/14 09:50 upstream 754e0b0e3560 8b9ca619 .config log report info inconsistent lock state in sync_info_debugfs_show
ci-qemu-upstream-386 2022/02/12 13:16 upstream 83e396641110 8b9ca619 .config log report info inconsistent lock state in sync_info_debugfs_show
ci-upstream-linux-next-kasan-gce-root 2022/02/17 19:26 linux-next ef6b35306dd8 3cd800e4 .config log report info inconsistent lock state in sync_info_debugfs_show