syzbot


inconsistent lock state in mark_held_locks

Status: upstream: reported on 2022/10/24 11:49
Reported-by: syzbot+aae240bc16b45a710af3@syzkaller.appspotmail.com
First crash: 107d, last: 92d
similar bugs (1):
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
upstream inconsistent lock state in mark_held_locks 2 85d 82d 0/24 upstream: reported on 2022/11/18 16:59

Sample crash report:
================================
WARNING: inconsistent lock state
4.19.211-syzkaller #0 Not tainted
--------------------------------
inconsistent {IN-HARDIRQ-W} -> {HARDIRQ-ON-W} usage.
syz-executor.5/22019 [HC0[0]:SC0[0]:HE1:SE1] takes:
0000000048b63cdc (sync_timeline_list_lock){?...}, at: spin_lock_irq include/linux/spinlock.h:354 [inline]
0000000048b63cdc (sync_timeline_list_lock){?...}, at: sync_debugfs_show+0x2d/0x200 drivers/dma-buf/sync_debug.c:156
{IN-HARDIRQ-W} state was registered at:
  __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
  arch_local_irq_enable arch/x86/include/asm/paravirt.h:799 [inline]
  __raw_spin_unlock_irq include/linux/spinlock_api_smp.h:168 [inline]
  _raw_spin_unlock_irq+0x50/0x80 kernel/locking/spinlock.c:192
  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
  get_signal+0x3f2/0x1f70 kernel/signal.c:2589
  do_signal+0x8f/0x1670 arch/x86/kernel/signal.c:799
  exit_to_usermode_loop+0x204/0x2a0 arch/x86/entry/common.c:163
  prepare_exit_to_usermode arch/x86/entry/common.c:198 [inline]
  syscall_return_slowpath arch/x86/entry/common.c:271 [inline]
  do_syscall_64+0x538/0x620 arch/x86/entry/common.c:296
  entry_SYSCALL_64_after_hwframe+0x49/0xbe
irq event stamp: 74
hardirqs last  enabled at (73): [<ffffffff881950e9>] __raw_spin_unlock_irqrestore include/linux/spinlock_api_smp.h:160 [inline]
hardirqs last  enabled at (73): [<ffffffff881950e9>] _raw_spin_unlock_irqrestore+0x79/0xe0 kernel/locking/spinlock.c:184
hardirqs last disabled at (74): [<ffffffff88194e05>] __raw_spin_lock_irq include/linux/spinlock_api_smp.h:126 [inline]
hardirqs last disabled at (74): [<ffffffff88194e05>] _raw_spin_lock_irq+0x35/0x80 kernel/locking/spinlock.c:160
softirqs last  enabled at (0): [<ffffffff81370d39>] copy_process.part.0+0x15b9/0x8260 kernel/fork.c:1856
softirqs last disabled at (0): [<0000000000000000>]           (null)

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

2 locks held by syz-executor.5/22019:
 #0: 00000000c02acd05 (&p->lock){+.+.}, at: seq_read+0x6b/0x11c0 fs/seq_file.c:164
 #1: 0000000048b63cdc (sync_timeline_list_lock){?...}, at: spin_lock_irq include/linux/spinlock.h:354 [inline]
 #1: 0000000048b63cdc (sync_timeline_list_lock){?...}, at: sync_debugfs_show+0x2d/0x200 drivers/dma-buf/sync_debug.c:156

