syzbot


INFO: rcu detected stall in blk_mq_requeue_work

Status: auto-obsoleted due to no activity on 2023/04/11 09:14
Subsystems: block
[Documentation on labels]
First crash: 1030d, last: 1030d

Sample crash report:
rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
rcu: 	1-...!: (0 ticks this GP) idle=126c/1/0x4000000000000000 softirq=37151/37151 fqs=0
rcu: 	Tasks blocked on level-0 rcu_node (CPUs 0-1): P9555/1:b..l
	(detected by 0, t=10502 jiffies, g=54741, q=63 ncpus=2)
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 PID: 1014 Comm: kworker/1:1H Not tainted 6.1.0-rc3-syzkaller-00239-g10d916c86eca #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 10/26/2022
Workqueue: kblockd blk_mq_requeue_work
RIP: 0010:native_irq_disable arch/x86/include/asm/irqflags.h:40 [inline]
RIP: 0010:arch_local_irq_disable arch/x86/include/asm/irqflags.h:75 [inline]
RIP: 0010:arch_local_irq_save arch/x86/include/asm/irqflags.h:107 [inline]
RIP: 0010:lock_is_held_type+0x54/0x140 kernel/locking/lockdep.c:5707
Code: c0 0f 85 ca 00 00 00 65 4c 8b 24 25 80 6f 02 00 41 8b 94 24 4c 0a 00 00 85 d2 0f 85 b1 00 00 00 48 89 fd 41 89 f6 9c 8f 04 24 <fa> 48 c7 c7 40 8f ec 89 31 db e8 3d 15 00 00 41 8b 84 24 48 0a 00
RSP: 0000:ffffc900003e8d78 EFLAGS: 00000046
RAX: 0000000000000000 RBX: ffff88803b440340 RCX: 0000000000000001
RDX: 0000000000000000 RSI: 00000000ffffffff RDI: ffff88803b440300
RBP: ffff88803b440300 R08: 0000000000000005 R09: 0000000000000000
R10: 0000000000000001 R11: 0000000000000000 R12: ffff88802024a0c0
R13: 00000000ffffffff R14: 00000000ffffffff R15: ffff88803b440340
FS:  0000000000000000(0000) GS:ffff8880b9b00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007f48ca1a8000 CR3: 000000002242f000 CR4: 00000000003506e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 <IRQ>
 lock_is_held include/linux/lockdep.h:283 [inline]
 advance_sched+0xfa/0x9a0 net/sched/sch_taprio.c:705
 __run_hrtimer kernel/time/hrtimer.c:1685 [inline]
 __hrtimer_run_queues+0x690/0xfb0 kernel/time/hrtimer.c:1749
 hrtimer_interrupt+0x31c/0x790 kernel/time/hrtimer.c:1811
 local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1096 [inline]
 __sysvec_apic_timer_interrupt+0x17c/0x640 arch/x86/kernel/apic/apic.c:1113
 sysvec_apic_timer_interrupt+0x8e/0xc0 arch/x86/kernel/apic/apic.c:1107
 </IRQ>
 <TASK>
 asm_sysvec_apic_timer_interrupt+0x16/0x20 arch/x86/include/asm/idtentry.h:649
RIP: 0010:__raw_spin_unlock_irq include/linux/spinlock_api_smp.h:160 [inline]
RIP: 0010:_raw_spin_unlock_irq+0x25/0x40 kernel/locking/spinlock.c:202
Code: 0f 1f 44 00 00 55 48 8b 74 24 08 48 89 fd 48 83 c7 18 e8 be 40 cd f7 48 89 ef e8 06 ad cd f7 e8 21 a4 f0 f7 fb bf 01 00 00 00 <e8> 06 43 c0 f7 65 8b 05 0f c8 70 76 85 c0 74 02 5d c3 e8 3e d0 6e
RSP: 0000:ffffc90004f8fc48 EFLAGS: 00000202
RAX: 00000000000cda5b RBX: ffff88801f3b9b48 RCX: 1ffffffff21298ce
RDX: 0000000000000000 RSI: 0000000000000001 RDI: 0000000000000001
RBP: ffff88801f3b9b08 R08: 0000000000000001 R09: ffffffff9092999f
R10: 0000000000000001 R11: 0000000000000000 R12: ffff88801f3b9b08
R13: ffff88801f3bc048 R14: ffffc90004f8fca0 R15: ffff88801f3bc048
 spin_unlock_irq include/linux/spinlock.h:400 [inline]
 blk_mq_requeue_work+0x16e/0x620 block/blk-mq.c:1423
 process_one_work+0x9bf/0x1710 kernel/workqueue.c:2289
 worker_thread+0x665/0x1080 kernel/workqueue.c:2436
 kthread+0x2e4/0x3a0 kernel/kthread.c:376
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:306
 </TASK>
