syzbot


INFO: rcu detected stall in wb_workfn

Status: auto-closed as invalid on 2022/01/25 21:50
Reported-by: syzbot+@syzkaller.appspotmail.com
First crash: 411d, last: 404d
similar bugs (3):
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
upstream INFO: rcu detected stall in wb_workfn (2) 1 161d 161d 0/24 auto-closed as invalid on 2022/09/25 22:53
linux-4.19 INFO: rcu detected stall in wb_workfn 1 110d 110d 0/1 upstream: reported on 2022/08/18 09:40
linux-4.14 INFO: rcu detected stall in wb_workfn 1 1143d 1143d 0/1 auto-closed as invalid on 2020/02/17 08:22

Sample crash report:
rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
rcu: 	Tasks blocked on level-0 rcu_node (CPUs 0-1): P10/1:b..l P9628/1:b..l P1242/1:b..l P2977/1:b..l
	(detected by 1, t=10502 jiffies, g=14353, q=36)
task:systemd-udevd   state:R  running task     stack:19728 pid: 2977 ppid:     1 flags:0x00004000
Call Trace:
 context_switch kernel/sched/core.c:4940 [inline]
 __schedule+0xb72/0x1460 kernel/sched/core.c:6287
 preempt_schedule_common kernel/sched/core.c:6459 [inline]
 preempt_schedule+0x14d/0x190 kernel/sched/core.c:6484
 preempt_schedule_thunk+0x16/0x18
 __raw_spin_unlock_irqrestore include/linux/spinlock_api_smp.h:161 [inline]
 _raw_spin_unlock_irqrestore+0x128/0x130 kernel/locking/spinlock.c:194
 spin_unlock_irqrestore include/linux/spinlock.h:418 [inline]
 __wake_up_common_lock kernel/sched/wait.c:140 [inline]
 __wake_up_sync_key+0x124/0x1c0 kernel/sched/wait.c:205
 sock_def_readable+0x106/0x200 net/core/sock.c:3054
 __netlink_sendskb net/netlink/af_netlink.c:1266 [inline]
 netlink_sendskb+0x8d/0x130 net/netlink/af_netlink.c:1272
 netlink_unicast+0x633/0x9f0 net/netlink/af_netlink.c:1360
 netlink_sendmsg+0xa29/0xe50 net/netlink/af_netlink.c:1935
 sock_sendmsg_nosec net/socket.c:704 [inline]
 sock_sendmsg net/socket.c:724 [inline]
 ____sys_sendmsg+0x5b9/0x910 net/socket.c:2409
 ___sys_sendmsg net/socket.c:2463 [inline]
 __sys_sendmsg+0x36f/0x450 net/socket.c:2492
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x44/0xd0 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7f750aa99e67
RSP: 002b:00007ffe50427758 EFLAGS: 00000246 ORIG_RAX: 000000000000002e
RAX: ffffffffffffffda RBX: 000055dfbee67170 RCX: 00007f750aa99e67
RDX: 0000000000000000 RSI: 00007ffe50427770 RDI: 0000000000000004
RBP: 00007ffe50427770 R08: 000055dfbee80124 R09: 0000000000000000
R10: 0000000000000018 R11: 0000000000000246 R12: 000055dfbee7f2b0
R13: 00000000000000ba R14: 000055dfbee67930 R15: 0000000000000000
task:kworker/u4:7    state:R  running task     stack:20280 pid: 1242 ppid:     2 flags:0x00004000
Workqueue: bat_events batadv_nc_worker
Call Trace:
 context_switch kernel/sched/core.c:4940 [inline]
 __schedule+0xb72/0x1460 kernel/sched/core.c:6287
 preempt_schedule_irq+0xf7/0x1c0 kernel/sched/core.c:6687
 irqentry_exit+0x56/0x90 kernel/entry/common.c:425
 asm_sysvec_reschedule_ipi+0x12/0x20
RIP: 0010:lock_acquire+0x21f/0x4d0 kernel/locking/lockdep.c:5629
Code: 08 4c 89 f7 e8 f2 e6 69 00 f6 84 24 81 00 00 00 02 0f 85 13 02 00 00 41 f7 c4 00 02 00 00 74 01 fb 48 c7 44 24 40 0e 36 e0 45 <4b> c7 04 2f 00 00 00 00 43 c7 44 2f 09 00 00 00 00 43 c7 44 2f 11
RSP: 0018:ffffc9000509fa80 EFLAGS: 00000206
RAX: 0000000000000001 RBX: 1ffff92000a13f60 RCX: ffff88801d52a698
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000
RBP: ffffc9000509fbd8 R08: dffffc0000000000 R09: fffffbfff1fa37d9
R10: fffffbfff1fa37d9 R11: 0000000000000000 R12: 0000000000000246
R13: 1ffff92000a13f58 R14: ffffc9000509fb00 R15: dffffc0000000000
 rcu_lock_acquire+0x2a/0x30 include/linux/rcupdate.h:267
 rcu_read_lock include/linux/rcupdate.h:687 [inline]
 batadv_nc_purge_orig_hash net/batman-adv/network-coding.c:410 [inline]
 batadv_nc_worker+0xc8/0x5b0 net/batman-adv/network-coding.c:721
 process_one_work+0x853/0x1140 kernel/workqueue.c:2297
 worker_thread+0xac1/0x1320 kernel/workqueue.c:2444
 kthread+0x453/0x480 kernel/kthread.c:319
 ret_from_fork+0x1f/0x30
