syzbot


INFO: rcu detected stall in ext4_file_write_iter

Status: upstream: reported C repro on 2019/04/12 16:30
Reported-by: syzbot+0f14e80e289d4997740f@syzkaller.appspotmail.com
First crash: 1337d, last: 43d
similar bugs (7):
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
upstream INFO: rcu detected stall in ext4_file_write_iter (3) 5 486d 576d 0/24 auto-closed as invalid on 2021/11/07 19:52
upstream INFO: rcu detected stall in ext4_file_write_iter (5) 3 227d 227d 0/24 auto-closed as invalid on 2022/06/25 07:58
upstream INFO: rcu detected stall in ext4_file_write_iter (4) C unreliable 58 322d 351d 0/24 closed as invalid on 2022/02/08 10:32
android-49 INFO: rcu detected stall in ext4_file_write_iter syz 2 1285d 1326d 0/3 public: reported syz repro on 2019/04/23 08:58
upstream INFO: rcu detected stall in ext4_file_write_iter (2) 1 788d 788d 0/24 auto-closed as invalid on 2021/01/10 12:58
upstream INFO: rcu detected stall in ext4_file_write_iter C inconclusive done 93 850d 1382d 17/24 fixed on 2020/09/25 01:17
linux-4.19 INFO: rcu detected stall in ext4_file_write_iter C error 7 444d 1329d 0/1 upstream: reported C repro on 2019/04/20 13:09

Sample crash report:
audit: type=1400 audit(1561786044.356:37): avc:  denied  { map } for  pid=7099 comm="syz-executor232" path="/root/syz-executor232886150" dev="sda1" ino=1426 scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:object_r:user_home_t:s0 tclass=file permissive=1
INFO: rcu_sched self-detected stall on CPU
	0-...: (10499 ticks this GP) idle=6e6/140000000000001/0 softirq=23189/23194 fqs=0 
	 (t=10500 jiffies g=925 c=924 q=4)
rcu_sched kthread starved for 10500 jiffies! g925 c924 f0x0 RCU_GP_WAIT_FQS(3) ->state=0x0 ->cpu=0
rcu_sched       R  running task    29824     9      2 0x80000000
Call Trace:
 context_switch kernel/sched/core.c:2807 [inline]
 __schedule+0x7b8/0x1cd0 kernel/sched/core.c:3383
 schedule+0x92/0x1c0 kernel/sched/core.c:3427
 schedule_timeout+0x43e/0xe10 kernel/time/timer.c:1744
 rcu_gp_kthread+0xbf4/0x1ec0 kernel/rcu/tree.c:2255
 kthread+0x319/0x430 kernel/kthread.c:232
 ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404
NMI backtrace for cpu 0
CPU: 0 PID: 7107 Comm: syz-executor232 Not tainted 4.14.131 #25
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
 <IRQ>
 __dump_stack lib/dump_stack.c:17 [inline]
 dump_stack+0x138/0x19c lib/dump_stack.c:53
 nmi_cpu_backtrace.cold+0x57/0x94 lib/nmi_backtrace.c:101
 nmi_trigger_cpumask_backtrace+0x141/0x189 lib/nmi_backtrace.c:62
 arch_trigger_cpumask_backtrace+0x14/0x20 arch/x86/kernel/apic/hw_nmi.c:38
 trigger_single_cpu_backtrace include/linux/nmi.h:158 [inline]
 rcu_dump_cpu_stacks+0x186/0x1d2 kernel/rcu/tree.c:1396
 print_cpu_stall kernel/rcu/tree.c:1542 [inline]
 check_cpu_stall kernel/rcu/tree.c:1610 [inline]
 __rcu_pending kernel/rcu/tree.c:3390 [inline]
 rcu_pending kernel/rcu/tree.c:3452 [inline]
 rcu_check_callbacks.cold+0x43d/0xd0a kernel/rcu/tree.c:2792
 update_process_times+0x31/0x70 kernel/time/timer.c:1588
 tick_sched_handle+0x85/0x160 kernel/time/tick-sched.c:161
 tick_sched_timer+0x43/0x130 kernel/time/tick-sched.c:1219
 __run_hrtimer kernel/time/hrtimer.c:1220 [inline]
 __hrtimer_run_queues+0x270/0xbc0 kernel/time/hrtimer.c:1284
 hrtimer_interrupt+0x1d8/0x5d0 kernel/time/hrtimer.c:1318
 local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1037 [inline]
 smp_apic_timer_interrupt+0x11c/0x5e0 arch/x86/kernel/apic/apic.c:1062
 apic_timer_interrupt+0x8e/0xa0 arch/x86/entry/entry_64.S:789
 </IRQ>
