bisecting fixing commit since f4cc0ed9b2c72687303b035379c5824a02224354
building syzkaller on 7509bf360eba1461ac6059e4cacfbc29c9d2d4c7
testing commit f4cc0ed9b2c72687303b035379c5824a02224354 with gcc (GCC) 8.1.0
kernel signature: 9b7b55190a74acd23902c28cef0bbea2e3ebf16e9087253a6850a4d86e5c4004
run #0: crashed: INFO: rcu detected stall in ext4_file_write_iter
run #1: crashed: INFO: rcu detected stall in corrupted
run #2: crashed: INFO: rcu detected stall in corrupted
run #3: crashed: INFO: rcu detected stall in corrupted
run #4: crashed: INFO: rcu detected stall in corrupted
run #5: crashed: INFO: rcu detected stall in corrupted
run #6: crashed: INFO: rcu detected stall in sendfile64
run #7: crashed: INFO: rcu detected stall in corrupted
run #8: crashed: INFO: rcu detected stall in ext4_file_write_iter
run #9: crashed: INFO: rcu detected stall in ext4_file_write_iter
testing current HEAD 4f68020fef1c6cf1b680ffb6481ac41379283ea3
testing commit 4f68020fef1c6cf1b680ffb6481ac41379283ea3 with gcc (GCC) 8.1.0
kernel signature: e15c7d28cb091de94b361a873c5ca4edc5c88a8b207ba6b67f1b474ed65ae756
run #0: crashed: INFO: rcu detected stall in corrupted
run #1: crashed: INFO: rcu detected stall in rw_verify_area
run #2: crashed: INFO: rcu detected stall in ext4_file_write_iter
run #3: crashed: INFO: rcu detected stall in corrupted
run #4: crashed: INFO: rcu detected stall in sendfile64
run #5: crashed: INFO: rcu detected stall in corrupted
run #6: crashed: INFO: rcu detected stall in sendfile64
run #7: crashed: INFO: rcu detected stall in sendfile64
run #8: crashed: INFO: rcu detected stall in corrupted
run #9: crashed: INFO: rcu detected stall in corrupted
revisions tested: 2, total time: 26m25.396715214s (build: 16m15.088825724s, test: 9m41.061878879s)
the crash still happens on HEAD
commit msg: Linux 4.14.182
crash: INFO: rcu detected stall in corrupted
IPv6: ADDRCONF(NETDEV_UP): veth0_to_bridge: link is not ready
IPv6: ADDRCONF(NETDEV_CHANGE): veth0_to_hsr: link becomes ready
IPv6: ADDRCONF(NETDEV_CHANGE): hsr_slave_0: link becomes ready
IPv6: ADDRCONF(NETDEV_CHANGE): veth0_to_bridge: link becomes ready
INFO: rcu_preempt self-detected stall on CPU
0-...: (1 GPs behind) idle=96e/140000000000001/0 softirq=9348/9355 fqs=18
(t=10501 jiffies g=1308 c=1307 q=763)
rcu_preempt kthread starved for 10464 jiffies! g1308 c1307 f0x0 RCU_GP_WAIT_FQS(3) ->state=0x0 ->cpu=1
INFO: rcu_preempt detected stalls on CPUs/tasks:
rcu_preempt R running task 29720 8 2 0x80000000
0-...: (1 GPs behind) idle=96e/140000000000001/0 softirq=9348/9355 fqs=18
Call Trace:
context_switch kernel/sched/core.c:2808 [inline]
__schedule+0x780/0x1d20 kernel/sched/core.c:3384
schedule+0x7f/0x1b0 kernel/sched/core.c:3428
schedule_timeout+0x40c/0xcc0 kernel/time/timer.c:1746
rcu_gp_kthread+0xbbf/0x1e00 kernel/rcu/tree.c:2255
(detected by 1, t=10502 jiffies, g=1308, c=1307, q=763)
Sending NMI from CPU 1 to CPUs 0:
kthread+0x338/0x400 kernel/kthread.c:232
NMI backtrace for cpu 0
CPU: 0 PID: 7003 Comm: syz-executor.3 Not tainted 4.14.182-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
task: ffff8880a492e400 task.stack: ffff88808f8e0000
RIP: 0010:io_serial_in+0x60/0x90 drivers/tty/serial/8250/8250_port.c:451
RSP: 0018:ffff8880aee07840 EFLAGS: 00000006
RAX: dffffc0000000005 RBX: ffffffff89d4e780 RCX: 0000000000000000
RDX: 00000000000003f9 RSI: 00000000000003f9 RDI: ffffffff89d4e7b8
RBP: ffff8880aee07850 R08: ffff8880a492ed20 R09: 00000000000076b7
R10: 0000000000000078 R11: ffff8880a492e400 R12: ffffffff89d4e9a0
R13: dffffc0000000000 R14: ffffffff89d4e780 R15: ffffffff89d4e7c8
FS: 00007facd39ef700(0000) GS:ffff8880aee00000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 0000000000758080 CR3: 0000000090bb5000 CR4: 00000000001406f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
serial_port_in include/linux/serial_core.h:261 [inline]
serial8250_console_write+0x240/0x860 drivers/tty/serial/8250/8250_port.c:3241
univ8250_console_write+0x4e/0x70 drivers/tty/serial/8250/8250_core.c:596
call_console_drivers kernel/printk/printk.c:1725 [inline]
console_unlock+0x8c2/0xe30 kernel/printk/printk.c:2397
vprintk_emit+0x1b4/0x4e0 kernel/printk/printk.c:1923
vprintk_default+0x1a/0x20 kernel/printk/printk.c:1963
vprintk_func+0x49/0x12c kernel/printk/printk_safe.c:401
printk+0x91/0xab kernel/printk/printk.c:1996
printk_stack_address arch/x86/kernel/dumpstack.c:70 [inline]
show_trace_log_lvl+0x22d/0x26b arch/x86/kernel/dumpstack.c:202
show_stack+0x38/0x3a arch/x86/kernel/dumpstack.c:237
sched_show_task.cold.89+0x2e1/0x342 kernel/sched/core.c:5168
rcu_check_gp_kthread_starvation+0x288/0x2c1 kernel/rcu/tree.c:1374
print_cpu_stall kernel/rcu/tree.c:1540 [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.77+0x40d/0xcfa kernel/rcu/tree.c:2792
update_process_times+0x2a/0x60 kernel/time/timer.c:1590
tick_sched_handle+0x7b/0x140 kernel/time/tick-sched.c:165
tick_sched_timer+0x34/0xf0 kernel/time/tick-sched.c:1223
__run_hrtimer kernel/time/hrtimer.c:1223 [inline]
__hrtimer_run_queues+0x297/0xaf0 kernel/time/hrtimer.c:1287
hrtimer_interrupt+0x1ae/0x600 kernel/time/hrtimer.c:1321
local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1075 [inline]
smp_apic_timer_interrupt+0x11f/0x5d0 arch/x86/kernel/apic/apic.c:1100
apic_timer_interrupt+0x9a/0xa0 arch/x86/entry/entry_64.S:793
RIP: 0010:splice_direct_to_actor+0x2aa/0x750 fs/splice.c:981
RSP: 0018:ffff88808f8e7b60 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff10
RAX: 000000000000001c RBX: 0000000078cd2200 RCX: 1ffff11011f1cf96
RDX: 000000000732ce00 RSI: ffff8880a492ec88 RDI: dffffc0000000000
RBP: ffff88808f8e7c50 R08: ffff8880a492eca8 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000000 R12: 000000000732ce00
R13: ffff88808f8e7c98 R14: 000000000732cde4 R15: ffff888094d730c0
do_splice_direct+0x144/0x250 fs/splice.c:1061
do_sendfile+0x463/0xd00 fs/read_write.c:1441
SYSC_sendfile64 fs/read_write.c:1496 [inline]
SyS_sendfile64+0x97/0x110 fs/read_write.c:1488
do_syscall_64+0x1c7/0x5b0 arch/x86/entry/common.c:292
entry_SYSCALL_64_after_hwframe+0x46/0xbb
RIP: 0033:0x459519
RSP: 002b:00007facd39eec78 EFLAGS: 00000246 ORIG_RAX: 0000000000000028
RAX: ffffffffffffffda RBX: 0000000000000004 RCX: 0000000000459519
RDX: 0000000020000000 RSI: 0000000000000003 RDI: 0000000000000003
RBP: 000000000075bf20 R08: 0000000000000000 R09: 0000000000000000
R10: 00008080fffffffe R11: 0000000000000246 R12: 00007facd39ef6d4
R13: 00000000004c6af0 R14: 00000000004dbd68 R15: 00000000ffffffff
Code: 34 0f b6 8b d1 00 00 00 48 8d 7b 38 48 b8 00 00 00 00 00 fc ff df 48 89 fa 48 c1 ea 03 d3 e6 80 3c 02 00 75 1d 03 73 38 89 f2 ec <48> 83 c4 08 0f b6 c0 5b 5d c3 89 75 f4 e8 ee 3b 6e fe 8b 75 f4
rcu_preempt kthread starved for 10465 jiffies! g1308 c1307 f0x0 RCU_GP_WAIT_FQS(3) ->state=0x0 ->cpu=1
rcu_preempt R
running task
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404
29720 8 2 0x80000000
NMI backtrace for cpu 0
Call Trace:
CPU: 0 PID: 7003 Comm: syz-executor.3 Not tainted 4.14.182-syzkaller #0
context_switch kernel/sched/core.c:2808 [inline]
__schedule+0x780/0x1d20 kernel/sched/core.c:3384
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
__dump_stack lib/dump_stack.c:17 [inline]
dump_stack+0xf7/0x13b lib/dump_stack.c:58
schedule+0x7f/0x1b0 kernel/sched/core.c:3428
nmi_cpu_backtrace.cold.4+0x3e/0x76 lib/nmi_backtrace.c:101
schedule_timeout+0x40c/0xcc0 kernel/time/timer.c:1746
nmi_trigger_cpumask_backtrace+0xe6/0x11a 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+0x172/0x1bf kernel/rcu/tree.c:1396
rcu_gp_kthread+0xbbf/0x1e00 kernel/rcu/tree.c:2255
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.77+0x415/0xcfa kernel/rcu/tree.c:2792
kthread+0x338/0x400 kernel/kthread.c:232
update_process_times+0x2a/0x60 kernel/time/timer.c:1590
tick_sched_handle+0x7b/0x140 kernel/time/tick-sched.c:165
tick_sched_timer+0x34/0xf0 kernel/time/tick-sched.c:1223
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404
__run_hrtimer kernel/time/hrtimer.c:1223 [inline]
__hrtimer_run_queues+0x297/0xaf0 kernel/time/hrtimer.c:1287
hrtimer_interrupt+0x1ae/0x600 kernel/time/hrtimer.c:1321
local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1075 [inline]
smp_apic_timer_interrupt+0x11f/0x5d0 arch/x86/kernel/apic/apic.c:1100
apic_timer_interrupt+0x9a/0xa0 arch/x86/entry/entry_64.S:793
RIP: 0010:splice_direct_to_actor+0x2aa/0x750 fs/splice.c:981
RSP: 0018:ffff88808f8e7b60 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff10
RAX: 000000000000001c RBX: 0000000078cd2200 RCX: 1ffff11011f1cf96
RDX: 000000000732ce00 RSI: ffff8880a492ec88 RDI: dffffc0000000000
RBP: ffff88808f8e7c50 R08: ffff8880a492eca8 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000000 R12: 000000000732ce00
R13: ffff88808f8e7c98 R14: 000000000732cde4 R15: ffff888094d730c0
do_splice_direct+0x144/0x250 fs/splice.c:1061
do_sendfile+0x463/0xd00 fs/read_write.c:1441
SYSC_sendfile64 fs/read_write.c:1496 [inline]
SyS_sendfile64+0x97/0x110 fs/read_write.c:1488
do_syscall_64+0x1c7/0x5b0 arch/x86/entry/common.c:292
entry_SYSCALL_64_after_hwframe+0x46/0xbb
RIP: 0033:0x459519
RSP: 002b:00007facd39eec78 EFLAGS: 00000246 ORIG_RAX: 0000000000000028
RAX: ffffffffffffffda RBX: 0000000000000004 RCX: 0000000000459519
RDX: 0000000020000000 RSI: 0000000000000003 RDI: 0000000000000003
RBP: 000000000075bf20 R08: 0000000000000000 R09: 0000000000000000
R10: 00008080fffffffe R11: 0000000000000246 R12: 00007facd39ef6d4
R13: 00000000004c6af0 R14: 00000000004dbd68 R15: 00000000ffffffff
INFO: rcu_sched detected stalls on CPUs/tasks:
0-...: (1 GPs behind) idle=96e/140000000000000/0 softirq=9348/9355 fqs=18
(detected by 1, t=10502 jiffies, g=344, c=343, q=15)
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 7003 Comm: syz-executor.3 Not tainted 4.14.182-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
task: ffff8880a492e400 task.stack: ffff88808f8e0000
RIP: 0010:lock_is_held_type+0x141/0x210 kernel/locking/lockdep.c:4037
RSP: 0018:ffff88808f8e7080 EFLAGS: 00000807
RAX: 0000000000000000 RBX: 0000000000000282 RCX: 0000000000000000
RDX: 1ffff11014925d90 RSI: ffffffff87990ee0 RDI: ffff8880a492ec84
RBP: ffff88808f8e70a0 R08: ffff8880a492ecd0 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000000 R12: ffff8880a492e400
R13: 0000000000000000 R14: 0000000000000565 R15: ffff88807d91fdc8
FS: 00007facd39ef700(0000) GS:ffff8880aee00000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 0000000000758080 CR3: 0000000090bb5000 CR4: 00000000001406f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
lock_is_held include/linux/lockdep.h:437 [inline]
___might_sleep+0x23b/0x2a0 kernel/sched/core.c:6006
__might_sleep+0x93/0xb0 kernel/sched/core.c:5994
__getblk_gfp+0x3a/0x5f0 fs/buffer.c:1381
sb_getblk include/linux/buffer_head.h:333 [inline]
__ext4_get_inode_loc+0x32b/0xe30 fs/ext4/inode.c:4515
ext4_get_inode_loc fs/ext4/inode.c:4628 [inline]
ext4_reserve_inode_write+0xd7/0x220 fs/ext4/inode.c:5788
ext4_mark_inode_dirty+0x12b/0x7b0 fs/ext4/inode.c:5955
ext4_dirty_inode+0x63/0x90 fs/ext4/inode.c:5994
__mark_inode_dirty+0x542/0xe80 fs/fs-writeback.c:2144
mark_inode_dirty include/linux/fs.h:2020 [inline]
generic_write_end+0x162/0x220 fs/buffer.c:2229
ext4_da_write_end+0x2d6/0xa20 fs/ext4/inode.c:3200
generic_perform_write+0x318/0x450 mm/filemap.c:3058
__generic_file_write_iter+0x201/0x580 mm/filemap.c:3172
ext4_file_write_iter+0x27a/0xe40 fs/ext4/file.c:270
call_write_iter include/linux/fs.h:1778 [inline]
do_iter_readv_writev+0x460/0x900 fs/read_write.c:675
do_iter_write+0x12b/0x520 fs/read_write.c:954
vfs_iter_write+0x5b/0xb0 fs/read_write.c:967
iter_file_splice_write+0x540/0xc20 fs/splice.c:749
do_splice_from fs/splice.c:851 [inline]
direct_splice_actor+0x104/0x1c0 fs/splice.c:1018
splice_direct_to_actor+0x27c/0x750 fs/splice.c:973
do_splice_direct+0x144/0x250 fs/splice.c:1061
do_sendfile+0x463/0xd00 fs/read_write.c:1441
SYSC_sendfile64 fs/read_write.c:1496 [inline]
SyS_sendfile64+0x97/0x110 fs/read_write.c:1488
do_syscall_64+0x1c7/0x5b0 arch/x86/entry/common.c:292
entry_SYSCALL_64_after_hwframe+0x46/0xbb
RIP: 0033:0x459519
RSP: 002b:00007facd39eec78 EFLAGS: 00000246 ORIG_RAX: 0000000000000028
RAX: ffffffffffffffda RBX: 0000000000000004 RCX: 0000000000459519
RDX: 0000000020000000 RSI: 0000000000000003 RDI: 0000000000000003
RBP: 000000000075bf20 R08: 0000000000000000 R09: 0000000000000000
R10: 00008080fffffffe R11: 0000000000000246 R12: 00007facd39ef6d4
R13: 00000000004c6af0 R14: 00000000004dbd68 R15: 00000000ffffffff
Code: ff ff 65 4c 8b 24 25 40 ee 01 00 49 8d bc 24 84 08 00 00 41 89 c5 48 b8 00 00 00 00 00 fc ff df 48 89 fa 48 c1 ea 03 0f b6 04 02 <48> 89 fa 83 e2 07 83 c2 03 38 c2 7c 04 84 c0 75 76 48 c7 c7 08
rcu_sched kthread starved for 10465 jiffies! g344 c343 f0x0 RCU_GP_WAIT_FQS(3) ->state=0x0 ->cpu=1
rcu_sched R running task 29832 9 2 0x80000000
Call Trace:
context_switch kernel/sched/core.c:2808 [inline]
__schedule+0x780/0x1d20 kernel/sched/core.c:3384
schedule+0x7f/0x1b0 kernel/sched/core.c:3428
schedule_timeout+0x40c/0xcc0 kernel/time/timer.c:1746
rcu_gp_kthread+0xbbf/0x1e00 kernel/rcu/tree.c:2255
kthread+0x338/0x400 kernel/kthread.c:232
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404