syzbot


INFO: rcu detected stall in sendfile64 (2)

Status: auto-closed as invalid on 2020/12/03 20:18
Reported-by: syzbot+f7bb058842149b6d5423@syzkaller.appspotmail.com
First crash: 1519d, last: 1365d
Similar bugs (1)
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
linux-4.14 INFO: rcu detected stall in sendfile64 1 1847d 1847d 0/1 auto-closed as invalid on 2019/10/08 13:45

Sample crash report:
audit: type=1804 audit(1596658565.332:57): pid=8384 uid=0 auid=0 ses=4 subj=system_u:system_r:kernel_t:s0 op="invalid_pcr" cause="open_writers" comm="syz-executor.4" name="/root/syzkaller-testdir087489993/syzkaller.mvW2M0/39/bus" dev="sda1" ino=15839 res=1
INFO: rcu_preempt self-detected stall on CPU
	1-...: (10496 ticks this GP) idle=076/140000000000001/0 softirq=13240/13240 fqs=29 
	 (t=10500 jiffies g=2245 c=2244 q=906)
rcu_preempt kthread starved for 10421 jiffies! g2245 c2244 f0x0 RCU_GP_WAIT_FQS(3) ->state=0x0 ->cpu=0
rcu_preempt     R  running task    30008     8      2 0x80000000
Call Trace:
 context_switch kernel/sched/core.c:2808 [inline]
 __schedule+0x88b/0x1de0 kernel/sched/core.c:3384
 schedule+0x8d/0x1b0 kernel/sched/core.c:3428
 schedule_timeout+0x4af/0xe90 kernel/time/timer.c:1746
 rcu_gp_kthread+0xc0a/0x1e60 kernel/rcu/tree.c:2255
 kthread+0x30d/0x420 kernel/kthread.c:232
 ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404
NMI backtrace for cpu 1
CPU: 1 PID: 8356 Comm: syz-executor.1 Not tainted 4.14.192-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:17 [inline]
 dump_stack+0x1b2/0x283 lib/dump_stack.c:58
 nmi_cpu_backtrace.cold+0x57/0x93 lib/nmi_backtrace.c:101
 nmi_trigger_cpumask_backtrace+0x13a/0x17f lib/nmi_backtrace.c:62
 trigger_single_cpu_backtrace include/linux/nmi.h:158 [inline]
 rcu_dump_cpu_stacks+0x15f/0x19c 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+0x464/0xd99 kernel/rcu/tree.c:2792
 update_process_times+0x29/0x60 kernel/time/timer.c:1590
 tick_sched_handle+0x7d/0x150 kernel/time/tick-sched.c:165
 tick_sched_timer+0x92/0x200 kernel/time/tick-sched.c:1223
 __run_hrtimer kernel/time/hrtimer.c:1223 [inline]
 __hrtimer_run_queues+0x30b/0xc80 kernel/time/hrtimer.c:1287
 hrtimer_interrupt+0x1e6/0x5e0 kernel/time/hrtimer.c:1321
 local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1075 [inline]
 smp_apic_timer_interrupt+0x117/0x5e0 arch/x86/kernel/apic/apic.c:1100
 apic_timer_interrupt+0x93/0xa0 arch/x86/entry/entry_64.S:793
 </IRQ>
RIP: 0010:orc_ip arch/x86/kernel/unwind_orc.c:27 [inline]
RIP: 0010:__orc_find+0x6f/0xf0 arch/x86/kernel/unwind_orc.c:49
RSP: 0018:ffff88805a25f5f8 EFLAGS: 00000a02 ORIG_RAX: ffffffffffffff10
RAX: 1ffffffff11491f4 RBX: ffffffff88a48fa0 RCX: ffffffff819812e3
RDX: 0000000000000000 RSI: ffffffff88f437a2 RDI: ffffffff88a48fa0
RBP: ffffffff88a48fa0 R08: ffffffff88f437a2 R09: ffffffff88f437a8
R10: 0000000000024e29 R11: 0000000000058071 R12: ffffffff88a48fa0
R13: ffffffff88a48fa0 R14: ffffffff88a48fa0 R15: dffffc0000000000
 orc_find arch/x86/kernel/unwind_orc.c:118 [inline]
 unwind_next_frame+0x59a/0x17d0 arch/x86/kernel/unwind_orc.c:355
 __save_stack_trace+0x90/0x160 arch/x86/kernel/stacktrace.c:44
 save_stack mm/kasan/kasan.c:447 [inline]
 set_track mm/kasan/kasan.c:459 [inline]
 kasan_kmalloc+0xeb/0x160 mm/kasan/kasan.c:551
 slab_post_alloc_hook mm/slab.h:442 [inline]
 slab_alloc mm/slab.c:3390 [inline]
 __do_kmalloc mm/slab.c:3718 [inline]
 __kmalloc+0x144/0x400 mm/slab.c:3729
 kmalloc_array include/linux/slab.h:607 [inline]
 kcalloc include/linux/slab.h:618 [inline]
 iter_file_splice_write+0x143/0xa90 fs/splice.c:692
 do_splice_from fs/splice.c:851 [inline]
 direct_splice_actor+0x115/0x160 fs/splice.c:1018
 splice_direct_to_actor+0x27c/0x730 fs/splice.c:973
 do_splice_direct+0x164/0x210 fs/splice.c:1061
 do_sendfile+0x47f/0xb30 fs/read_write.c:1441
 SYSC_sendfile64 fs/read_write.c:1502 [inline]
 SyS_sendfile64+0xff/0x110 fs/read_write.c:1488
 do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
 entry_SYSCALL_64_after_hwframe+0x46/0xbb
