INFO: rcu detected stall in ext4_file_write_iter

[syzbot <syzbot+7d19c5fe6a3f1161abb7@syzkaller.appspotmail.com>]

Hello,

syzbot found the following crash on:

HEAD commit:    8a61716ff2ab Merge tag 'ceph-for-5.0-rc8' of git://github...
git tree:       upstream
console output: https://syzkaller.appspot.com/x/log.txt?x=161b71d4c00000
kernel config:  https://syzkaller.appspot.com/x/.config?x=7132344728e7ec3f
dashboard link: https://syzkaller.appspot.com/bug?extid=7d19c5fe6a3f1161abb7
compiler:       gcc (GCC) 9.0.0 20181231 (experimental)
syz repro:      https://syzkaller.appspot.com/x/repro.syz?x=103908f8c00000
C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=105e5cd0c00000

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

audit: type=1400 audit(1550814986.750:36): avc:  denied  { map } for   
pid=8058 comm="syz-executor004" path="/root/syz-executor004991115"  
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
hrtimer: interrupt took 42841 ns
rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
rcu: 	(detected by 1, t=10502 jiffies, g=5873, q=2)
rcu: All QSes seen, last rcu_preempt kthread activity 10502  
(4295059997-4295049495), jiffies_till_next_fqs=1, root ->qsmask 0x0
syz-executor004 R  running task    26448  8069   8060 0x00000000
Call Trace:
  <IRQ>
  sched_show_task kernel/sched/core.c:5306 [inline]
  sched_show_task.cold+0x292/0x30b kernel/sched/core.c:5281
  print_other_cpu_stall kernel/rcu/tree.c:1301 [inline]
  check_cpu_stall kernel/rcu/tree.c:1429 [inline]
  rcu_pending kernel/rcu/tree.c:3018 [inline]
  rcu_check_callbacks.cold+0xa10/0xa4a kernel/rcu/tree.c:2521
  update_process_times+0x32/0x80 kernel/time/timer.c:1635
  tick_sched_handle+0xa2/0x190 kernel/time/tick-sched.c:161
  tick_sched_timer+0x47/0x130 kernel/time/tick-sched.c:1271
  __run_hrtimer kernel/time/hrtimer.c:1389 [inline]
  __hrtimer_run_queues+0x33e/0xde0 kernel/time/hrtimer.c:1451
  hrtimer_interrupt+0x314/0x770 kernel/time/hrtimer.c:1509
  local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1035 [inline]
  smp_apic_timer_interrupt+0x120/0x570 arch/x86/kernel/apic/apic.c:1060
  apic_timer_interrupt+0xf/0x20 arch/x86/entry/entry_64.S:807
  </IRQ>
RIP: 0010:__sanitizer_cov_trace_pc+0x0/0x50 kernel/kcov.c:94
Code: e5 08 41 bc f4 ff ff ff e8 11 9f ea ff 48 c7 05 12 fb e5 08 00 00 00  
00 e9 c8 e9 ff ff 90 90 90 90 90 90 90 90 90 90 90 90 90 <55> 48 89 e5 48  
8b 75 08 65 48 8b 04 25 40 ee 01 00 65 8b 15 38 0c
RSP: 0018:ffff888084ed72c0 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff13
RAX: dffffc0000000000 RBX: ffff88809a2205c0 RCX: ffffffff81e7c36c
RDX: 1ffff11013444114 RSI: ffffffff81e7c37a RDI: ffff88809a2208a0
RBP: ffff888084ed7300 R08: ffff88808fa28240 R09: ffffed1015d25bd0
R10: ffffed1015d25bcf R11: ffff8880ae92de7b R12: 0000000000000002
R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000001
  __ext4_journal_start fs/ext4/ext4_jbd2.h:311 [inline]
  ext4_dirty_inode+0x64/0xc0 fs/ext4/inode.c:6081
  __mark_inode_dirty+0x919/0x1290 fs/fs-writeback.c:2155
  mark_inode_dirty include/linux/fs.h:2125 [inline]
  __generic_write_end+0x1b9/0x240 fs/buffer.c:2118
  generic_write_end+0x6c/0x90 fs/buffer.c:2163
  ext4_da_write_end+0x3c8/0xa50 fs/ext4/inode.c:3204
  generic_perform_write+0x2f0/0x530 mm/filemap.c:3219
  __generic_file_write_iter+0x25e/0x630 mm/filemap.c:3333
  ext4_file_write_iter+0x33f/0x1160 fs/ext4/file.c:266
  call_write_iter include/linux/fs.h:1863 [inline]
  do_iter_readv_writev+0x5e0/0x8e0 fs/read_write.c:680
  do_iter_write fs/read_write.c:956 [inline]
  do_iter_write+0x184/0x610 fs/read_write.c:937
  vfs_iter_write+0x77/0xb0 fs/read_write.c:969
  iter_file_splice_write+0x667/0xbe0 fs/splice.c:749
  do_splice_from fs/splice.c:851 [inline]
  direct_splice_actor+0x126/0x1a0 fs/splice.c:1023
  splice_direct_to_actor+0x369/0x970 fs/splice.c:978
  do_splice_direct+0x1da/0x2a0 fs/splice.c:1066
  do_sendfile+0x597/0xd00 fs/read_write.c:1436
  __do_sys_sendfile64 fs/read_write.c:1491 [inline]
  __se_sys_sendfile64 fs/read_write.c:1483 [inline]
  __x64_sys_sendfile64+0x15a/0x220 fs/read_write.c:1483
  do_syscall_64+0x103/0x610 arch/x86/entry/common.c:290
  entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x446a59
Code: e8 dc e6 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 4b 07 fc ff c3 66 2e 0f 1f 84 00 00 00 00
RSP: 002b:00007fce454e5db8 EFLAGS: 00000246 ORIG_RAX: 0000000000000028
RAX: ffffffffffffffda RBX: 00000000006dcc28 RCX: 0000000000446a59
RDX: 0000000020000000 RSI: 0000000000000003 RDI: 0000000000000003
RBP: 00000000006dcc20 R08: 0000000000000000 R09: 0000000000000000
R10: 00008080fffffffe R11: 0000000000000246 R12: 00000000006dcc2c
R13: 00007ffd7bf04daf R14: 00007fce454e69c0 R15: 20c49ba5e353f7cf
rcu: rcu_preempt kthread starved for 10502 jiffies! g5873 f0x2  
RCU_GP_WAIT_FQS(5) ->state=0x0 ->cpu=1
rcu: RCU grace-period kthread stack dump:
rcu_preempt     R  running task    29200    10      2 0x80000000
Call Trace:
  context_switch kernel/sched/core.c:2844 [inline]
  __schedule+0x817/0x1cc0 kernel/sched/core.c:3485
  schedule+0x92/0x180 kernel/sched/core.c:3529
  schedule_timeout+0x4db/0xfd0 kernel/time/timer.c:1803
  rcu_gp_fqs_loop kernel/rcu/tree.c:1948 [inline]
  rcu_gp_kthread+0x956/0x17a0 kernel/rcu/tree.c:2105
  kthread+0x357/0x430 kernel/kthread.c:246
  ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352


---
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 syzkaller@googlegroups.com.

syzbot will keep track of this bug report. See:
https://goo.gl/tpsmEJ#bug-status-tracking for how to communicate with  
syzbot.
syzbot can test patches for this bug, for details see:
https://goo.gl/tpsmEJ#testing-patches