RIP: 0010:debug_smp_processor_id+0x1c/0x20 lib/smp_processor_id.c:58
RSP: 0018:ffff88808fb7f470 EFLAGS: 00000282 ORIG_RAX: ffffffffffffff10
RAX: 0000000000000000 RBX: ffffffff87ab2740 RCX: 0000000000000000
RDX: 0000000000000000 RSI: ffffffff869d29a0 RDI: ffffffff869d29e0
RBP: ffff88808fb7f470 R08: 000000000000001c R09: ffffea00021c8a40
R10: ffff8880a5849a40 R11: ffff8880872297e3 R12: 0000000000000001
R13: 0000000000000000 R14: ffff888095f255f0 R15: 000000000000001c
 rcu_lockdep_current_cpu_online kernel/rcu/tree.c:1186 [inline]
 rcu_lockdep_current_cpu_online+0x3a/0x140 kernel/rcu/tree.c:1177
 rcu_read_lock_sched_held+0x97/0x130 kernel/rcu/update.c:113
 trace_writeback_mark_inode_dirty include/trace/events/writeback.h:114 [inline]
 __mark_inode_dirty+0x8f4/0x1040 fs/fs-writeback.c:2125
 mark_inode_dirty include/linux/fs.h:2019 [inline]
 generic_write_end+0x1b7/0x290 fs/buffer.c:2218
 ext4_da_write_end+0x344/0x8e0 fs/ext4/inode.c:3181
 generic_perform_write+0x29f/0x480 mm/filemap.c:3035
 __generic_file_write_iter+0x239/0x5b0 mm/filemap.c:3149
 ext4_file_write_iter+0x2ac/0xe90 fs/ext4/file.c:264
 call_write_iter include/linux/fs.h:1777 [inline]
 do_iter_readv_writev+0x418/0x670 fs/read_write.c:675
 do_iter_write fs/read_write.c:954 [inline]
 do_iter_write+0x154/0x540 fs/read_write.c:935
 vfs_iter_write+0x77/0xb0 fs/read_write.c:967
 iter_file_splice_write+0x572/0xad0 fs/splice.c:749
 do_splice_from fs/splice.c:851 [inline]
 direct_splice_actor+0x123/0x190 fs/splice.c:1018
 splice_direct_to_actor+0x29e/0x7b0 fs/splice.c:973
 do_splice_direct+0x18d/0x230 fs/splice.c:1061
 do_sendfile+0x4db/0xbd0 fs/read_write.c:1441
 SYSC_sendfile64 fs/read_write.c:1496 [inline]
 SyS_sendfile64+0x9d/0x110 fs/read_write.c:1488
 do_syscall_64+0x1e8/0x640 arch/x86/entry/common.c:292
 entry_SYSCALL_64_after_hwframe+0x42/0xb7
RIP: 0033:0x4417a9
RSP: 002b:00007fff5f5841a8 EFLAGS: 00000246 ORIG_RAX: 0000000000000028
RAX: ffffffffffffffda RBX: 00007fff5f584350 RCX: 00000000004417a9
RDX: 0000000020000000 RSI: 0000000000000003 RDI: 0000000000000003
RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000000
R10: 00008080fffffffe R11: 0000000000000246 R12: 0000000000000000
R13: 0000000000402480 R14: 0000000000000000 R15: 0000000000000000
INFO: rcu_preempt detected stalls on CPUs/tasks:
	(detected by 0, t=10554 jiffies, g=1220, c=1219, q=23)