RIP: 0033:0x45ccd9
RSP: 002b:00007f5f158b5c78 EFLAGS: 00000246 ORIG_RAX: 0000000000000028
RAX: ffffffffffffffda RBX: 0000000000026b80 RCX: 000000000045ccd9
RDX: 0000000000000000 RSI: 0000000000000006 RDI: 0000000000000005
RBP: 000000000078bf48 R08: 0000000000000000 R09: 0000000000000000
R10: 00008400fffffffa R11: 0000000000000246 R12: 000000000078bf0c
R13: 00007fff30ca3a8f R14: 00007f5f158b69c0 R15: 000000000078bf0c
INFO: rcu_sched detected stalls on CPUs/tasks:
	1-...: (10498 ticks this GP) idle=076/140000000000001/0 softirq=13240/13240 fqs=29 
	(detected by 0, t=10555 jiffies, g=882, c=881, q=3)
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 PID: 8356 Comm: syz-executor.1 Not tainted 4.14.192-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
task: ffff888059fa8280 task.stack: ffff88805a258000
RIP: 0010:lock_release+0x124/0x870 kernel/locking/lockdep.c:4015
RSP: 0018:ffff8880aeb07e30 EFLAGS: 00000807
RAX: dffffc0000000000 RBX: 1ffff11015d60fc9 RCX: 0000000000001995
RDX: 0000000000000000 RSI: 0000000000000001 RDI: ffff888059fa8b04
RBP: ffffffff87d93a08 R08: ffffffff8a085628 R09: 00000000000e403a
R10: 0000000000000000 R11: ffff888059fa8280 R12: ffffffff814f3b09
R13: ffff888059fa8280 R14: ffff8880aeb25ca8 R15: 0000000000000000
FS:  00007f5f158b6700(0000) GS:ffff8880aeb00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 0000001b31633000 CR3: 0000000095260000 CR4: 00000000001406e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 <IRQ>
 seqcount_lockdep_reader_access include/linux/seqlock.h:82 [inline]
 read_seqcount_begin include/linux/seqlock.h:164 [inline]
 ktime_get_update_offsets_now+0xd7/0x3f0 kernel/time/timekeeping.c:2230
 hrtimer_update_base kernel/time/hrtimer.c:505 [inline]
 hrtimer_interrupt+0x139/0x5e0 kernel/time/hrtimer.c:1309
 local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1075 [inline]
 smp_apic_timer_interrupt+0x117/0x5e0 arch/x86/kernel/apic/apic.c:1100
 apic_timer_interrupt+0x93/0xa0 arch/x86/entry/entry_64.S:793
 </IRQ>
