INFO: rcu detected stall in ext4_file_write_iter

21 views
Skip to first unread message

syzbot

unread,
Apr 12, 2019, 12:30:11 PM4/12/19
to syzkaller...@googlegroups.com
Hello,

syzbot found the following crash on:

HEAD commit: 1ec8f1f0 Linux 4.14.111
git tree: linux-4.14.y
console output: https://syzkaller.appspot.com/x/log.txt?x=136ed6fd200000
kernel config: https://syzkaller.appspot.com/x/.config?x=fdadf290ea9fc6f9
dashboard link: https://syzkaller.appspot.com/bug?extid=0f14e80e289d4997740f
compiler: gcc (GCC) 9.0.0 20181231 (experimental)

Unfortunately, I don't have any reproducer for this crash yet.

IMPORTANT: if you fix the bug, please add the following tag to the commit:
Reported-by: syzbot+0f14e8...@syzkaller.appspotmail.com

audit: type=1804 audit(1555082859.632:93): pid=26137 uid=0 auid=4294967295
ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023
op="invalid_pcr" cause="open_writers" comm="syz-executor.2"
name="/root/syzkaller-testdir770443220/syzkaller.vnfIW8/454/bus" dev="sda1"
ino=18172 res=1
INFO: rcu_preempt self-detected stall on CPU
1-...: (1 GPs behind) idle=dae/140000000000001/0 softirq=97728/97732 fqs=1
(t=10500 jiffies g=32128 c=32127 q=171)
rcu_preempt kthread starved for 10496 jiffies! g32128 c32127 f0x0
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+0x7be/0x1cf0 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+0x31c/0x430 kernel/kthread.c:232
ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:402
NMI backtrace for cpu 1
CPU: 1 PID: 26128 Comm: syz-executor.4 Not tainted 4.14.111 #1
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+0x273/0xbd0 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+0x12c/0x600 arch/x86/kernel/apic/apic.c:1062
apic_timer_interrupt+0x8e/0xa0 arch/x86/entry/entry_64.S:787
</IRQ>
RIP: 0010:arch_local_irq_restore arch/x86/include/asm/paravirt.h:778
[inline]
RIP: 0010:lock_acquire+0x1ea/0x430 kernel/locking/lockdep.c:3997
RSP: 0018:ffff88809974f2a8 EFLAGS: 00000282 ORIG_RAX: ffffffffffffff10
RAX: 1ffffffff0ee2965 RBX: ffff88806dbbe5c0 RCX: 000000001ffc7b3a
RDX: dffffc0000000000 RSI: ffff88806dbbee90 RDI: 0000000000000282
RBP: ffff88809974f2f0 R08: 0000000000000000 R09: ffff88806dbbeeb0
R10: ffff88806dbbee90 R11: ffff88806dbbe5c0 R12: ffffffff8778ed60
R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000002
rcu_lock_acquire include/linux/rcupdate.h:244 [inline]
rcu_read_lock include/linux/rcupdate.h:631 [inline]
avc_has_perm_noaudit+0xca/0x420 security/selinux/avc.c:1106
cred_has_capability+0x12e/0x290 security/selinux/hooks.c:1745
selinux_capable+0x36/0x40 security/selinux/hooks.c:2225
security_capable+0x88/0xc0 security/security.c:279
ns_capable_common+0x73/0x160 kernel/capability.c:375
ns_capable kernel/capability.c:397 [inline]
capable+0x22/0x30 kernel/capability.c:431
should_remove_suid+0xa6/0xe0 fs/inode.c:1767
dentry_needs_remove_privs.part.0+0x18/0x60 fs/inode.c:1788
dentry_needs_remove_privs fs/inode.c:1833 [inline]
file_remove_privs+0x1f6/0x430 fs/inode.c:1824
__generic_file_write_iter+0x15e/0x5b0 mm/filemap.c:3095
ext4_file_write_iter+0x2c0/0xfd0 fs/ext4/file.c:264
call_write_iter include/linux/fs.h:1774 [inline]
do_iter_readv_writev+0x41e/0x680 fs/read_write.c:674
do_iter_write fs/read_write.c:953 [inline]
do_iter_write+0x154/0x550 fs/read_write.c:934
vfs_iter_write+0x77/0xb0 fs/read_write.c:966
iter_file_splice_write+0x578/0xae0 fs/splice.c:749
do_splice_from fs/splice.c:851 [inline]
direct_splice_actor+0x126/0x1a0 fs/splice.c:1018
splice_direct_to_actor+0x2a1/0x7b0 fs/splice.c:973
do_splice_direct+0x18d/0x230 fs/splice.c:1061
do_sendfile+0x4db/0xbd0 fs/read_write.c:1440
SYSC_sendfile64 fs/read_write.c:1501 [inline]
SyS_sendfile64+0x102/0x110 fs/read_write.c:1487
do_syscall_64+0x1eb/0x630 arch/x86/entry/common.c:289
entry_SYSCALL_64_after_hwframe+0x42/0xb7
RIP: 0033:0x458c29
RSP: 002b:00007fc820c65c78 EFLAGS: 00000246 ORIG_RAX: 0000000000000028
RAX: ffffffffffffffda RBX: 0000000000000004 RCX: 0000000000458c29
RDX: 0000000000000000 RSI: 0000000000000007 RDI: 0000000000000005
RBP: 000000000073bf00 R08: 0000000000000000 R09: 0000000000000000
R10: 00008000fffffffe R11: 0000000000000246 R12: 00007fc820c666d4
R13: 00000000004c5c9c R14: 00000000004da240 R15: 00000000ffffffff
INFO: rcu_sched detected stalls on CPUs/tasks:
1-...: (1 GPs behind) idle=dae/140000000000000/0 softirq=97727/97732 fqs=1
(detected by 0, t=10555 jiffies, g=17001, c=17000, q=3)
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 PID: 26128 Comm: syz-executor.4 Not tainted 4.14.111 #1
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
Google 01/01/2011
task: ffff88806dbbe5c0 task.stack: ffff888099748000
RIP: 0010:__sanitizer_cov_trace_pc+0x51/0x60 kernel/kcov.c:93
RSP: 0018:ffff88809974f248 EFLAGS: 00000246
RAX: 0000000000040000 RBX: 0000000000000002 RCX: ffffc90009a53000
RDX: 0000000000040000 RSI: ffffffff81c24948 RDI: 0000000000000282
RBP: ffff88809974f248 R08: ffff888077ee5348 R09: 0000000000000002
R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000
R13: ffff888215cfe400 R14: ffff888017d2c064 R15: ffff8880943858b0
FS: 00007fc820c66700(0000) GS:ffff8880aef00000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 0000001b2dd33000 CR3: 000000005df03000 CR4: 00000000001406e0
Call Trace:
brelse include/linux/buffer_head.h:295 [inline]
ext4_do_update_inode fs/ext4/inode.c:5179 [inline]
ext4_mark_iloc_dirty+0x16d8/0x2900 fs/ext4/inode.c:5691
ext4_mark_inode_dirty+0x1f0/0x870 fs/ext4/inode.c:5870
ext4_dirty_inode+0x73/0xa0 fs/ext4/inode.c:5901
__mark_inode_dirty+0x550/0x1040 fs/fs-writeback.c:2130
mark_inode_dirty include/linux/fs.h:2016 [inline]
generic_write_end+0x1b7/0x290 fs/buffer.c:2218
ext4_da_write_end+0x347/0x8f0 fs/ext4/inode.c:3181
generic_perform_write+0x2a2/0x490 mm/filemap.c:3035
__generic_file_write_iter+0x239/0x5b0 mm/filemap.c:3149
ext4_file_write_iter+0x2c0/0xfd0 fs/ext4/file.c:264
call_write_iter include/linux/fs.h:1774 [inline]
do_iter_readv_writev+0x41e/0x680 fs/read_write.c:674
do_iter_write fs/read_write.c:953 [inline]
do_iter_write+0x154/0x550 fs/read_write.c:934
vfs_iter_write+0x77/0xb0 fs/read_write.c:966
iter_file_splice_write+0x578/0xae0 fs/splice.c:749
do_splice_from fs/splice.c:851 [inline]
direct_splice_actor+0x126/0x1a0 fs/splice.c:1018
splice_direct_to_actor+0x2a1/0x7b0 fs/splice.c:973
do_splice_direct+0x18d/0x230 fs/splice.c:1061
do_sendfile+0x4db/0xbd0 fs/read_write.c:1440
SYSC_sendfile64 fs/read_write.c:1501 [inline]
SyS_sendfile64+0x102/0x110 fs/read_write.c:1487
do_syscall_64+0x1eb/0x630 arch/x86/entry/common.c:289
entry_SYSCALL_64_after_hwframe+0x42/0xb7
RIP: 0033:0x458c29
RSP: 002b:00007fc820c65c78 EFLAGS: 00000246 ORIG_RAX: 0000000000000028
RAX: ffffffffffffffda RBX: 0000000000000004 RCX: 0000000000458c29
RDX: 0000000000000000 RSI: 0000000000000007 RDI: 0000000000000005
RBP: 000000000073bf00 R08: 0000000000000000 R09: 0000000000000000
R10: 00008000fffffffe R11: 0000000000000246 R12: 00007fc820c666d4
R13: 00000000004c5c9c R14: 00000000004da240 R15: 00000000ffffffff
Code: 74 01 c3 55 48 89 e5 48 8b 75 08 48 8b 88 d0 12 00 00 8b 80 cc 12 00
00 48 8b 11 48 83 c2 01 48 39 d0 76 07 48 89 34 d1 48 89 11 <5d> c3 0f 1f
00 66 2e 0f 1f 84 00 00 00 00 00 55 48 89 e5 41 57
rcu_sched kthread starved for 10552 jiffies! g17001 c17000 f0x0
RCU_GP_WAIT_FQS(3) ->state=0x0 ->cpu=0
rcu_sched R running task 29776 9 2 0x80000000
Call Trace:
context_switch kernel/sched/core.c:2807 [inline]
__schedule+0x7be/0x1cf0 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+0x31c/0x430 kernel/kthread.c:232
ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:402


