syzbot


inconsistent lock state in io_file_data_ref_zero

Status: fixed on 2021/03/10 01:48
Subsystems: fs
[Documentation on labels]
Reported-by: syzbot+1f4ba1e5520762c523c6@syzkaller.appspotmail.com
Fix commit: ac0648a56c1f io_uring: use bottom half safe lock for fixed file data
First crash: 1214d, last: 1187d
Cause bisection: introduced by (bisect log) :
commit dcd479e10a0510522a5d88b29b8f79ea3467d501
Author: Johannes Berg <johannes.berg@intel.com>
Date: Fri Oct 9 12:17:11 2020 +0000

  mac80211: always wind down STA state

Crash: BUG: sleeping function called from invalid context in sta_info_move_state (log)
Repro: C syz .config
  
Discussions (2)
Title Replies (including bot) Last reply
[PATCH 5.10 00/63] 5.10.5-rc1 review 75 (75) 2021/01/07 08:13
inconsistent lock state in io_file_data_ref_zero 1 (2) 2020/11/23 16:37

Sample crash report:
================================
WARNING: inconsistent lock state
5.10.0-rc4-syzkaller #0 Not tainted
--------------------------------
inconsistent {SOFTIRQ-ON-W} -> {IN-SOFTIRQ-W} usage.
kworker/1:3/8675 [HC0[0]:SC1[1]:HE1:SE0] takes:
ffff888140dd94a8 (&file_data->lock){+.?.}-{2:2}, at: spin_lock include/linux/spinlock.h:354 [inline]
ffff888140dd94a8 (&file_data->lock){+.?.}-{2:2}, at: io_file_data_ref_zero+0x6a/0x3a0 fs/io_uring.c:7361
{SOFTIRQ-ON-W} state was registered at:
  lock_acquire+0x114/0x5e0 kernel/locking/lockdep.c:5435
  __raw_spin_lock include/linux/spinlock_api_smp.h:142 [inline]
  _raw_spin_lock+0x2a/0x40 kernel/locking/spinlock.c:151
  spin_lock include/linux/spinlock.h:354 [inline]
  io_sqe_files_register fs/io_uring.c:7496 [inline]
  __io_uring_register fs/io_uring.c:9660 [inline]
  __do_sys_io_uring_register fs/io_uring.c:9750 [inline]
  __se_sys_io_uring_register+0x3aee/0x3f90 fs/io_uring.c:9732
  do_syscall_64+0x2d/0x70 arch/x86/entry/common.c:46
  entry_SYSCALL_64_after_hwframe+0x44/0xa9
irq event stamp: 40498
hardirqs last  enabled at (40498): [<ffffffff8940613e>] __raw_spin_unlock_irqrestore include/linux/spinlock_api_smp.h:160 [inline]
hardirqs last  enabled at (40498): [<ffffffff8940613e>] _raw_spin_unlock_irqrestore+0x2e/0x60 kernel/locking/spinlock.c:191
hardirqs last disabled at (40497): [<ffffffff89405f9d>] __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:108 [inline]
hardirqs last disabled at (40497): [<ffffffff89405f9d>] _raw_spin_lock_irqsave+0x4d/0xa0 kernel/locking/spinlock.c:159
softirqs last  enabled at (40390): [<ffffffff87c11c35>] local_bh_enable+0x5/0x20 include/linux/bottom_half.h:31
softirqs last disabled at (40393): [<ffffffff89600eaf>] asm_call_irq_on_stack+0xf/0x20

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

       CPU0
       ----
  lock(&file_data->lock);
  <Interrupt>
    lock(&file_data->lock);

 *** DEADLOCK ***