RIP: 0010:get_current arch/x86/include/asm/current.h:15 [inline]
RIP: 0010:__sanitizer_cov_trace_pc+0x0/0x50 kernel/kcov.c:60
RSP: 0018:ffff88805a25f690 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff10
RAX: 0000000000000000 RBX: 000000000045ccd9 RCX: ffffc90006a82000
RDX: 0000000000040000 RSI: ffffffff81648af4 RDI: ffffffff87c0dba8
RBP: 000000000045ccd9 R08: 0000000000000000 R09: 0000000000020012
R10: ffff888059fa8b30 R11: ffff888059fa8280 R12: 0000000000000000
R13: 0000000000000000 R14: ffff88812fe527c0 R15: 0000000000000100
 rcu_read_unlock include/linux/rcupdate.h:681 [inline]
 is_bpf_text_address+0x7a/0x150 kernel/bpf/core.c:458
 kernel_text_address kernel/extable.c:150 [inline]
 kernel_text_address+0xbd/0xf0 kernel/extable.c:120
 __kernel_text_address+0x9/0x30 kernel/extable.c:105
 unwind_get_return_address arch/x86/kernel/unwind_orc.c:252 [inline]
 unwind_get_return_address+0x51/0x90 arch/x86/kernel/unwind_orc.c:247
 __save_stack_trace+0xa0/0x160 arch/x86/kernel/stacktrace.c:45
 save_stack mm/kasan/kasan.c:447 [inline]
 set_track mm/kasan/kasan.c:459 [inline]
 kasan_kmalloc+0xeb/0x160 mm/kasan/kasan.c:551
 __do_kmalloc mm/slab.c:3720 [inline]
 __kmalloc+0x15a/0x400 mm/slab.c:3729
 kmalloc_array include/linux/slab.h:607 [inline]
 kcalloc include/linux/slab.h:618 [inline]
 iter_file_splice_write+0x143/0xa90 fs/splice.c:692
 do_splice_from fs/splice.c:851 [inline]
 direct_splice_actor+0x115/0x160 fs/splice.c:1018
 splice_direct_to_actor+0x27c/0x730 fs/splice.c:973
 do_splice_direct+0x164/0x210 fs/splice.c:1061
 do_sendfile+0x47f/0xb30 fs/read_write.c:1441
 SYSC_sendfile64 fs/read_write.c:1502 [inline]
 SyS_sendfile64+0xff/0x110 fs/read_write.c:1488
 do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
 entry_SYSCALL_64_after_hwframe+0x46/0xbb
RIP: 0033:0x45ccd9
RSP: 002b:00007f5f158b5c78 EFLAGS: 00000246 ORIG_RAX: 0000000000000028
RAX: ffffffffffffffda RBX: 0000000000026b80 RCX: 000000000045ccd9
RDX: 0000000000000000 RSI: 0000000000000006 RDI: 0000000000000005
RBP: 000000000078bf48 R08: 0000000000000000 R09: 0000000000000000
R10: 00008400fffffffa R11: 0000000000000246 R12: 000000000078bf0c
R13: 00007fff30ca3a8f R14: 00007f5f158b69c0 R15: 000000000078bf0c
Code: 66 0f 1f 44 00 00 65 4c 8b 2c 25 40 ee 01 00 49 8d bd 84 08 00 00 48 b8 00 00 00 00 00 fc ff df 48 89 fa 48 c1 ea 03 0f b6 14 02 <48> 89 f8 83 e0 07 83 c0 03 38 d0 7c 08 84 d2 0f 85 fa 04 00 00 
rcu_sched kthread starved for 10477 jiffies! g882 c881 f0x0 RCU_GP_WAIT_FQS(3) ->state=0x0 ->cpu=0
rcu_sched       R  running task    30008     9      2 0x80000000
Call Trace:
 context_switch kernel/sched/core.c:2808 [inline]
 __schedule+0x88b/0x1de0 kernel/sched/core.c:3384
 schedule+0x8d/0x1b0 kernel/sched/core.c:3428
 schedule_timeout+0x4af/0xe90 kernel/time/timer.c:1746
 rcu_gp_kthread+0xc0a/0x1e60 kernel/rcu/tree.c:2255
 kthread+0x30d/0x420 kernel/kthread.c:232
 ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404
syz-executor.0 (8370) used greatest stack depth: 24216 bytes left
audit: type=1804 audit(1596658565.332:58): pid=8384 uid=0 auid=0 ses=4 subj=system_u:system_r:kernel_t:s0 op="invalid_pcr" cause="open_writers" comm="syz-executor.4" name="/root/syzkaller-testdir087489993/syzkaller.mvW2M0/39/bus" dev="sda1" ino=15839 res=1

Crashes (3):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2020/08/05 20:17 linux-4.14.y ca4f2c56d416 b7129355 .config console log report ci2-linux-4-14
2020/05/11 18:52 linux-4.14.y ab9dfda23248 9eb09c40 .config console log report ci2-linux-4-14
2020/03/04 07:16 linux-4.14.y 78d697fc93f9 1f73b64b .config console log report ci2-linux-4-14
* Struck through repros no longer work on HEAD.