---
This bug is generated by a bot. It may contain errors.
See https://goo.gl/tpsmEJ for more information about syzbot.
syzbot engineers can be reached at syzk...@googlegroups.com.

syzbot will keep track of this bug report. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.

syzbot

unread,
Apr 20, 2019, 9:09:06 AM4/20/19
to syzkaller...@googlegroups.com
Hello,

syzbot found the following crash on:

HEAD commit: c98875d9 Linux 4.19.36
git tree: linux-4.19.y
console output: https://syzkaller.appspot.com/x/log.txt?x=118ef013200000
kernel config: https://syzkaller.appspot.com/x/.config?x=5e40ac5fbcc6366d
dashboard link: https://syzkaller.appspot.com/bug?extid=b0c07a7f1f6925ea6219
compiler: gcc (GCC) 9.0.0 20181231 (experimental)

Unfortunately, I don't have any reproducer for this crash yet.

IMPORTANT: if you fix the bug, please add the following tag to the commit:
Reported-by: syzbot+b0c07a...@syzkaller.appspotmail.com

audit: type=1804 audit(1555761973.955:354): pid=15997 uid=0 auid=4294967295
ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023
op=invalid_pcr cause=open_writers comm="syz-executor.3"
name="/root/syzkaller-testdir720252269/syzkaller.nVEy86/3628/bus"
dev="sda1" ino=16810 res=1
Enabling of bearer <ib:bridge_slave_0> rejected, failed to enable media
rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
rcu: (detected by 1, t=10502 jiffies, g=237509, q=88)
rcu: All QSes seen, last rcu_preempt kthread activity 10502
(4295097465-4295086963), jiffies_till_next_fqs=1, root ->qsmask 0x0
syz-executor.1 R running task 25984 15998 7798 0x00000000
Call Trace:
<IRQ>
sched_show_task kernel/sched/core.c:5297 [inline]
sched_show_task.cold+0x292/0x30b kernel/sched/core.c:5272
print_other_cpu_stall kernel/rcu/tree.c:1430 [inline]
check_cpu_stall kernel/rcu/tree.c:1557 [inline]
__rcu_pending kernel/rcu/tree.c:3293 [inline]
rcu_pending kernel/rcu/tree.c:3336 [inline]
rcu_check_callbacks.cold+0xaa1/0xd93 kernel/rcu/tree.c:2682
update_process_times+0x32/0x80 kernel/time/timer.c:1636
tick_sched_handle+0xa2/0x190 kernel/time/tick-sched.c:164
tick_sched_timer+0x47/0x130 kernel/time/tick-sched.c:1274
__run_hrtimer kernel/time/hrtimer.c:1398 [inline]
__hrtimer_run_queues+0x33e/0xde0 kernel/time/hrtimer.c:1460
hrtimer_interrupt+0x314/0x770 kernel/time/hrtimer.c:1518
local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1029 [inline]
smp_apic_timer_interrupt+0x120/0x570 arch/x86/kernel/apic/apic.c:1054
apic_timer_interrupt+0xf/0x20 arch/x86/entry/entry_64.S:867
</IRQ>
RIP: 0010:arch_local_save_flags arch/x86/include/asm/paravirt.h:783 [inline]
RIP: 0010:arch_local_irq_save arch/x86/include/asm/paravirt.h:805 [inline]
RIP: 0010:lock_acquire+0x85/0x3f0 kernel/locking/lockdep.c:3898
Code: 02 00 00 8b b3 7c 08 00 00 85 f6 0f 85 83 01 00 00 48 c7 c0 00 33 72
88 48 ba 00 00 00 00 00 fc ff df 48 c1 e8 03 80 3c 10 00 <0f> 85 f9 02 00
00 48 83 3d dd 8d 1f 07 00 0f 84 82 02 00 00 9c 58
RSP: 0018:ffff8880a8657378 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff13
RAX: 1ffffffff10e4660 RBX: ffff8880602ce640 RCX: 0000000000000002
RDX: dffffc0000000000 RSI: 0000000000000000 RDI: ffff8880602ceebc
RBP: ffff8880a86573c0 R08: 0000000000000000 R09: 0000000000000000
R10: ffffed1015d24732 R11: 0000000000000000 R12: ffffffff8879d3e0
R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000002
rcu_lock_acquire include/linux/rcupdate.h:244 [inline]
rcu_read_lock include/linux/rcupdate.h:629 [inline]
wb_get_create_current include/linux/backing-dev.h:300 [inline]
balance_dirty_pages_ratelimited+0x73c/0x1f50 mm/page-writeback.c:1873
generic_perform_write+0x35a/0x530 mm/filemap.c:3175
__generic_file_write_iter+0x25e/0x630 mm/filemap.c:3264
ext4_file_write_iter+0x33f/0x11a0 fs/ext4/file.c:266
call_write_iter include/linux/fs.h:1811 [inline]
do_iter_readv_writev+0x55d/0x830 fs/read_write.c:680
do_iter_write fs/read_write.c:959 [inline]
do_iter_write+0x184/0x600 fs/read_write.c:940
vfs_iter_write+0x77/0xb0 fs/read_write.c:972
iter_file_splice_write+0x667/0xbe0 fs/splice.c:750
do_splice_from fs/splice.c:852 [inline]
direct_splice_actor+0x126/0x1a0 fs/splice.c:1019
splice_direct_to_actor+0x2ea/0x890 fs/splice.c:974
do_splice_direct+0x1da/0x2a0 fs/splice.c:1062
do_sendfile+0x597/0xce0 fs/read_write.c:1446
__do_sys_sendfile64 fs/read_write.c:1507 [inline]
__se_sys_sendfile64 fs/read_write.c:1493 [inline]
__x64_sys_sendfile64+0x1dd/0x220 fs/read_write.c:1493
do_syscall_64+0x103/0x610 arch/x86/entry/common.c:290
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x458c29
Code: ad b8 fb ff c3 66 2e 0f 1f 84 00 00 00 00 00 66 90 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 0f 83 7b b8 fb ff c3 66 2e 0f 1f 84 00 00 00 00
RSP: 002b:00007f6668809c78 EFLAGS: 00000246 ORIG_RAX: 0000000000000028
RAX: ffffffffffffffda RBX: 0000000000000004 RCX: 0000000000458c29
RDX: 0000000000000000 RSI: 0000000000000009 RDI: 0000000000000007
RBP: 000000000073bfa0 R08: 0000000000000000 R09: 0000000000000000
R10: 00008000fffffffe R11: 0000000000000246 R12: 00007f666880a6d4
R13: 00000000004c5e10 R14: 00000000004da5c8 R15: 00000000ffffffff
rcu: rcu_preempt kthread starved for 10502 jiffies! g237509 f0x2
RCU_GP_WAIT_FQS(5) ->state=0x0 ->cpu=0
rcu: RCU grace-period kthread stack dump:
rcu_preempt R running task 29104 10 2 0x80000000
Call Trace:
context_switch kernel/sched/core.c:2826 [inline]
__schedule+0x813/0x1d00 kernel/sched/core.c:3474
schedule+0x92/0x1c0 kernel/sched/core.c:3518
schedule_timeout+0x4db/0xfd0 kernel/time/timer.c:1804
rcu_gp_kthread+0xd5c/0x2190 kernel/rcu/tree.c:2202
kthread+0x357/0x430 kernel/kthread.c:246
ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:413