task:systemd-udevd   state:R  running task     stack:25296 pid: 9628 ppid:  2977 flags:0x00004000
Call Trace:
 context_switch kernel/sched/core.c:4940 [inline]
 __schedule+0xb72/0x1460 kernel/sched/core.c:6287
 preempt_schedule_common kernel/sched/core.c:6459 [inline]
 preempt_schedule+0x14d/0x190 kernel/sched/core.c:6484
 preempt_schedule_thunk+0x16/0x18
 __raw_spin_unlock_irq include/linux/spinlock_api_smp.h:169 [inline]
 _raw_spin_unlock_irq+0x3c/0x40 kernel/locking/spinlock.c:202
 spin_unlock_irq include/linux/spinlock.h:413 [inline]
 loop_queue_work drivers/block/loop.c:1066 [inline]
 loop_queue_rq+0x995/0xa70 drivers/block/loop.c:2177
 __blk_mq_issue_directly block/blk-mq.c:1985 [inline]
 __blk_mq_try_issue_directly+0x4e8/0xc80 block/blk-mq.c:2041
 blk_mq_request_issue_directly block/blk-mq.c:2089 [inline]
 blk_mq_try_issue_list_directly+0x280/0x6d0 block/blk-mq.c:2107
 blk_mq_sched_insert_requests+0x25d/0x510 block/blk-mq-sched.c:506
 blk_mq_flush_plug_list+0x63f/0x710 block/blk-mq.c:1942
 blk_flush_plug_list+0x491/0x4e0 block/blk-core.c:1726
 blk_finish_plug+0x5a/0x80 block/blk-core.c:1743
 read_pages+0x4a5/0x8a0 mm/readahead.c:150
 page_cache_ra_unbounded+0x82a/0x9b0 mm/readahead.c:239
 do_page_cache_ra mm/readahead.c:269 [inline]
 force_page_cache_ra+0x3b6/0x420 mm/readahead.c:301
 page_cache_sync_readahead include/linux/pagemap.h:883 [inline]
 filemap_get_pages+0x43d/0xd90 mm/filemap.c:2545
 filemap_read+0x3be/0x1060 mm/filemap.c:2628
 blkdev_read_iter+0x12a/0x180 block/fops.c:545
 call_read_iter include/linux/fs.h:2157 [inline]
 new_sync_read fs/read_write.c:404 [inline]
 vfs_read+0xaf9/0xe60 fs/read_write.c:485
 ksys_read+0x18f/0x2c0 fs/read_write.c:623
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x44/0xd0 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7f750aa99210
RSP: 002b:00007ffe50421d38 EFLAGS: 00000246 ORIG_RAX: 0000000000000000
RAX: ffffffffffffffda RBX: 000055dfbee76290 RCX: 00007f750aa99210
RDX: 0000000000000018 RSI: 000055dfbee762b8 RDI: 000000000000000f
RBP: 000055dfbee73810 R08: 0000000000000000 R09: 0000000000000050
R10: 000055dfbee762a8 R11: 0000000000000246 R12: 0000000000184200
R13: 0000000000184218 R14: 000055dfbee73860 R15: 0000000000000018
task:kworker/u4:1    state:R  running task     stack:21008 pid:   10 ppid:     2 flags:0x00004000
Workqueue: writeback wb_workfn (flush-7:2)
Call Trace:
 context_switch kernel/sched/core.c:4940 [inline]
 __schedule+0xb72/0x1460 kernel/sched/core.c:6287
 preempt_schedule_irq+0xf7/0x1c0 kernel/sched/core.c:6687
 irqentry_exit+0x56/0x90 kernel/entry/common.c:425
 asm_sysvec_apic_timer_interrupt+0x12/0x20