stack backtrace:
CPU: 0 PID: 22019 Comm: syz-executor.5 Not tainted 4.19.211-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 10/26/2022
Call Trace:
 __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_held_locks+0xa6/0xf0 kernel/locking/lockdep.c:2810
 __trace_hardirqs_on_caller kernel/locking/lockdep.c:2831 [inline]
 lockdep_hardirqs_on+0x288/0x5c0 kernel/locking/lockdep.c:2884
 __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
 traverse.part.0+0xcf/0x5f0 fs/seq_file.c:116
 traverse fs/seq_file.c:106 [inline]
 seq_read+0x99d/0x11c0 fs/seq_file.c:191
 do_loop_readv_writev fs/read_write.c:701 [inline]
 do_loop_readv_writev fs/read_write.c:688 [inline]
 do_iter_read+0x471/0x630 fs/read_write.c:925
 vfs_readv+0xe5/0x150 fs/read_write.c:987
 do_preadv fs/read_write.c:1071 [inline]
 __do_sys_preadv fs/read_write.c:1121 [inline]
 __se_sys_preadv fs/read_write.c:1116 [inline]
 __x64_sys_preadv+0x22b/0x310 fs/read_write.c:1116
 do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
 entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x7fbe42f02639
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:00007fbe41475168 EFLAGS: 00000246 ORIG_RAX: 0000000000000127
RAX: ffffffffffffffda RBX: 00007fbe43022f80 RCX: 00007fbe42f02639
RDX: 0000000000000001 RSI: 00000000200001c0 RDI: 0000000000000003
RBP: 00007fbe42f5d7e1 R08: 0000000000000101 R09: 0000000000000000
R10: 0000000000000101 R11: 0000000000000246 R12: 0000000000000000
R13: 00007fffef96db0f R14: 00007fbe41475300 R15: 0000000000022000
print_req_error: 986 callbacks suppressed
print_req_error: I/O error, dev nbd5, sector 0
block nbd4: Device being setup by another task
buffer_io_error: 986 callbacks suppressed
Buffer I/O error on dev nbd5, logical block 0, async page read
print_req_error: I/O error, dev nbd5, sector 2
Buffer I/O error on dev nbd5, logical block 1, async page read
print_req_error: I/O error, dev nbd5, sector 4
Buffer I/O error on dev nbd5, logical block 2, async page read
print_req_error: I/O error, dev nbd5, sector 6
Buffer I/O error on dev nbd5, logical block 3, async page read
print_req_error: I/O error, dev nbd5, sector 0
Buffer I/O error on dev nbd5, logical block 0, async page read
print_req_error: I/O error, dev nbd5, sector 2
Buffer I/O error on dev nbd5, logical block 1, async page read
print_req_error: I/O error, dev nbd5, sector 4
audit: type=1804 audit(1667937790.188:78): pid=22043 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.0" name="/root/syzkaller-testdir1875502379/syzkaller.kDwUrd/3567/bus" dev="sda1" ino=16296 res=1
Buffer I/O error on dev nbd5, logical block 2, async page read
print_req_error: I/O error, dev nbd5, sector 6
Buffer I/O error on dev nbd5, logical block 3, async page read
print_req_error: I/O error, dev nbd5, sector 0
Buffer I/O error on dev nbd5, logical block 0, async page read
print_req_error: I/O error, dev nbd5, sector 2
Buffer I/O error on dev nbd5, logical block 1, async page read
ldm_validate_partition_table(): Disk read failed.
Dev nbd5: unable to read RDB block 0
 nbd5: unable to read partition table
nbd5: partition table beyond EOD, truncated
block nbd4: Device being setup by another task
audit: type=1804 audit(1667937790.218:79): pid=22043 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.0" name="/root/syzkaller-testdir1875502379/syzkaller.kDwUrd/3567/bus" dev="sda1" ino=16296 res=1
block nbd1: Device being setup by another task
audit: type=1804 audit(1667937790.218:80): pid=22043 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.0" name="/root/syzkaller-testdir1875502379/syzkaller.kDwUrd/3567/bus" dev="sda1" ino=16296 res=1
block nbd1: Device being setup by another task
ldm_validate_partition_table(): Disk read failed.
Dev nbd5: unable to read RDB block 0
 nbd5: unable to read partition table
audit: type=1804 audit(1667937790.218:81): pid=22043 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.0" name="/root/syzkaller-testdir1875502379/syzkaller.kDwUrd/3567/bus" dev="sda1" ino=16296 res=1
nbd5: partition table beyond EOD, truncated
block nbd1: Device being setup by another task
audit: type=1804 audit(1667937790.218:82): pid=22043 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.0" name="/root/syzkaller-testdir1875502379/syzkaller.kDwUrd/3567/bus" dev="sda1" ino=16296 res=1
block nbd1: Device being setup by another task
audit: type=1804 audit(1667937790.218:83): pid=22043 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.0" name="/root/syzkaller-testdir1875502379/syzkaller.kDwUrd/3567/bus" dev="sda1" ino=16296 res=1
ldm_validate_partition_table(): Disk read failed.
audit: type=1804 audit(1667937790.218:84): pid=22043 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.0" name="/root/syzkaller-testdir1875502379/syzkaller.kDwUrd/3567/bus" dev="sda1" ino=16296 res=1
Dev nbd5: unable to read RDB block 0
 nbd5: unable to read partition table