All QSes seen, last rcu_preempt kthread activity 10554 (4295013694-4295003140), jiffies_till_next_fqs=1, root ->qsmask 0x0
syz-executor232 R  running task    26976  7107   7103 0x00000008
Call Trace:
 <IRQ>
 sched_show_task kernel/sched/core.c:5167 [inline]
 sched_show_task.cold+0x294/0x2ff kernel/sched/core.c:5142
 print_other_cpu_stall kernel/rcu/tree.c:1501 [inline]
 check_cpu_stall kernel/rcu/tree.c:1616 [inline]
 __rcu_pending kernel/rcu/tree.c:3390 [inline]
 rcu_pending kernel/rcu/tree.c:3452 [inline]
 rcu_check_callbacks.cold+0xcb1/0xd0a kernel/rcu/tree.c:2792
 update_process_times+0x31/0x70 kernel/time/timer.c:1588
 tick_sched_handle+0x85/0x160 kernel/time/tick-sched.c:161
 tick_sched_timer+0x43/0x130 kernel/time/tick-sched.c:1219
 __run_hrtimer kernel/time/hrtimer.c:1220 [inline]
 __hrtimer_run_queues+0x270/0xbc0 kernel/time/hrtimer.c:1284
 hrtimer_interrupt+0x1d8/0x5d0 kernel/time/hrtimer.c:1318
 local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1037 [inline]
 smp_apic_timer_interrupt+0x11c/0x5e0 arch/x86/kernel/apic/apic.c:1062
 apic_timer_interrupt+0x8e/0xa0 arch/x86/entry/entry_64.S:789
 </IRQ>
RIP: 0010:debug_smp_processor_id+0x1c/0x20 lib/smp_processor_id.c:58
RSP: 0018:ffff88808fb7f470 EFLAGS: 00000282 ORIG_RAX: ffffffffffffff10
RAX: 0000000000000000 RBX: ffffffff87ab2740 RCX: 0000000000000000
RDX: 0000000000000000 RSI: ffffffff869d29a0 RDI: ffffffff869d29e0
RBP: ffff88808fb7f470 R08: 000000000000001c R09: ffffea00021c8a40
R10: ffff8880a5849a40 R11: ffff8880872297e3 R12: 0000000000000001
R13: 0000000000000000 R14: ffff888095f255f0 R15: 000000000000001c
 rcu_lockdep_current_cpu_online kernel/rcu/tree.c:1186 [inline]
 rcu_lockdep_current_cpu_online+0x3a/0x140 kernel/rcu/tree.c:1177
 rcu_read_lock_sched_held+0x97/0x130 kernel/rcu/update.c:113
 trace_writeback_mark_inode_dirty include/trace/events/writeback.h:114 [inline]
 __mark_inode_dirty+0x8f4/0x1040 fs/fs-writeback.c:2125
 mark_inode_dirty include/linux/fs.h:2019 [inline]
 generic_write_end+0x1b7/0x290 fs/buffer.c:2218
 ext4_da_write_end+0x344/0x8e0 fs/ext4/inode.c:3181
 generic_perform_write+0x29f/0x480 mm/filemap.c:3035
 __generic_file_write_iter+0x239/0x5b0 mm/filemap.c:3149
 ext4_file_write_iter+0x2ac/0xe90 fs/ext4/file.c:264
 call_write_iter include/linux/fs.h:1777 [inline]
 do_iter_readv_writev+0x418/0x670 fs/read_write.c:675
 do_iter_write fs/read_write.c:954 [inline]
 do_iter_write+0x154/0x540 fs/read_write.c:935
 vfs_iter_write+0x77/0xb0 fs/read_write.c:967
 iter_file_splice_write+0x572/0xad0 fs/splice.c:749
 do_splice_from fs/splice.c:851 [inline]
 direct_splice_actor+0x123/0x190 fs/splice.c:1018
 splice_direct_to_actor+0x29e/0x7b0 fs/splice.c:973
 do_splice_direct+0x18d/0x230 fs/splice.c:1061
 do_sendfile+0x4db/0xbd0 fs/read_write.c:1441
 SYSC_sendfile64 fs/read_write.c:1496 [inline]
 SyS_sendfile64+0x9d/0x110 fs/read_write.c:1488
 do_syscall_64+0x1e8/0x640 arch/x86/entry/common.c:292
 entry_SYSCALL_64_after_hwframe+0x42/0xb7