RIP: 0010:lock_is_held_type+0x4e/0x190 kernel/locking/lockdep.c:5661
Code: d4 e1 03 00 0f 84 0a 01 00 00 65 8b 05 0b 90 07 76 85 c0 0f 85 fb 00 00 00 65 4c 8b 2c 25 c0 ef 01 00 41 83 bd 1c 0a 00 00 00 <0f> 85 e4 00 00 00 41 89 f6 49 89 ff 48 c7 04 24 00 00 00 00 9c 8f
RSP: 0018:ffffc90000cf6ac8 EFLAGS: 00000246
RAX: 0000000000000000 RBX: 00000000ffffffff RCX: ffff888011239c80
RDX: 0000000000000000 RSI: 00000000ffffffff RDI: ffff8880849d36c0
RBP: ffff8880849d36c0 R08: ffffffff843b4288 R09: ffffffff843b3fa0
R10: 0000000000000002 R11: ffff888011239c80 R12: dffffc0000000000
R13: ffff888011239c80 R14: ffffc90000cf6c18 R15: 1ffff9200019ed83
 lock_is_held include/linux/lockdep.h:283 [inline]
 xa_entry include/linux/xarray.h:1182 [inline]
 xas_find+0x445/0x9e0 lib/xarray.c:1262
 find_get_entry mm/filemap.c:1978 [inline]
 find_get_pages_range+0x230/0x8f0 mm/filemap.c:2162
 pagevec_lookup_range+0x2e/0x70 mm/swap.c:1104
 mpage_release_unused_pages+0x335/0x9a0 fs/ext4/inode.c:1567
 ext4_writepages+0x1326/0x4080 fs/ext4/inode.c:2816
 do_writepages+0x49d/0x760 mm/page-writeback.c:2364
 __writeback_single_inode+0xd4/0x590 fs/fs-writeback.c:1616
 writeback_sb_inodes+0xd29/0x29e0 fs/fs-writeback.c:1881
 wb_writeback+0x41c/0x9b0 fs/fs-writeback.c:2053
 wb_do_writeback fs/fs-writeback.c:2196 [inline]
 wb_workfn+0x41b/0x1430 fs/fs-writeback.c:2237
 process_one_work+0x853/0x1140 kernel/workqueue.c:2297
 worker_thread+0xac1/0x1320 kernel/workqueue.c:2444
 kthread+0x453/0x480 kernel/kthread.c:319
 ret_from_fork+0x1f/0x30
rcu: rcu_preempt kthread starved for 10502 jiffies! g14353 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x0 ->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:R  running task     stack:26544 pid:   14 ppid:     2 flags:0x00004000
Call Trace:
 context_switch kernel/sched/core.c:4940 [inline]
 __schedule+0xb72/0x1460 kernel/sched/core.c:6287
 schedule+0x14b/0x210 kernel/sched/core.c:6366
 schedule_timeout+0x1b9/0x300 kernel/time/timer.c:1881
 rcu_gp_fqs_loop+0x1fd/0x770 kernel/rcu/tree.c:1957
 rcu_gp_kthread+0xa5/0x350 kernel/rcu/tree.c:2130
 kthread+0x453/0x480 kernel/kthread.c:319
 ret_from_fork+0x1f/0x30
rcu: Stack dump where RCU GP kthread last ran:
NMI backtrace for cpu 1
CPU: 1 PID: 9738 Comm: syz-executor.3 Not tainted 5.15.0-rc6-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:88 [inline]
 dump_stack_lvl+0x1dc/0x2d8 lib/dump_stack.c:106
 nmi_cpu_backtrace+0x45f/0x490 lib/nmi_backtrace.c:105
 nmi_trigger_cpumask_backtrace+0x16a/0x280 lib/nmi_backtrace.c:62
 trigger_single_cpu_backtrace include/linux/nmi.h:164 [inline]
 rcu_check_gp_kthread_starvation+0x1ff/0x270 kernel/rcu/tree_stall.h:481
 print_other_cpu_stall kernel/rcu/tree_stall.h:586 [inline]
 check_cpu_stall kernel/rcu/tree_stall.h:729 [inline]
 rcu_pending kernel/rcu/tree.c:3880 [inline]
 rcu_sched_clock_irq+0x23d5/0x2bc0 kernel/rcu/tree.c:2599
 update_process_times+0x197/0x200 kernel/time/timer.c:1785
 tick_sched_handle kernel/time/tick-sched.c:226 [inline]
 tick_sched_timer+0x27d/0x420 kernel/time/tick-sched.c:1421
 __run_hrtimer kernel/time/hrtimer.c:1685 [inline]
 __hrtimer_run_queues+0x4cb/0xa60 kernel/time/hrtimer.c:1749
 hrtimer_interrupt+0x3b3/0x1040 kernel/time/hrtimer.c:1811
 local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1086 [inline]
 __sysvec_apic_timer_interrupt+0xf9/0x270 arch/x86/kernel/apic/apic.c:1103
 sysvec_apic_timer_interrupt+0x8c/0xb0 arch/x86/kernel/apic/apic.c:1097
 </IRQ>
 asm_sysvec_apic_timer_interrupt+0x12/0x20