4 locks held by kworker/1:3/8675:
 #0: ffff888010464d38 ((wq_completion)events){+.+.}-{0:0}, at: process_one_work+0x6f4/0xfc0 kernel/workqueue.c:2245
 #1: ffffc90001b6fd80 ((work_completion)(&w->work)#2){+.+.}-{0:0}, at: process_one_work+0x733/0xfc0 kernel/workqueue.c:2247
 #2: ffffffff8bce6980 (rcu_callback){....}-{0:0}, at: rcu_lock_acquire+0x0/0x20 kernel/rcu/tree.c:1365
 #3: ffffffff8bce68c0 (rcu_read_lock){....}-{1:2}, at: rcu_lock_acquire+0x5/0x30 include/linux/rcupdate.h:247

stack backtrace:
CPU: 1 PID: 8675 Comm: kworker/1:3 Not tainted 5.10.0-rc4-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Workqueue: events iterate_cleanup_work
Call Trace:
 <IRQ>
 __dump_stack lib/dump_stack.c:77 [inline]
 dump_stack+0x137/0x1be lib/dump_stack.c:118
 print_usage_bug+0xc08/0x1090 kernel/locking/lockdep.c:3738
 mark_lock_irq kernel/locking/lockdep.c:3749 [inline]
 mark_lock+0x1953/0x20e0 kernel/locking/lockdep.c:4409
 mark_usage kernel/locking/lockdep.c:4304 [inline]
 __lock_acquire+0xbff/0x6210 kernel/locking/lockdep.c:4784
 lock_acquire+0x114/0x5e0 kernel/locking/lockdep.c:5435
 __raw_spin_lock include/linux/spinlock_api_smp.h:142 [inline]
 _raw_spin_lock+0x2a/0x40 kernel/locking/spinlock.c:151
 spin_lock include/linux/spinlock.h:354 [inline]
 io_file_data_ref_zero+0x6a/0x3a0 fs/io_uring.c:7361
 percpu_ref_put_many include/linux/percpu-refcount.h:322 [inline]
 percpu_ref_put+0x1cb/0x1d0 include/linux/percpu-refcount.h:338
 rcu_do_batch kernel/rcu/tree.c:2476 [inline]
 rcu_core+0x79b/0x10b0 kernel/rcu/tree.c:2711
 __do_softirq+0x307/0x6be kernel/softirq.c:298
 asm_call_irq_on_stack+0xf/0x20
 </IRQ>
 __run_on_irqstack arch/x86/include/asm/irq_stack.h:26 [inline]
 run_on_irqstack_cond arch/x86/include/asm/irq_stack.h:77 [inline]
 do_softirq_own_stack+0x9a/0xe0 arch/x86/kernel/irq_64.c:77
 invoke_softirq kernel/softirq.c:393 [inline]
 __irq_exit_rcu+0x1d6/0x200 kernel/softirq.c:423
 irq_exit_rcu+0x5/0x20 kernel/softirq.c:435
 sysvec_apic_timer_interrupt+0xe0/0xf0 arch/x86/kernel/apic/apic.c:1091
 asm_sysvec_apic_timer_interrupt+0x12/0x20 arch/x86/include/asm/idtentry.h:631
RIP: 0010:should_resched arch/x86/include/asm/preempt.h:102 [inline]
RIP: 0010:__local_bh_enable_ip+0xfe/0x170 kernel/softirq.c:202
Code: 89 e8 66 9e f7 07 65 66 8b 05 7e af bc 7e 66 85 c0 75 41 bf 01 00 00 00 e8 1f 34 09 00 e8 2a 74 34 00 fb 65 8b 05 6e 64 bb 7e <85> c0 75 05 e8 10 c1 b9 ff 65 48 8b 04 25 28 00 00 00 48 3b 44 24
RSP: 0018:ffffc90001b6fbb0 EFLAGS: 00000282
RAX: 0000000080000000 RBX: 00000000000001ff RCX: ffffffff81599766
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000
RBP: ffff888021893668 R08: dffffc0000000000 R09: fffffbfff1dd427b
R10: fffffbfff1dd427b R11: 0000000000000000 R12: dffffc0000000000
R13: 00000000000026cd R14: ffffffff87c11c35 R15: dffffc0000000000
 get_next_corpse net/netfilter/nf_conntrack_core.c:2221 [inline]
 nf_ct_iterate_cleanup+0x427/0x4d0 net/netfilter/nf_conntrack_core.c:2244
 nf_ct_iterate_cleanup_net+0xfc/0x150 net/netfilter/nf_conntrack_core.c:2329
 iterate_cleanup_work+0x4c/0x100 net/netfilter/nf_nat_masquerade.c:216
 process_one_work+0x789/0xfc0 kernel/workqueue.c:2272
 worker_thread+0xaa4/0x1460 kernel/workqueue.c:2418
 kthread+0x36b/0x390 kernel/kthread.c:292
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:296

