syzbot


inconsistent lock state in sync_timeline_debug_remove

Status: upstream: reported C repro on 2022/02/22 17:04
Reported-by: syzbot+5f940166cd8f78936b86@syzkaller.appspotmail.com
First crash: 793d, last: 431d
Similar bugs (4)
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
linux-5.15 inconsistent lock state in sync_timeline_debug_remove origin:upstream C 14 5d13h 107d 0/3 upstream: reported C repro on 2024/01/09 18:24
upstream inconsistent lock state in sync_timeline_debug_remove dri media C inconclusive 231 1h41m 801d 0/26 upstream: reported C repro on 2022/02/14 08:30
linux-4.19 inconsistent lock state in sync_timeline_debug_remove C error 1 798d 798d 0/1 upstream: reported C repro on 2022/02/18 00:33
linux-6.1 inconsistent lock state in sync_timeline_debug_remove 1 166d 166d 0/3 auto-obsoleted due to no activity on 2024/02/19 12:00
Fix bisection attempts (10)
Created Duration User Patch Repo Result
2023/02/19 21:06 28m bisect fix linux-4.14.y job log (0) log
2023/01/20 13:51 24m bisect fix linux-4.14.y job log (0) log
2022/10/27 21:47 28m bisect fix linux-4.14.y job log (0) log
2022/09/20 20:55 24m bisect fix linux-4.14.y job log (0) log
2022/08/21 20:30 25m bisect fix linux-4.14.y job log (0) log
2022/07/22 20:06 23m bisect fix linux-4.14.y job log (0) log
2022/06/22 19:40 25m bisect fix linux-4.14.y job log (0) log
2022/05/23 19:12 28m bisect fix linux-4.14.y job log (0) log
2022/04/23 18:50 21m bisect fix linux-4.14.y job log (0) log
2022/03/24 18:20 27m bisect fix linux-4.14.y job log (0) log

Sample crash report:
================================
WARNING: inconsistent lock state
4.14.267-syzkaller #0 Not tainted
--------------------------------
inconsistent {HARDIRQ-ON-W} -> {IN-HARDIRQ-W} usage.
syz-executor152/7972 [HC1[1]:SC0[0]:HE0:SE1] takes:
 (sync_timeline_list_lock){?.+.}, at: [<ffffffff8399e885>] sync_timeline_debug_remove+0x25/0x190 drivers/dma-buf/sync_debug.c:40
{HARDIRQ-ON-W} state was registered at:
  __trace_hardirqs_on_caller kernel/locking/lockdep.c:2875 [inline]
  trace_hardirqs_on_caller+0x288/0x580 kernel/locking/lockdep.c:2930
  __raw_spin_unlock_irq include/linux/spinlock_api_smp.h:168 [inline]
  _raw_spin_unlock_irq+0x24/0x80 kernel/locking/spinlock.c:200
  spin_unlock_irq include/linux/spinlock.h:367 [inline]
  sync_print_obj drivers/dma-buf/sync_debug.c:127 [inline]
  sync_debugfs_show+0xeb/0x200 drivers/dma-buf/sync_debug.c:162
  seq_read+0x4e4/0x1180 fs/seq_file.c:240
  __vfs_read+0xe4/0x620 fs/read_write.c:411
  vfs_read+0x139/0x340 fs/read_write.c:447
  SYSC_read fs/read_write.c:574 [inline]
  SyS_read+0xf2/0x210 fs/read_write.c:567
  do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
  entry_SYSCALL_64_after_hwframe+0x46/0xbb
irq event stamp: 9166
hardirqs last  enabled at (9165): [<ffffffff87242b74>] __raw_spin_unlock_irq include/linux/spinlock_api_smp.h:168 [inline]
hardirqs last  enabled at (9165): [<ffffffff87242b74>] _raw_spin_unlock_irq+0x24/0x80 kernel/locking/spinlock.c:200
hardirqs last disabled at (9166): [<ffffffff87401eee>] irq_work_interrupt+0x8e/0xa0 arch/x86/entry/entry_64.S:824
softirqs last  enabled at (4510): [<ffffffff8760068b>] __do_softirq+0x68b/0x9ff kernel/softirq.c:314
softirqs last disabled at (4489): [<ffffffff81321d13>] invoke_softirq kernel/softirq.c:368 [inline]
softirqs last disabled at (4489): [<ffffffff81321d13>] irq_exit+0x193/0x240 kernel/softirq.c:409

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 ***