syzbot

unread,
Jun 22, 2019, 8:58:07 AM6/22/19
to syzkaller...@googlegroups.com
syzbot has found a reproducer for the following crash on:

HEAD commit: 63bbbcd8 Linux 4.19.54
git tree: linux-4.19.y
console output: https://syzkaller.appspot.com/x/log.txt?x=1464241aa00000
kernel config: https://syzkaller.appspot.com/x/.config?x=70330221b6dd6ab1
dashboard link: https://syzkaller.appspot.com/bug?extid=b0c07a7f1f6925ea6219
compiler: gcc (GCC) 9.0.0 20181231 (experimental)
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=15d22e69a00000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=15e0941aa00000

IMPORTANT: if you fix the bug, please add the following tag to the commit:
Reported-by: syzbot+b0c07a...@syzkaller.appspotmail.com

audit: type=1400 audit(1561207928.558:36): avc: denied { map } for
pid=7583 comm="syz-executor978" path="/root/syz-executor978141630"
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
rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
rcu: (detected by 1, t=10502 jiffies, g=5293, q=20)
rcu: All QSes seen, last rcu_preempt kthread activity 10503
(4295055363-4295044860), jiffies_till_next_fqs=1, root ->qsmask 0x0
syz-executor978 R running task 26464 7592 7585 0x00000000
Call Trace:
<IRQ>
sched_show_task kernel/sched/core.c:5297 [inline]
sched_show_task.cold+0x292/0x30b kernel/sched/core.c:5272
print_other_cpu_stall kernel/rcu/tree.c:1430 [inline]
check_cpu_stall kernel/rcu/tree.c:1557 [inline]
__rcu_pending kernel/rcu/tree.c:3293 [inline]
rcu_pending kernel/rcu/tree.c:3336 [inline]
rcu_check_callbacks.cold+0xaa1/0xd93 kernel/rcu/tree.c:2682
update_process_times+0x32/0x80 kernel/time/timer.c:1636
tick_sched_handle+0xa2/0x190 kernel/time/tick-sched.c:164
tick_sched_timer+0x47/0x130 kernel/time/tick-sched.c:1274
__run_hrtimer kernel/time/hrtimer.c:1398 [inline]
__hrtimer_run_queues+0x33b/0xdd0 kernel/time/hrtimer.c:1460
hrtimer_interrupt+0x314/0x770 kernel/time/hrtimer.c:1518
local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1029 [inline]
smp_apic_timer_interrupt+0x111/0x550 arch/x86/kernel/apic/apic.c:1054
apic_timer_interrupt+0xf/0x20 arch/x86/entry/entry_64.S:869
</IRQ>
RIP: 0010:arch_local_save_flags arch/x86/include/asm/paravirt.h:783 [inline]
RIP: 0010:arch_local_irq_save arch/x86/include/asm/paravirt.h:805 [inline]
RIP: 0010:lock_is_held_type+0x87/0x210 kernel/locking/lockdep.c:3934
Code: 72 88 48 ba 00 00 00 00 00 fc ff df 48 c1 e8 03 80 3c 10 00 0f 85 69
01 00 00 48 83 3d d1 8e 20 07 00 0f 84 20 01 00 00 9c 58 <0f> 1f 44 00 00
48 c7 c2 50 36 72 88 48 89 c3 48 b8 00 00 00 00 00
RSP: 0018:ffff8880908b7428 EFLAGS: 00000286 ORIG_RAX: ffffffffffffff13
RAX: 0000000000000286 RBX: ffff8880a112e700 RCX: 0000000000000000
RDX: dffffc0000000000 RSI: 00000000ffffffff RDI: ffff8880a112ef7c
RBP: ffff8880908b7448 R08: ffff8880a112e700 R09: ffffed1015d24733
R10: ffffed1015d24732 R11: ffff8880ae923993 R12: ffffffff8879d760
R13: ffff88808efad4f0 R14: 000000000496d9e4 R15: ffff88808efad6f0
lock_is_held include/linux/lockdep.h:344 [inline]
rcu_read_lock_sched_held+0x110/0x130 kernel/rcu/update.c:118
trace_ext4_da_write_end include/trace/events/ext4.h:382 [inline]
ext4_da_write_end+0x865/0xa50 fs/ext4/inode.c:3146
generic_perform_write+0x2ed/0x520 mm/filemap.c:3150
__generic_file_write_iter+0x25e/0x630 mm/filemap.c:3264
ext4_file_write_iter+0x32b/0x1060 fs/ext4/file.c:266
call_write_iter include/linux/fs.h:1820 [inline]
do_iter_readv_writev+0x558/0x830 fs/read_write.c:681
do_iter_write fs/read_write.c:960 [inline]
do_iter_write+0x184/0x5f0 fs/read_write.c:941
vfs_iter_write+0x77/0xb0 fs/read_write.c:973
iter_file_splice_write+0x661/0xbd0 fs/splice.c:750
do_splice_from fs/splice.c:852 [inline]
direct_splice_actor+0x123/0x190 fs/splice.c:1019
splice_direct_to_actor+0x2e7/0x890 fs/splice.c:974
do_splice_direct+0x1da/0x2a0 fs/splice.c:1062
do_sendfile+0x597/0xce0 fs/read_write.c:1447
__do_sys_sendfile64 fs/read_write.c:1502 [inline]
__se_sys_sendfile64 fs/read_write.c:1494 [inline]
__x64_sys_sendfile64+0x15a/0x220 fs/read_write.c:1494
do_syscall_64+0xfd/0x620 arch/x86/entry/common.c:293
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x4417c9
Code: e8 7c e7 ff ff 48 83 c4 18 c3 0f 1f 80 00 00 00 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 0f 83 bb 07 fc ff c3 66 2e 0f 1f 84 00 00 00 00
RSP: 002b:00007ffedf309698 EFLAGS: 00000246 ORIG_RAX: 0000000000000028
RAX: ffffffffffffffda RBX: 00007ffedf309840 RCX: 00000000004417c9
RDX: 0000000020000000 RSI: 0000000000000003 RDI: 0000000000000003
RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000000
R10: 00008080fffffffe R11: 0000000000000246 R12: 0000000000000000
R13: 00000000004024a0 R14: 0000000000000000 R15: 0000000000000000
rcu: rcu_preempt kthread starved for 10549 jiffies! g5293 f0x2
RCU_GP_WAIT_FQS(5) ->state=0x0 ->cpu=0
rcu: RCU grace-period kthread stack dump:
rcu_preempt R running task 29624 10 2 0x80000000
Call Trace:
context_switch kernel/sched/core.c:2826 [inline]
__schedule+0x80d/0x1c70 kernel/sched/core.c:3474
schedule+0x92/0x1c0 kernel/sched/core.c:3518
schedule_timeout+0x4db/0xfc0 kernel/time/timer.c:1804
rcu_gp_kthread+0xd5c/0x2190 kernel/rcu/tree.c:2202
kthread+0x354/0x420 kernel/kthread.c:246
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415

syzbot

unread,
Jun 29, 2019, 1:33:06 AM6/29/19
to syzkaller...@googlegroups.com
syzbot has found a reproducer for the following crash on:

HEAD commit: f4cc0ed9 Linux 4.14.131
git tree: linux-4.14.y
console output: https://syzkaller.appspot.com/x/log.txt?x=123e2355a00000
kernel config: https://syzkaller.appspot.com/x/.config?x=ab1953b2cdac00f5
dashboard link: https://syzkaller.appspot.com/bug?extid=0f14e80e289d4997740f
compiler: gcc (GCC) 9.0.0 20181231 (experimental)
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=112f9503a00000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=14702c33a00000

IMPORTANT: if you fix the bug, please add the following tag to the commit:
Reported-by: syzbot+0f14e8...@syzkaller.appspotmail.com

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

Reply all
Reply to author
Forward
0 new messages