task:kworker/u4:20   state:R  running task     stack:27448 pid:9555  ppid:2      flags:0x00004000
Workqueue: netns cleanup_net
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:5191 [inline]
 __schedule+0xae9/0x53f0 kernel/sched/core.c:6503
 preempt_schedule_irq+0x4e/0x90 kernel/sched/core.c:6815
 irqentry_exit+0x31/0x80 kernel/entry/common.c:432
 asm_sysvec_apic_timer_interrupt+0x16/0x20 arch/x86/include/asm/idtentry.h:649
RIP: 0010:lock_acquire+0x223/0x630 kernel/locking/lockdep.c:5636
Code: 87 a3 7e 83 f8 01 0f 85 3a 03 00 00 9c 58 f6 c4 02 0f 85 25 03 00 00 48 83 7c 24 08 00 74 01 fb 48 b8 00 00 00 00 00 fc ff df <48> 01 c3 48 c7 03 00 00 00 00 48 c7 43 08 00 00 00 00 48 8b 84 24
RSP: 0018:ffffc900058afa28 EFLAGS: 00000206
RAX: dffffc0000000000 RBX: 1ffff92000b15f48 RCX: a6553aa45a17a382
RDX: 1ffff110100f7191 RSI: 0000000000000000 RDI: 0000000000000000
RBP: 0000000000000000 R08: 0000000000000000 R09: ffffffff90929947
R10: fffffbfff2125328 R11: 1ffffffff17f2029 R12: 0000000000000002
R13: 0000000000000000 R14: ffffffff8bf85b40 R15: 0000000000000000
 rcu_lock_acquire include/linux/rcupdate.h:304 [inline]
 rcu_read_lock include/linux/rcupdate.h:738 [inline]
 inet_twsk_purge+0x12e/0x8a0 net/ipv4/inet_timewait_sock.c:268
 ops_exit_list+0x125/0x170 net/core/net_namespace.c:174
 cleanup_net+0x4ea/0xb00 net/core/net_namespace.c:601
 process_one_work+0x9bf/0x1710 kernel/workqueue.c:2289
 worker_thread+0x665/0x1080 kernel/workqueue.c:2436
 kthread+0x2e4/0x3a0 kernel/kthread.c:376
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:306
 </TASK>
rcu: rcu_preempt kthread timer wakeup didn't happen for 10501 jiffies! g54741 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402
rcu: 	Possible timer handling issue on cpu=1 timer-softirq=33884
rcu: rcu_preempt kthread starved for 10502 jiffies! g54741 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402 ->cpu=1
rcu: 	Unless rcu_preempt kthread gets sufficient CPU time, OOM is now expected behavior.
rcu: RCU grace-period kthread stack dump:
task:rcu_preempt     state:I stack:28792 pid:15    ppid:2      flags:0x00004000
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:5191 [inline]
 __schedule+0xae9/0x53f0 kernel/sched/core.c:6503
 schedule+0xda/0x1b0 kernel/sched/core.c:6579
 schedule_timeout+0x14a/0x2a0 kernel/time/timer.c:1935
 rcu_gp_fqs_loop+0x190/0x910 kernel/rcu/tree.c:1660
 rcu_gp_kthread+0x236/0x360 kernel/rcu/tree.c:1859
 kthread+0x2e4/0x3a0 kernel/kthread.c:376
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:306
 </TASK>