RIP: 0010:kasan_check_range+0x4/0x2f0 mm/kasan/generic.c:188
Code: c7 e8 40 05 2c 08 31 c0 c3 0f 0b b8 ea ff ff ff c3 0f 0b b8 ea ff ff ff c3 cc cc cc cc cc cc cc cc cc cc cc cc cc 41 57 41 56 <41> 55 41 54 53 b0 01 48 85 f6 0f 84 0d 02 00 00 48 89 fb 48 01 f3
RSP: 0018:ffffc900048ff4e8 EFLAGS: 00000246
RAX: 1ffffffff18716fb RBX: ffff8880b9d32508 RCX: ffffffff816e0828
RDX: 0000000000000000 RSI: 0000000000000004 RDI: ffff8880b9d32508
RBP: ffffc900048ff5a8 R08: ffffffff847e0080 R09: ffffed1028c6dbc1
R10: ffffed1028c6dbc1 R11: 0000000000000000 R12: ffff88807292e780
R13: dffffc0000000000 R14: ffffffff8c38b7d8 R15: dffffc0000000000
 instrument_atomic_read include/linux/instrumented.h:71 [inline]
 atomic_read include/linux/atomic/atomic-instrumented.h:27 [inline]
 rcu_dynticks_curr_cpu_in_eqs kernel/rcu/tree.c:330 [inline]
 rcu_is_watching+0x58/0xb0 kernel/rcu/tree.c:1121
 rcu_read_lock_held_common kernel/rcu/update.c:108 [inline]
 rcu_read_lock_sched_held+0x6b/0x130 kernel/rcu/update.c:123
 trace_kfree+0x2e/0xd0 include/trace/events/kmem.h:118
 kfree+0x2f/0x310 mm/slub.c:4542
 tty_free_file drivers/tty/tty_io.c:220 [inline]
 tty_open+0x907/0xdd0 drivers/tty/tty_io.c:2149
 chrdev_open+0x5fb/0x680 fs/char_dev.c:414
 do_dentry_open+0x7cb/0x1020 fs/open.c:822
 do_open fs/namei.c:3428 [inline]
 path_openat+0x28b4/0x3670 fs/namei.c:3561
 do_filp_open+0x277/0x4f0 fs/namei.c:3588
 do_sys_openat2+0x13b/0x500 fs/open.c:1200
 do_sys_open fs/open.c:1216 [inline]
 __do_sys_openat fs/open.c:1232 [inline]
 __se_sys_openat fs/open.c:1227 [inline]
 __x64_sys_openat+0x243/0x290 fs/open.c:1227
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x44/0xd0 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7fc10b71ea39
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 bc ff ff ff f7 d8 64 89 01 48
RSP: 002b:00007fc108c94188 EFLAGS: 00000246 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 00007fc10b821f60 RCX: 00007fc10b71ea39
RDX: 0000000000000802 RSI: 0000000020000840 RDI: ffffffffffffff9c
RBP: 00007fc10b778c5f R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 00007ffe3346efbf R14: 00007fc108c94300 R15: 0000000000022000
sched: RT throttling activated
----------------
Code disassembly (best guess):
   0:	08 4c 89 f7          	or     %cl,-0x9(%rcx,%rcx,4)
   4:	e8 f2 e6 69 00       	callq  0x69e6fb
   9:	f6 84 24 81 00 00 00 	testb  $0x2,0x81(%rsp)
  10:	02
  11:	0f 85 13 02 00 00    	jne    0x22a
  17:	41 f7 c4 00 02 00 00 	test   $0x200,%r12d
  1e:	74 01                	je     0x21
  20:	fb                   	sti
  21:	48 c7 44 24 40 0e 36 	movq   $0x45e0360e,0x40(%rsp)
  28:	e0 45
* 2a:	4b c7 04 2f 00 00 00 	movq   $0x0,(%r15,%r13,1) <-- trapping instruction
  31:	00
  32:	43 c7 44 2f 09 00 00 	movl   $0x0,0x9(%r15,%r13,1)
  39:	00 00
  3b:	43                   	rex.XB
  3c:	c7                   	.byte 0xc7
  3d:	44 2f                	rex.R (bad)
  3f:	11                   	.byte 0x11

Crashes (2):
Manager Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Title
ci-upstream-kasan-gce-smack-root 2021/10/20 19:03 upstream 8e37395c3a5d 418a00eb .config log report info INFO: rcu detected stall in wb_workfn
ci-upstream-bpf-kasan-gce 2021/10/27 21:49 bpf 440ffcdd9db4 373bf66b .config log report info INFO: rcu detected stall in wb_workfn
* Struck through repros no longer work on HEAD.