syzbot


inconsistent lock state in sync_timeline_debug_remove

Status: upstream: reported C repro on 2022/02/18 00:33
Reported-by: syzbot+92c90d4a84afd30c2cf4@syzkaller.appspotmail.com
First crash: 876d, last: 876d
Fix bisection: failed (error log, bisect log)
  
Similar bugs (5)
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
linux-6.1 inconsistent lock state in sync_timeline_debug_remove (2) 3 59d 73d 0/3 upstream: reported on 2024/05/01 22:11
linux-4.14 inconsistent lock state in sync_timeline_debug_remove C 1 510d 872d 0/1 upstream: reported C repro on 2022/02/22 17:04
linux-5.15 inconsistent lock state in sync_timeline_debug_remove origin:upstream missing-backport C error 20 56d 186d 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 335 38d 880d 0/27 upstream: reported C repro on 2022/02/14 08:30
linux-6.1 inconsistent lock state in sync_timeline_debug_remove 1 245d 245d 0/3 auto-obsoleted due to no activity on 2024/02/19 12:00

Sample crash report:
================================
WARNING: inconsistent lock state
4.19.211-syzkaller #0 Not tainted
--------------------------------
inconsistent {HARDIRQ-ON-W} -> {IN-HARDIRQ-W} usage.
syz-executor529/8102 [HC1[1]:SC0[0]:HE0:SE1] takes:
000000003fbca257 (sync_timeline_list_lock){?.+.}, at: sync_timeline_debug_remove+0x25/0x190 drivers/dma-buf/sync_debug.c:40
{HARDIRQ-ON-W} state was registered at:
  __raw_spin_unlock_irq include/linux/spinlock_api_smp.h:168 [inline]
  _raw_spin_unlock_irq+0x24/0x80 kernel/locking/spinlock.c:192
  spin_unlock_irq include/linux/spinlock.h:379 [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+0x4e0/0x11c0 fs/seq_file.c:232
  __vfs_read+0xf7/0x750 fs/read_write.c:416
  vfs_read+0x194/0x3c0 fs/read_write.c:452
  ksys_read+0x12b/0x2a0 fs/read_write.c:579
  do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
  entry_SYSCALL_64_after_hwframe+0x49/0xbe
irq event stamp: 9160
hardirqs last  enabled at (9159): [<ffffffff88195174>] __raw_spin_unlock_irq include/linux/spinlock_api_smp.h:168 [inline]
hardirqs last  enabled at (9159): [<ffffffff88195174>] _raw_spin_unlock_irq+0x24/0x80 kernel/locking/spinlock.c:192
hardirqs last disabled at (9160): [<ffffffff81003d00>] trace_hardirqs_off_thunk+0x1a/0x1c
softirqs last  enabled at (9062): [<ffffffff88400678>] __do_softirq+0x678/0x980 kernel/softirq.c:318
softirqs last disabled at (9047): [<ffffffff813927d5>] invoke_softirq kernel/softirq.c:372 [inline]
softirqs last disabled at (9047): [<ffffffff813927d5>] irq_exit+0x215/0x260 kernel/softirq.c:412

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-executor529/8102.

stack backtrace:
CPU: 1 PID: 8102 Comm: syz-executor529 Not tainted 4.19.211-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:77 [inline]
 dump_stack+0x1fc/0x2ef lib/dump_stack.c:118
 print_usage_bug.cold+0x42e/0x570 kernel/locking/lockdep.c:2545
 valid_state kernel/locking/lockdep.c:2558 [inline]
 mark_lock_irq kernel/locking/lockdep.c:2752 [inline]
 mark_lock+0xc70/0x1160 kernel/locking/lockdep.c:3132
 mark_irqflags kernel/locking/lockdep.c:3007 [inline]
 __lock_acquire+0x1077/0x3ff0 kernel/locking/lockdep.c:3373
 lock_acquire+0x170/0x3c0 kernel/locking/lockdep.c:3908
 __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
 _raw_spin_lock_irqsave+0x8c/0xc0 kernel/locking/spinlock.c:152
 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+0x31/0x40 drivers/dma-buf/sw_sync.c:125
 timeline_fence_release+0x1fe/0x2f0 drivers/dma-buf/sw_sync.c:153
 dma_fence_release+0xeb/0x330 drivers/dma-buf/dma-fence.c:228
 kref_put include/linux/kref.h:70 [inline]
 dma_fence_put include/linux/dma-fence.h:259 [inline]
 dma_fence_array_release+0x192/0x230 drivers/dma-buf/dma-fence-array.c:96
 dma_fence_release+0xeb/0x330 drivers/dma-buf/dma-fence.c:228
 kref_put include/linux/kref.h:70 [inline]
 dma_fence_put include/linux/dma-fence.h:259 [inline]
 irq_dma_fence_array_work+0x54/0x60 drivers/dma-buf/dma-fence-array.c:39
 irq_work_run_list+0x140/0x1c0 kernel/irq_work.c:164
 irq_work_run+0x4e/0xb0 kernel/irq_work.c:179
 smp_irq_work_interrupt+0x98/0x440 arch/x86/kernel/irq_work.c:21
 irq_work_interrupt+0xf/0x20 arch/x86/entry/entry_64.S:925
 </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:192
Code: c0 98 82 f1 89 48 ba 00 00 00 00 00 fc ff df 48 c1 e8 03 80 3c 10 00 75 31 48 83 3d 01 31 d8 01 00 74 25 fb 66 0f 1f 44 00 00 <bf> 01 00 00 00 e8 26 1b 28 f9 65 8b 05 9f 8d e8 77 85 c0 74 02 5d
RSP: 0018:ffff888095e47ca8 EFLAGS: 00000286 ORIG_RAX: ffffffffffffff09
RAX: 1ffffffff13e3053 RBX: ffff8880b45dbde0 RCX: 0000000000000000
RDX: dffffc0000000000 RSI: 0000000000000001 RDI: ffff8880b2596d84
RBP: ffff8880b45dbe50 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000000 R12: dffffc0000000000
R13: ffff8880b45dbe40 R14: ffff8880b45dbe00 R15: 0000000000000000
 spin_unlock_irq include/linux/spinlock.h:379 [inline]
 sw_sync_debugfs_release+0x14a/0x1b0 drivers/dma-buf/sw_sync.c:330
 __fput+0x2ce/0x890 fs/file_table.c:278
 task_work_run+0x148/0x1c0 kernel/task_work.c:113
 exit_task_work include/linux/task_work.h:22 [inline]
 do_exit+0xbf3/0x2be0 kernel/exit.c:870
 do_group_exit+0x125/0x310 kernel/exit.c:967
 __do_sys_exit_group kernel/exit.c:978 [inline]
 __se_sys_exit_group kernel/exit.c:976 [inline]
 __x64_sys_exit_group+0x3a/0x50 kernel/exit.c:976
 do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
 entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x7f9365a68ed9

----------------
Code disassembly (best guess), 5 bytes skipped:
   0:	48 ba 00 00 00 00 00 	movabs $0xdffffc0000000000,%rdx
   7:	fc ff df
   a:	48 c1 e8 03          	shr    $0x3,%rax
   e:	80 3c 10 00          	cmpb   $0x0,(%rax,%rdx,1)
  12:	75 31                	jne    0x45
  14:	48 83 3d 01 31 d8 01 	cmpq   $0x0,0x1d83101(%rip)        # 0x1d8311d
  1b:	00
  1c:	74 25                	je     0x43
  1e:	fb                   	sti
  1f:	66 0f 1f 44 00 00    	nopw   0x0(%rax,%rax,1)
* 25:	bf 01 00 00 00       	mov    $0x1,%edi <-- trapping instruction
  2a:	e8 26 1b 28 f9       	callq  0xf9281b55
  2f:	65 8b 05 9f 8d e8 77 	mov    %gs:0x77e88d9f(%rip),%eax        # 0x77e88dd5
  36:	85 c0                	test   %eax,%eax
  38:	74 02                	je     0x3c
  3a:	5d                   	pop    %rbp

Crashes (1):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2022/02/18 00:32 linux-4.19.y 3f8a27f9e27b 3cd800e4 .config console log report syz C ci2-linux-4-19 inconsistent lock state in sync_timeline_debug_remove
* Struck through repros no longer work on HEAD.