rcu: Stack dump where RCU GP kthread last ran:
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 PID: 1014 Comm: kworker/1:1H Not tainted 6.1.0-rc3-syzkaller-00239-g10d916c86eca #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 10/26/2022
Workqueue: kblockd blk_mq_requeue_work
RIP: 0010:kasan_check_range+0x12b/0x180 mm/kasan/generic.c:190
Code: 3a 00 74 ef 49 8d 04 2c 48 85 d2 75 0b 48 89 da 48 29 c2 e9 55 ff ff ff 49 39 d2 75 17 49 0f be 02 41 83 e1 07 49 39 c1 7d 0a <5b> b8 01 00 00 00 5d 41 5c c3 44 89 c2 e8 f3 ee ff ff 5b 83 f0 01
RSP: 0000:ffffc900003e8c28 EFLAGS: 00000046
RAX: fffffbfff228ae22 RBX: fffffbfff228ae22 RCX: ffffffff815f5111
RDX: fffffbfff228ae22 RSI: 0000000000000004 RDI: ffffffff91457108
RBP: fffffbfff228ae21 R08: 0000000000000001 R09: ffffffff9145710b
R10: fffffbfff228ae21 R11: 0000000000000000 R12: ffffffff91457110
R13: ffffffff91457118 R14: 1ffff9200007d1a2 R15: ffffffff89eef760
FS:  0000000000000000(0000) GS:ffff8880b9b00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007f48ca1a8000 CR3: 000000002242f000 CR4: 00000000003506e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 <IRQ>
 instrument_atomic_read_write include/linux/instrumented.h:102 [inline]
 atomic_try_cmpxchg_acquire include/linux/atomic/atomic-instrumented.h:541 [inline]
 queued_spin_lock include/asm-generic/qspinlock.h:111 [inline]
 do_raw_spin_lock+0x111/0x2a0 kernel/locking/spinlock_debug.c:115
 __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:111 [inline]
 _raw_spin_lock_irqsave+0x41/0x50 kernel/locking/spinlock.c:162
 debug_object_activate+0x12e/0x3e0 lib/debugobjects.c:658
 debug_hrtimer_activate kernel/time/hrtimer.c:420 [inline]
 debug_activate kernel/time/hrtimer.c:475 [inline]
 enqueue_hrtimer+0x2b/0x470 kernel/time/hrtimer.c:1084
 __run_hrtimer kernel/time/hrtimer.c:1702 [inline]
 __hrtimer_run_queues+0xc12/0xfb0 kernel/time/hrtimer.c:1749
 hrtimer_interrupt+0x31c/0x790 kernel/time/hrtimer.c:1811
 local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1096 [inline]
 __sysvec_apic_timer_interrupt+0x17c/0x640 arch/x86/kernel/apic/apic.c:1113
 sysvec_apic_timer_interrupt+0x8e/0xc0 arch/x86/kernel/apic/apic.c:1107
 </IRQ>
 <TASK>
 asm_sysvec_apic_timer_interrupt+0x16/0x20 arch/x86/include/asm/idtentry.h:649
RIP: 0010:__raw_spin_unlock_irq include/linux/spinlock_api_smp.h:160 [inline]
RIP: 0010:_raw_spin_unlock_irq+0x25/0x40 kernel/locking/spinlock.c:202
Code: 0f 1f 44 00 00 55 48 8b 74 24 08 48 89 fd 48 83 c7 18 e8 be 40 cd f7 48 89 ef e8 06 ad cd f7 e8 21 a4 f0 f7 fb bf 01 00 00 00 <e8> 06 43 c0 f7 65 8b 05 0f c8 70 76 85 c0 74 02 5d c3 e8 3e d0 6e
RSP: 0000:ffffc90004f8fc48 EFLAGS: 00000202
RAX: 00000000000cda5b RBX: ffff88801f3b9b48 RCX: 1ffffffff21298ce
RDX: 0000000000000000 RSI: 0000000000000001 RDI: 0000000000000001
RBP: ffff88801f3b9b08 R08: 0000000000000001 R09: ffffffff9092999f
R10: 0000000000000001 R11: 0000000000000000 R12: ffff88801f3b9b08
R13: ffff88801f3bc048 R14: ffffc90004f8fca0 R15: ffff88801f3bc048
 spin_unlock_irq include/linux/spinlock.h:400 [inline]
 blk_mq_requeue_work+0x16e/0x620 block/blk-mq.c:1423
 process_one_work+0x9bf/0x1710 kernel/workqueue.c:2289
 worker_thread+0x665/0x1080 kernel/workqueue.c:2436
 kthread+0x2e4/0x3a0 kernel/kthread.c:376
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:306
 </TASK>

Crashes (1):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2022/11/05 03:24 upstream 10d916c86eca 6d752409 .config console log report info ci-upstream-kasan-gce-selinux-root INFO: rcu detected stall in blk_mq_requeue_work
* Struck through repros no longer work on HEAD.