INFO: rcu detected stall in tcp_write_timer

[syzbot]

Hello,

syzbot found the following crash on:

HEAD commit: 84f5ad46 Linux 4.14.162
git tree: linux-4.14.y
console output: https://syzkaller.appspot.com/x/log.txt?x=1050b5c1e00000
kernel config: https://syzkaller.appspot.com/x/.config?x=67bcc84091a71c98
dashboard link: https://syzkaller.appspot.com/bug?extid=375bc096ce55c9a34210
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+375bc0...@syzkaller.appspotmail.com

loop1: rw=2049, want=196, limit=63
attempt to access beyond end of device
loop1: rw=2049, want=197, limit=63
attempt to access beyond end of device
loop1: rw=2049, want=213, limit=63
INFO: rcu_sched detected stalls on CPUs/tasks:
(detected by 0, t=10502 jiffies, g=37727, c=37726, q=4)
All QSes seen, last rcu_sched kthread activity 10498
(4295075517-4295065019), jiffies_till_next_fqs=1, root ->qsmask 0x0
syz-executor.2 R running task 26656 551 304 0x00000008
Call Trace:
<IRQ>
sched_show_task kernel/sched/core.c:5168 [inline]
sched_show_task.cold+0x2f0/0x351 kernel/sched/core.c:5143
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:1590
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:1223 [inline]
__hrtimer_run_queues+0x270/0xbc0 kernel/time/hrtimer.c:1287
hrtimer_interrupt+0x1d8/0x5d0 kernel/time/hrtimer.c:1321
local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1075 [inline]
smp_apic_timer_interrupt+0x11c/0x5e0 arch/x86/kernel/apic/apic.c:1100
apic_timer_interrupt+0x96/0xa0 arch/x86/entry/entry_64.S:792
RIP: 0010:arch_local_irq_restore arch/x86/include/asm/paravirt.h:779
[inline]
RIP: 0010:kmem_cache_free+0xb0/0x2b0 mm/slab.c:3759
RSP: 0018:ffff8880aec07bc8 EFLAGS: 00000282 ORIG_RAX: ffffffffffffff10
RAX: 0000000000000007 RBX: ffff8880a84e9340 RCX: 1ffff1100ae6f133
RDX: 0000000000000000 RSI: ffff888057378978 RDI: 0000000000000282
RBP: ffff8880aec07be8 R08: 00000000b46e486d R09: ffff888057378998
R10: 0000000000000000 R11: 0000000000000000 R12: ffff88821b7d0240
R13: 0000000000000282 R14: ffffffff851a1588 R15: dffffc0000000000
kfree_skbmem+0x88/0x110 net/core/skbuff.c:607
__kfree_skb+0x1e/0x30 net/core/skbuff.c:646
sk_wmem_free_skb include/net/sock.h:1421 [inline]
tcp_write_queue_purge include/net/tcp.h:1631 [inline]
tcp_write_err+0x2ad/0x640 net/ipv4/tcp_timer.c:39
tcp_fastopen_synack_timer net/ipv4/tcp_timer.c:384 [inline]
tcp_retransmit_timer+0x351/0x25c0 net/ipv4/tcp_timer.c:421
tcp_write_timer_handler+0x479/0x7e0 net/ipv4/tcp_timer.c:583
tcp_write_timer+0xd6/0x180 net/ipv4/tcp_timer.c:601
call_timer_fn+0x161/0x670 kernel/time/timer.c:1279
expire_timers kernel/time/timer.c:1318 [inline]
__run_timers kernel/time/timer.c:1636 [inline]
__run_timers kernel/time/timer.c:1604 [inline]
run_timer_softirq+0x5b7/0x1520 kernel/time/timer.c:1649
__do_softirq+0x244/0x9a0 kernel/softirq.c:288
invoke_softirq kernel/softirq.c:368 [inline]
irq_exit+0x160/0x1b0 kernel/softirq.c:409
exiting_irq arch/x86/include/asm/apic.h:648 [inline]
smp_apic_timer_interrupt+0x146/0x5e0 arch/x86/kernel/apic/apic.c:1102
apic_timer_interrupt+0x96/0xa0 arch/x86/entry/entry_64.S:792
</IRQ>
RIP: 0010:preempt_schedule_irq+0xab/0x140 kernel/sched/core.c:3611
RSP: 0018:ffff88807c7ef5b8 EFLAGS: 00000286 ORIG_RAX: ffffffffffffff10
RAX: 1ffffffff0fe2d2b RBX: dffffc0000000000 RCX: 1ffff1100ae6f129
RDX: 0000000000000000 RSI: ffff888057378928 RDI: ffff8880573788fc
RBP: ffff88807c7ef5d8 R08: 0000012a95ecc03e R09: ffff888057378948
R10: 0000000000000000 R11: 0000000000000000 R12: ffffed100ae6f010
R13: ffff888057378080 R14: ffffffff87f16958 R15: 0000000000000000
retint_kernel+0x1b/0x2d
RIP: 0010:sb_find_get_block include/linux/buffer_head.h:338 [inline]
RIP: 0010:recently_deleted fs/ext4/ialloc.c:690 [inline]
RIP: 0010:find_inode_bit.isra.0+0x1fb/0x4d0 fs/ext4/ialloc.c:730
RSP: 0018:ffff88807c7ef690 EFLAGS: 00000282 ORIG_RAX: ffffffffffffff10
RAX: ffff888079037738 RBX: dffffc0000000000 RCX: ffffc90009023000
RDX: 000000000001b7b8 RSI: ffffffff819bf7c7 RDI: ffff88808f7b1e28
RBP: ffff88807c7ef6f0 R08: ffff888057378080 R09: ffff888057378948
R10: 0000000000000000 R11: 0000000000000000 R12: ffff888215fbccc0
R13: 00000000000000c0 R14: ffff88807c7ef830 R15: 0000000000000000
__ext4_new_inode+0x1285/0x4860 fs/ext4/ialloc.c:922
ext4_create+0x1da/0x4f0 fs/ext4/namei.c:2478
lookup_open+0x11a6/0x1860 fs/namei.c:3240
do_last fs/namei.c:3331 [inline]
path_openat+0xfca/0x3f70 fs/namei.c:3566
do_filp_open+0x18e/0x250 fs/namei.c:3600
do_sys_open+0x2c5/0x430 fs/open.c:1084
SYSC_openat fs/open.c:1111 [inline]
SyS_openat+0x30/0x40 fs/open.c:1105
do_syscall_64+0x1e8/0x640 arch/x86/entry/common.c:292
entry_SYSCALL_64_after_hwframe+0x42/0xb7
RIP: 0033:0x45af49
RSP: 002b:00007f98b71f1c78 EFLAGS: 00000246 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 0000000000000004 RCX: 000000000045af49
RDX: 000000000000275a RSI: 0000000020000280 RDI: ffffffffffffff9c
RBP: 000000000075bf20 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00007f98b71f26d4
R13: 00000000004c87eb R14: 00000000004e0970 R15: 00000000ffffffff
INFO: rcu_preempt detected stalls on CPUs/tasks:
1-...: (1 GPs behind) idle=042/140000000000000/0 softirq=167533/167535
fqs=0
(detected by 0, t=10532 jiffies, g=45630, c=45629, q=586)
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 PID: 31155 Comm: syz-executor.5 Not tainted 4.14.162-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
Google 01/01/2011
task: ffff8880a14cc480 task.stack: ffff88805faf0000
RIP: 0010:debug_lockdep_rcu_enabled+0x26/0xa0 kernel/rcu/update.c:299
RSP: 0018:ffff88805faf7700 EFLAGS: 00000202
RAX: 0000000000000007 RBX: ffffea000256ea40 RCX: 1ffffffff1166301
RDX: 0000000000000000 RSI: ffffffff87049200 RDI: 0000000000000000
RBP: ffff88805faf7700 R08: 0000000000000000 R09: ffff8880a14ccd48
R10: ffff8880a14ccd28 R11: ffff8880a14cc480 R12: ffffea000256ea40
R13: ffffea000256ea60 R14: ffffea000256ea40 R15: dead000000000100
FS: 0000000000000000(0000) GS:ffff8880aed00000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 0000000000c058a4 CR3: 0000000056add000 CR4: 00000000001406e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
rcu_read_unlock include/linux/rcupdate.h:681 [inline]
__unlock_page_memcg+0x46/0x100 mm/memcontrol.c:1716
unlock_page_memcg+0x2c/0x40 mm/memcontrol.c:1725
page_remove_file_rmap mm/rmap.c:1245 [inline]
page_remove_rmap+0x1c7/0x940 mm/rmap.c:1296
zap_pte_range mm/memory.c:1342 [inline]
zap_pmd_range mm/memory.c:1444 [inline]
zap_pud_range mm/memory.c:1473 [inline]
zap_p4d_range mm/memory.c:1494 [inline]
unmap_page_range+0xabd/0x19f0 mm/memory.c:1515
unmap_single_vma+0x15d/0x2c0 mm/memory.c:1560
unmap_vmas+0xac/0x170 mm/memory.c:1590
exit_mmap+0x285/0x4e0 mm/mmap.c:3062
__mmput kernel/fork.c:930 [inline]
mmput+0x114/0x440 kernel/fork.c:951
exit_mm kernel/exit.c:545 [inline]
do_exit+0x6fc/0x2c80 kernel/exit.c:841
do_group_exit+0x111/0x330 kernel/exit.c:951
get_signal+0x381/0x1cd0 kernel/signal.c:2413
do_signal+0x86/0x19a0 arch/x86/kernel/signal.c:814
exit_to_usermode_loop+0x15c/0x220 arch/x86/entry/common.c:160
prepare_exit_to_usermode arch/x86/entry/common.c:199 [inline]
syscall_return_slowpath arch/x86/entry/common.c:270 [inline]
do_syscall_64+0x4bc/0x640 arch/x86/entry/common.c:297
entry_SYSCALL_64_after_hwframe+0x42/0xb7
RIP: 0033:0x414d8a
RSP: 002b:00007ffe42241b08 EFLAGS: 00000246 ORIG_RAX: 000000000000003d
RAX: fffffffffffffe00 RBX: 00000000000079b4 RCX: 0000000000414d8a
RDX: 0000000040000000 RSI: 00007ffe42241b14 RDI: ffffffffffffffff
RBP: 00000000000000f8 R08: 00000000000079b3 R09: 000000000267b940
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000416a50
R13: 00007ffe42241d98 R14: 0000000000000000 R15: 0000000000000000
Code: 00 00 00 00 00 48 c7 c0 0c 18 b3 88 55 48 ba 00 00 00 00 00 fc ff df
48 89 c1 83 e0 07 48 89 e5 48 c1 e9 03 83 c0 03 0f b6 14 11 <38> d0 7c 04
84 d2 75 49 8b 15 38 96 65 07 85 d2 74 3b 48 c7 c0
rcu_preempt kthread starved for 10532 jiffies! g45630 c45629 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:2808 [inline]
__schedule+0x7b8/0x1cd0 kernel/sched/core.c:3384
schedule+0x92/0x1c0 kernel/sched/core.c:3428
schedule_timeout+0x43e/0xe10 kernel/time/timer.c:1746
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


---
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]

Auto-closing this bug as obsolete.
Crashes did not happen for a while, no reproducer and no activity.