audit: type=1804 audit(1667937790.218:85): pid=22043 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.0" name="/root/syzkaller-testdir1875502379/syzkaller.kDwUrd/3567/bus" dev="sda1" ino=16296 res=1
nbd5: partition table beyond EOD, truncated
audit: type=1804 audit(1667937790.218:86): pid=22043 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.0" name="/root/syzkaller-testdir1875502379/syzkaller.kDwUrd/3567/bus" dev="sda1" ino=16296 res=1
block nbd1: Device being setup by another task
caif:caif_disconnect_client(): nothing to disconnect
caif:caif_disconnect_client(): nothing to disconnect
caif:caif_disconnect_client(): nothing to disconnect
block nbd3: Device being setup by another task
ldm_validate_partition_table(): Disk read failed.
Dev nbd5: unable to read RDB block 0
 nbd5: unable to read partition table
nbd5: partition table beyond EOD, truncated
ldm_validate_partition_table(): Disk read failed.
block nbd4: Device being setup by another task
Dev nbd5: unable to read RDB block 0
 nbd5: unable to read partition table
nbd5: partition table beyond EOD, truncated
block nbd4: Device being setup by another task
ldm_validate_partition_table(): Disk read failed.
Dev nbd5: unable to read RDB block 0
 nbd5: unable to read partition table
nbd5: partition table beyond EOD, truncated
block nbd1: server does not support multiple connections per device.
block nbd4: Device being setup by another task
Unknown ioctl -1068991484
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
Unknown ioctl -1068991484
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
block nbd1: server does not support multiple connections per device.
Unknown ioctl -1068991484
block nbd1: server does not support multiple connections per device.
Unknown ioctl -1068991484
print_req_error: 350 callbacks suppressed
print_req_error: I/O error, dev nbd5, sector 0
buffer_io_error: 350 callbacks suppressed
Buffer I/O error on dev nbd5, logical block 0, async page read
print_req_error: I/O error, dev nbd5, sector 2
Buffer I/O error on dev nbd5, logical block 1, async page read
print_req_error: I/O error, dev nbd5, sector 4
Buffer I/O error on dev nbd5, logical block 2, async page read
print_req_error: I/O error, dev nbd5, sector 6
Buffer I/O error on dev nbd5, logical block 3, async page read
print_req_error: I/O error, dev nbd5, sector 0
Buffer I/O error on dev nbd5, logical block 0, async page read
print_req_error: I/O error, dev nbd5, sector 2
Buffer I/O error on dev nbd5, logical block 1, async page read
print_req_error: I/O error, dev nbd5, sector 4
Buffer I/O error on dev nbd5, logical block 2, async page read
print_req_error: I/O error, dev nbd5, sector 6
Buffer I/O error on dev nbd5, logical block 3, async page read
print_req_error: I/O error, dev nbd5, sector 0
Buffer I/O error on dev nbd5, logical block 0, async page read
print_req_error: I/O error, dev nbd5, sector 2
Buffer I/O error on dev nbd5, logical block 1, async page read
ldm_validate_partition_table(): Disk read failed.
Dev nbd5: unable to read RDB block 0
 nbd5: unable to read partition table
nbd5: partition table beyond EOD, truncated
ldm_validate_partition_table(): Disk read failed.
Dev nbd5: unable to read RDB block 0
 nbd5: unable to read partition table
nbd5: partition table beyond EOD, truncated
ldm_validate_partition_table(): Disk read failed.
Dev nbd5: unable to read RDB block 0
 nbd5: unable to read partition table
nbd5: partition table beyond EOD, truncated
block nbd4: Device being setup by another task
block nbd4: Device being setup by another task
block nbd4: Device being setup by another task
block nbd4: Device being setup by another task
ldm_validate_partition_table(): Disk read failed.
Dev nbd5: unable to read RDB block 0
 nbd5: unable to read partition table
nbd5: partition table beyond EOD, truncated
ldm_validate_partition_table(): Disk read failed.
Dev nbd5: unable to read RDB block 0
 nbd5: unable to read partition table
nbd5: partition table beyond EOD, truncated
ldm_validate_partition_table(): Disk read failed.
Dev nbd5: unable to read RDB block 0
 nbd5: unable to read partition table
nbd5: partition table beyond EOD, truncated
ldm_validate_partition_table(): Disk read failed.
Dev nbd5: unable to read RDB block 0
 nbd5: unable to read partition table
nbd5: partition table beyond EOD, truncated
block nbd4: Device being setup by another task
block nbd4: Device being setup by another task

Crashes (2):
Manager Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets Title
ci2-linux-4-19 2022/11/08 20:03 linux-4.19.y 3f8a27f9e27b 060f945e .config console log report info [disk image] [vmlinux] inconsistent lock state in mark_held_locks
ci2-linux-4-19 2022/10/24 11:49 linux-4.19.y 3f8a27f9e27b faae2fda .config console log report info [disk image] [vmlinux] inconsistent lock state in mark_held_locks
* Struck through repros no longer work on HEAD.