syzbot


INFO: rcu detected stall in process_one_work (3)

Status: fixed on 2020/11/16 12:12
Reported-by: syzbot+f0f857c714a8800e048c@syzkaller.appspotmail.com
Fix commit: 1d0e850a49a5 afs: Fix cell removal
First crash: 712d, last: 671d

Cause bisection: introduced by (bisect log) [merge commit]:
commit 5f739e4a491ab63730ef3b7464171340c689fbff
Author: Linus Torvalds <torvalds@linux-foundation.org>
Date: Tue Mar 12 20:27:20 2019 +0000

  Merge branch 'work.misc' of git://git.kernel.org/pub/scm/linux/kernel/git/viro/vfs

Crash: general protection fault in batadv_iv_ogm_queue_add (log)
Repro: C syz .config

Fix bisection: fixed by (bisect log) :
commit 1d0e850a49a5b56f8f3cb51e74a11e2fedb96be6
Author: David Howells <dhowells@redhat.com>
Date: Fri Oct 16 12:21:14 2020 +0000

  afs: Fix cell removal

similar bugs (3):
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
upstream INFO: rcu detected stall in process_one_work (2) 1 849d 849d 0/23 auto-closed as invalid on 2020/07/10 22:43
upstream INFO: rcu detected stall in process_one_work (4) 1 324d 324d 0/23 auto-closed as invalid on 2021/12/18 04:26
upstream INFO: rcu detected stall in process_one_work 8 1088d 1531d 0/23 auto-closed as invalid on 2019/11/14 14:39

Sample crash report:
rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
rcu: 	Tasks blocked on level-0 rcu_node (CPUs 0-1):
------------[ cut here ]------------
WARNING: CPU: 1 PID: 6878 at kernel/sched/core.c:3013 rq_unlock kernel/sched/sched.h:1326 [inline]
WARNING: CPU: 1 PID: 6878 at kernel/sched/core.c:3013 try_invoke_on_locked_down_task+0x214/0x2c0 kernel/sched/core.c:3019
Kernel panic - not syncing: panic_on_warn set ...
CPU: 1 PID: 6878 Comm: kworker/1:0 Not tainted 5.9.0-rc2-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Workqueue: rcu_gp srcu_invoke_callbacks
Call Trace:
 <IRQ>
 __dump_stack lib/dump_stack.c:77 [inline]
 dump_stack+0x18f/0x20d lib/dump_stack.c:118
 panic+0x2e3/0x75c kernel/panic.c:231
 __warn.cold+0x20/0x4a kernel/panic.c:600
 report_bug+0x1bd/0x210 lib/bug.c:198
 handle_bug+0x38/0x90 arch/x86/kernel/traps.c:234
 exc_invalid_op+0x14/0x40 arch/x86/kernel/traps.c:254
 asm_exc_invalid_op+0x12/0x20 arch/x86/include/asm/idtentry.h:536
RIP: 0010:try_invoke_on_locked_down_task+0x214/0x2c0 kernel/sched/core.c:3013
Code: 45 31 f6 49 39 c0 74 3a 8b 74 24 38 49 8d 78 18 4c 89 04 24 e8 2d 99 08 00 4c 8b 04 24 4c 89 c7 e8 41 33 a5 06 e9 29 ff ff ff <0f> 0b e9 86 fe ff ff 4c 89 ee 48 89 ef 41 ff d4 41 89 c6 e9 11 ff
RSP: 0018:ffffc90000da8bd8 EFLAGS: 00010046
RAX: 0000000000000000 RBX: 1ffff920001b517d RCX: 0000000000000001
RDX: 0000000000000000 RSI: ffffffff81612380 RDI: ffff8880953c2540
RBP: ffff8880953c2540 R08: 0000000000000033 R09: ffffffff89bcb363
R10: 0000000000000629 R11: 0000000000000001 R12: ffffffff81612380
R13: ffffc90000da8d00 R14: ffff8880953c28c0 R15: ffff8880ae736c00
 rcu_print_task_stall kernel/rcu/tree_stall.h:267 [inline]
 print_other_cpu_stall kernel/rcu/tree_stall.h:475 [inline]
 check_cpu_stall kernel/rcu/tree_stall.h:634 [inline]
 rcu_pending kernel/rcu/tree.c:3637 [inline]
 rcu_sched_clock_irq.cold+0x92e/0xccd kernel/rcu/tree.c:2519
 update_process_times+0x25/0xa0 kernel/time/timer.c:1710
 tick_sched_handle+0x9b/0x180 kernel/time/tick-sched.c:176
 tick_sched_timer+0x1d1/0x2a0 kernel/time/tick-sched.c:1328
 __run_hrtimer kernel/time/hrtimer.c:1524 [inline]
 __hrtimer_run_queues+0x1d5/0xfc0 kernel/time/hrtimer.c:1588
 hrtimer_interrupt+0x32a/0x930 kernel/time/hrtimer.c:1650
 local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1080 [inline]
 __sysvec_apic_timer_interrupt+0x142/0x5e0 arch/x86/kernel/apic/apic.c:1097
 asm_call_on_stack+0xf/0x20 arch/x86/entry/entry_64.S:706
 </IRQ>
 __run_on_irqstack arch/x86/include/asm/irq_stack.h:22 [inline]
 run_on_irqstack_cond arch/x86/include/asm/irq_stack.h:48 [inline]
 sysvec_apic_timer_interrupt+0xb2/0xf0 arch/x86/kernel/apic/apic.c:1091
 asm_sysvec_apic_timer_interrupt+0x12/0x20 arch/x86/include/asm/idtentry.h:581
RIP: 0010:arch_local_irq_restore arch/x86/include/asm/paravirt.h:770 [inline]
RIP: 0010:__raw_spin_unlock_irqrestore include/linux/spinlock_api_smp.h:160 [inline]
RIP: 0010:_raw_spin_unlock_irqrestore+0x8c/0xe0 kernel/locking/spinlock.c:191
Code: 48 c7 c0 c8 3b b6 89 48 ba 00 00 00 00 00 fc ff df 48 c1 e8 03 80 3c 10 00 75 37 48 83 3d f3 0f c0 01 00 74 22 48 89 df 57 9d <0f> 1f 44 00 00 bf 01 00 00 00 e8 95 87 59 f9 65 8b 05 8e d2 0b 78
RSP: 0018:ffffc90003ac7c28 EFLAGS: 00000286
RAX: 1ffffffff136c779 RBX: 0000000000000286 RCX: 0000000000000002
RDX: dffffc0000000000 RSI: 0000000000000000 RDI: 0000000000000286
RBP: ffffc90000dd7c30 R08: 0000000000000001 R09: ffffffff8c5f3a0f
R10: fffffbfff18be741 R11: 0000000000000001 R12: ffffe8ffffd0a740
R13: ffffe8ffffd0a680 R14: ffffe8ffffd0a640 R15: ffffc90000dd7c18
 srcu_invoke_callbacks+0x207/0x399 kernel/rcu/srcutree.c:1201
 process_one_work+0x94c/0x1670 kernel/workqueue.c:2269
 worker_thread+0x64c/0x1120 kernel/workqueue.c:2415
 kthread+0x3b5/0x4a0 kernel/kthread.c:292
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:294
Shutting down cpus with NMI
Kernel Offset: disabled
Rebooting in 86400 seconds..

Crashes (1):
Manager Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Title
ci-upstream-kasan-gce-selinux-root 2020/08/26 10:33 upstream abb3438d69fb 344da168 .config log report syz C