no locks held by syz-executor152/7972.

stack backtrace:
CPU: 0 PID: 7972 Comm: syz-executor152 Not tainted 4.14.267-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
 <IRQ>
 __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:3069 [inline]
 __lock_acquire+0xfb2/0x3f20 kernel/locking/lockdep.c:3448
 lock_acquire+0x170/0x3f0 kernel/locking/lockdep.c:3998
 __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
 _raw_spin_lock_irqsave+0x8c/0xc0 kernel/locking/spinlock.c:160
 sync_timeline_debug_remove+0x25/0x190 drivers/dma-buf/sync_debug.c:40
 sync_timeline_free drivers/dma-buf/sw_sync.c:113 [inline]
 kref_put include/linux/kref.h:70 [inline]
 sync_timeline_put+0x22/0x30 drivers/dma-buf/sw_sync.c:125
 timeline_fence_release+0x1ec/0x2d0 drivers/dma-buf/sw_sync.c:153
 dma_fence_release+0xd1/0x320 drivers/dma-buf/dma-fence.c:178
 kref_put include/linux/kref.h:70 [inline]
 dma_fence_put include/linux/dma-fence.h:197 [inline]
 dma_fence_array_release+0x162/0x1f0 drivers/dma-buf/dma-fence-array.c:96
 dma_fence_release+0xd1/0x320 drivers/dma-buf/dma-fence.c:178
 kref_put include/linux/kref.h:70 [inline]
 dma_fence_put include/linux/dma-fence.h:197 [inline]
 irq_dma_fence_array_work+0x46/0x50 drivers/dma-buf/dma-fence-array.c:39
 irq_work_run_list+0xf0/0x160 kernel/irq_work.c:156
 irq_work_run+0x4e/0xc0 kernel/irq_work.c:171
 smp_irq_work_interrupt+0xa3/0x4e0 arch/x86/kernel/irq_work.c:21
 irq_work_interrupt+0x93/0xa0 arch/x86/entry/entry_64.S:824
 </IRQ>
RIP: 0010:__raw_spin_unlock_irq include/linux/spinlock_api_smp.h:169 [inline]
RIP: 0010:_raw_spin_unlock_irq+0x50/0x80 kernel/locking/spinlock.c:200
RSP: 0018:ffff888091557ca0 EFLAGS: 00000282 ORIG_RAX: ffffffffffffff09
RAX: 1ffffffff11e127b RBX: ffff8880ab91efe0 RCX: 0000000000000000
RDX: dffffc0000000000 RSI: 0000000000000001 RDI: ffff8880b4952b84
RBP: ffff8880ab91f050 R08: ffff88823fff7018 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000000 R12: dffffc0000000000
R13: ffff8880ab91f040 R14: ffff8880ab91f000 R15: ffff8880ab91f050
 spin_unlock_irq include/linux/spinlock.h:367 [inline]
 sw_sync_debugfs_release+0x12c/0x1a0 drivers/dma-buf/sw_sync.c:331
 __fput+0x25f/0x7a0 fs/file_table.c:210
 task_work_run+0x11f/0x190 kernel/task_work.c:113
 exit_task_work include/linux/task_work.h:22 [inline]
 do_exit+0xa44/0x2850 kernel/exit.c:868
 do_group_exit+0x100/0x2e0 kernel/exit.c:965
 SYSC_exit_group kernel/exit.c:976 [inline]
 SyS_exit_group+0x19/0x20 kernel/exit.c:974
 do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
 entry_SYSCALL_64_after_hwframe+0x46/0xbb
RIP: 0033:0x7f87f8bd5ed9
RSP: 002b:00007ffce1e6bef8 EFLAGS: 00000246 ORIG_RAX: 00000000000000e7
RAX: ffffffffffffffda RBX: 00007f87f8c4a2b0 RCX: 00007f87f8bd5ed9
RDX: 000000000000003c RSI: 00000000000000e7 RDI: 0000000000000000
RBP: 000000000

Crashes (1):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2022/02/22 17:03 linux-4.14.y a35d65bedfbc 6e821dbf .config console log report syz C ci2-linux-4-14 inconsistent lock state in sync_timeline_debug_remove
* Struck through repros no longer work on HEAD.