Crashes (7152):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2020/11/21 14:56 upstream 27bba9c532a8 68068804 .config console log report syz C ci-upstream-kasan-gce-smack-root
2020/11/21 12:23 upstream 27bba9c532a8 68068804 .config console log report syz C ci-upstream-kasan-gce-root
2020/11/21 11:30 upstream 27bba9c532a8 68068804 .config console log report syz C ci-upstream-kasan-gce-selinux-root
2020/11/21 09:22 upstream 27bba9c532a8 68068804 .config console log report syz C ci-upstream-kasan-gce
2020/11/21 10:03 upstream 27bba9c532a8 68068804 .config console log report syz C ci-upstream-kasan-gce-386
2020/12/17 07:39 upstream 5e60366d56c6 04201c06 .config console log report info ci-upstream-kasan-gce-selinux-root
2020/12/17 06:32 upstream 5e60366d56c6 04201c06 .config console log report info ci-upstream-kasan-gce-selinux-root
2020/12/17 04:46 upstream 5e60366d56c6 04201c06 .config console log report info ci-upstream-kasan-gce-selinux-root
2020/12/17 02:16 upstream 5e60366d56c6 04201c06 .config console log report info ci-upstream-kasan-gce-selinux-root
2020/12/17 00:06 upstream 5e60366d56c6 04201c06 .config console log report info ci-upstream-kasan-gce-selinux-root
2020/12/16 21:58 upstream 5e60366d56c6 04201c06 .config console log report info ci-upstream-kasan-gce-selinux-root
2020/12/16 19:55 upstream 5e60366d56c6 04201c06 .config console log report info ci-upstream-kasan-gce-selinux-root
2020/12/16 18:39 upstream 5e60366d56c6 04201c06 .config console log report info ci-upstream-kasan-gce
2020/12/16 18:15 upstream 5e60366d56c6 04201c06 .config console log report info ci-upstream-kasan-gce-selinux-root
2020/12/16 17:11 upstream 5e60366d56c6 f213e07e .config console log report info ci-upstream-kasan-gce-selinux-root
2020/12/16 16:04 upstream d635a69dd498 f213e07e .config console log report info ci-upstream-kasan-gce-selinux-root
2020/12/16 16:02 upstream d635a69dd498 f213e07e .config console log report info ci-upstream-kasan-gce
2020/12/16 15:02 upstream d635a69dd498 f213e07e .config console log report info ci-upstream-kasan-gce-selinux-root
2020/12/16 13:19 upstream d635a69dd498 f213e07e .config console log report info ci-upstream-kasan-gce-smack-root
2020/12/16 12:43 upstream d635a69dd498 f213e07e .config console log report info ci-upstream-kasan-gce-selinux-root
2020/12/16 11:40 upstream d635a69dd498 f213e07e .config console log report info ci-upstream-kasan-gce-selinux-root
2020/12/16 11:35 upstream d635a69dd498 f213e07e .config console log report info ci-upstream-kasan-gce-smack-root
2020/12/16 08:52 upstream d635a69dd498 f213e07e .config console log report info ci-upstream-kasan-gce-smack-root
2020/12/16 07:45 upstream d635a69dd498 f213e07e .config console log report info ci-upstream-kasan-gce-selinux-root
2020/12/16 06:54 upstream d635a69dd498 f213e07e .config console log report info ci-upstream-kasan-gce
2020/12/16 06:31 upstream d635a69dd498 f213e07e .config console log report info ci-upstream-kasan-gce
2020/12/16 05:28 upstream d635a69dd498 f213e07e .config console log report info ci-upstream-kasan-gce-smack-root
2020/12/16 04:24 upstream d635a69dd498 f213e07e .config console log report info ci-upstream-kasan-gce-smack-root
2020/12/16 03:30 upstream d635a69dd498 f213e07e .config console log report info ci-upstream-kasan-gce-smack-root
2020/12/16 02:31 upstream 148842c98a24 97183ed7 .config console log report info ci-upstream-kasan-gce-selinux-root
2020/12/16 02:26 upstream 148842c98a24 97183ed7 .config console log report info ci-upstream-kasan-gce-selinux-root
2020/12/16 01:15 upstream 148842c98a24 97183ed7 .config console log report info ci-upstream-kasan-gce-root
2020/12/16 00:13 upstream 148842c98a24 97183ed7 .config console log report info ci-upstream-kasan-gce-smack-root
2020/12/15 22:48 upstream 148842c98a24 97183ed7 .config console log report info ci-upstream-kasan-gce-selinux-root
2020/12/15 22:06 upstream 148842c98a24 97183ed7 .config console log report info ci-upstream-kasan-gce-smack-root
2020/12/15 20:22 upstream 148842c98a24 97183ed7 .config console log report info ci-upstream-kasan-gce-selinux-root
2020/12/15 19:05 upstream 148842c98a24 97183ed7 .config console log report info ci-upstream-kasan-gce
2020/12/15 17:40 upstream 148842c98a24 97183ed7 .config console log report info ci-upstream-kasan-gce-smack-root
2020/12/15 17:39 upstream 148842c98a24 97183ed7 .config console log report info ci-upstream-kasan-gce-root
2020/12/15 16:37 upstream 148842c98a24 97183ed7 .config console log report info ci-upstream-kasan-gce-root
2020/12/15 15:08 upstream 148842c98a24 97183ed7 .config console log report info ci-upstream-kasan-gce-selinux-root
2020/12/15 14:06 upstream 148842c98a24 97183ed7 .config console log report info ci-upstream-kasan-gce-root
2020/12/15 12:38 upstream 148842c98a24 97183ed7 .config console log report info ci-upstream-kasan-gce-root
2020/12/15 11:52 upstream 148842c98a24 97183ed7 .config console log report info ci-upstream-kasan-gce-root
2020/12/15 10:58 upstream 148842c98a24 97183ed7 .config console log report info ci-upstream-kasan-gce-selinux-root
2020/12/15 10:24 upstream 148842c98a24 97183ed7 .config console log report info ci-upstream-kasan-gce-selinux-root
2020/11/21 04:57 upstream 27bba9c532a8 740ff461 .config console log report info ci-upstream-kasan-gce-smack-root
2020/12/16 23:15 upstream 5e60366d56c6 04201c06 .config console log report info ci-upstream-kasan-gce-386
2020/12/16 20:52 upstream 5e60366d56c6 04201c06 .config console log report info ci-upstream-kasan-gce-386
2020/12/16 09:32 upstream d635a69dd498 f213e07e .config console log report info ci-upstream-kasan-gce-386
2020/12/16 05:28 upstream d635a69dd498 f213e07e .config console log report info ci-upstream-kasan-gce-386
2020/11/26 08:06 linux-next 62918e6fd7b5 2f1cec62 .config console log report info ci-upstream-linux-next-kasan-gce-root
* Struck through repros no longer work on HEAD.