RIP: 0033:0x4417a9
RSP: 002b:00007fff5f5841a8 EFLAGS: 00000246 ORIG_RAX: 0000000000000028
RAX: ffffffffffffffda RBX: 00007fff5f584350 RCX: 00000000004417a9
RDX: 0000000020000000 RSI: 0000000000000003 RDI: 0000000000000003
RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000000
R10: 00008080fffffffe R11: 0000000000000246 R12: 0000000000000000
R13: 0000000000402480 R14: 0000000000000000 R15: 0000000000000000
rcu_preempt kthread starved for 10554 jiffies! g1220 c1219 f0x2 RCU_GP_WAIT_FQS(3) ->state=0x0 ->cpu=0
rcu_preempt     R  running task    29776     8      2 0x80000000
Call Trace:
 context_switch kernel/sched/core.c:2807 [inline]
 __schedule+0x7b8/0x1cd0 kernel/sched/core.c:3383
 schedule+0x92/0x1c0 kernel/sched/core.c:3427
 schedule_timeout+0x43e/0xe10 kernel/time/timer.c:1744
 rcu_gp_kthread+0xbf4/0x1ec0 kernel/rcu/tree.c:2255
 kthread+0x319/0x430 kernel/kthread.c:232
 ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404

Fix bisection attempts:
Manager Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Title
ci2-linux-4-14 2022/10/27 15:32 linux-4.14.y 41f36d7859a7 7509bf36 .config log report syz C
ci2-linux-4-14 2022/09/19 15:12 linux-4.14.y 5df8b4735177 7509bf36 .config log report syz C
ci2-linux-4-14 2022/08/20 12:14 linux-4.14.y b641242202ed 7509bf36 .config log report syz C
ci2-linux-4-14 2022/07/21 11:51 linux-4.14.y 424a46ea058e 7509bf36 .config log report syz C
ci2-linux-4-14 2022/06/21 11:18 linux-4.14.y 84bae26850e3 7509bf36 .config log report syz C
ci2-linux-4-14 2022/05/22 10:21 linux-4.14.y dffb5c6ff09c 7509bf36 .config log report syz C
ci2-linux-4-14 2022/04/22 06:36 linux-4.14.y 15a1c6b6f516 7509bf36 .config log report syz C
ci2-linux-4-14 2022/03/23 05:32 linux-4.14.y eb045674aab3 7509bf36 .config log report syz C
ci2-linux-4-14 2022/02/20 15:09 linux-4.14.y a35d65bedfbc 7509bf36 .config log report syz C
ci2-linux-4-14 2022/01/21 13:16 linux-4.14.y 4ba8e26127c3 7509bf36 .config log report syz C
ci2-linux-4-14 2021/12/22 12:38 linux-4.14.y 8ee0807eedf3 7509bf36 .config log report syz C
ci2-linux-4-14 2021/11/22 11:55 linux-4.14.y 5f9f3b0057d5 7509bf36 .config log report syz C
ci2-linux-4-14 2021/10/23 10:41 linux-4.14.y 2760370b1649 7509bf36 .config log report syz C
ci2-linux-4-14 2021/09/22 22:44 linux-4.14.y 8ea4f73cfa7e 7509bf36 .config log report syz C
ci2-linux-4-14 2021/08/23 19:38 linux-4.14.y 162b95d01320 7509bf36 .config log report syz C
ci2-linux-4-14 2021/07/24 19:03 linux-4.14.y 964f3712e6a7 7509bf36 .config log report syz C
ci2-linux-4-14 2021/06/24 18:31 linux-4.14.y cfb41ef9deb1 7509bf36 .config log report syz C
ci2-linux-4-14 2021/05/25 13:45 linux-4.14.y 96afcb20f36f 7509bf36 .config log report syz C
ci2-linux-4-14 2021/04/25 12:28 linux-4.14.y cf256fbcbe34 7509bf36 .config log report syz C
ci2-linux-4-14 2021/03/26 05:25 linux-4.14.y 670d6552eda8 7509bf36 .config log report syz C
ci2-linux-4-14 2021/02/24 04:32 linux-4.14.y 3242aa3a635c 7509bf36 .config log report syz C
ci2-linux-4-14 2021/01/24 03:50 linux-4.14.y 2d2791fce891 7509bf36 .config log report syz C
ci2-linux-4-14 2020/12/25 03:22 linux-4.14.y 3f2ecb86cb90 7509bf36 .config log report syz C
ci2-linux-4-14 2020/11/25 02:56 linux-4.14.y 87335852c5d9 7509bf36 .config log report syz C
ci2-linux-4-14 2020/10/26 02:30 linux-4.14.y 5b7a52cd2eef 7509bf36 .config log report syz C
ci2-linux-4-14 2020/09/26 01:21 linux-4.14.y ca87c8281190 7509bf36 .config log report syz C
ci2-linux-4-14 2020/08/27 00:55 linux-4.14.y d7e78d08fa77 7509bf36 .config log report syz C
ci2-linux-4-14 2020/07/28 00:17 linux-4.14.y 69b94dd6dcd1 7509bf36 .config log report syz C
ci2-linux-4-14 2020/06/02 14:29 linux-4.14.y 4f68020fef1c 7509bf36 .config log report syz C
ci2-linux-4-14 2020/05/03 14:02 linux-4.14.y 773e2b1cd56a 7509bf36 .config log report syz C
ci2-linux-4-14 2020/04/03 13:20 linux-4.14.y 4520f06b03ae 7509bf36 .config log report syz C
ci2-linux-4-14 2020/03/04 12:42 linux-4.14.y 78d697fc93f9 7509bf36 .config log report syz C
ci2-linux-4-14 2020/02/03 12:14 linux-4.14.y 9fa690a2a016 7509bf36 .config log report syz C
ci2-linux-4-14 2020/01/04 11:47 linux-4.14.y 4c5bf01e16a7 7509bf36 .config log report syz C
ci2-linux-4-14 2019/12/05 11:20 linux-4.14.y fbc5fe7a54d0 7509bf36 .config log report syz C
* Struck through repros no longer work on HEAD.
Crashes (7):
Manager Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Title
ci2-linux-4-14 2019/06/29 05:32 linux-4.14.y f4cc0ed9b2c7 7509bf36 .config log report syz C
ci2-linux-4-14 2020/06/27 23:48 linux-4.14.y b850307b279c a2cdad9d .config log report
ci2-linux-4-14 2020/06/24 11:31 linux-4.14.y b850307b279c 41694dbf .config log report
ci2-linux-4-14 2020/03/04 12:51 linux-4.14.y 78d697fc93f9 712198ac .config log report
ci2-linux-4-14 2019/09/08 20:12 linux-4.14.y 414510bc00a5 a60cb4cd .config log report
ci2-linux-4-14 2019/04/23 00:06 linux-4.14.y 68d7a45eec10 53199d6e .config log report
ci2-linux-4-14 2019/04/12 15:29 linux-4.14.y 1ec8f1f0bffe 4f421599 .config log report
* Struck through repros no longer work on HEAD.