INFO: rcu detected stall in wb_workfn

7 views
Skip to first unread message

syzbot

unread,
Oct 20, 2019, 5:21:08 AM10/20/19
to syzkaller...@googlegroups.com
Hello,

syzbot found the following crash on:

HEAD commit: b98aebd2 Linux 4.14.150
git tree: linux-4.14.y
console output: https://syzkaller.appspot.com/x/log.txt?x=1290feb0e00000
kernel config: https://syzkaller.appspot.com/x/.config?x=c52c93b368dac5a7
dashboard link: https://syzkaller.appspot.com/bug?extid=c1dbf7d51c6231d760b4
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+c1dbf7...@syzkaller.appspotmail.com

kvm: vcpu 0: requested 128 ns lapic timer period limited to 500000 ns
INFO: rcu_preempt detected stalls on CPUs/tasks:
0-...: (1 ticks this GP) idle=772/140000000000001/0 softirq=44619/44619
fqs=0
(detected by 1, t=12384 jiffies, g=10918, c=10917, q=408)
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 29 Comm: kworker/u4:2 Not tainted 4.14.150 #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
Google 01/01/2011
Workqueue: writeback wb_workfn (flush-8:0)
task: ffff8880a9ec6000 task.stack: ffff8880a9ed8000
RIP: 0010:lock_is_held_type+0xb/0x210 kernel/locking/lockdep.c:4021
RSP: 0018:ffff8880aee07e20 EFLAGS: 00000002
RAX: dffffc0000000000 RBX: 0000000000000003 RCX: 0000000000000000
RDX: 1ffffffff0f565b8 RSI: 00000000ffffffff RDI: ffffffff8778f6e0
RBP: ffff8880aee07e38 R08: 000000a7f9071c0c R09: ffff88821fff8008
R10: ffff88821fff8010 R11: 0000000000000001 R12: ffff888098854490
R13: ffff8880aee25b40 R14: dffffc0000000000 R15: 0000000000000000
FS: 0000000000000000(0000) GS:ffff8880aee00000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 0000001b2c628000 CR3: 0000000087e81000 CR4: 00000000001426f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
<IRQ>
trace_hrtimer_expire_exit include/trace/events/timer.h:267 [inline]
__run_hrtimer kernel/time/hrtimer.c:1221 [inline]
__hrtimer_run_queues+0x938/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: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
</IRQ>
RIP: 0010:__read_once_size include/linux/compiler.h:183 [inline]
RIP: 0010:csd_lock_wait kernel/smp.c:108 [inline]
RIP: 0010:smp_call_function_single+0xfd/0x370 kernel/smp.c:302
RSP: 0018:ffff8880a9edee60 EFLAGS: 00000297 ORIG_RAX: ffffffffffffff10
RAX: ffff8880a9ec6000 RBX: 1ffff110153dbdd0 RCX: 0000000000000830
RDX: 0000000000000000 RSI: 00000000000000fb RDI: 0000000000000830
RBP: ffff8880a9edef08 R08: 0000000000002095 R09: 0000000000000000
R10: ffff8880a9ec6948 R11: ffff8880a9ec6000 R12: 0000000000000000
R13: ffff8880a9edf010 R14: 0000000000000000 R15: 0000000000000040
smp_call_function_many+0x638/0x7c0 kernel/smp.c:434
native_flush_tlb_others+0x81/0x4a0 arch/x86/mm/tlb.c:663
flush_tlb_others arch/x86/include/asm/paravirt.h:309 [inline]
flush_tlb_mm_range+0x1ce/0x340 arch/x86/mm/tlb.c:712
flush_tlb_page arch/x86/include/asm/tlbflush.h:573 [inline]
ptep_clear_flush+0xe6/0x110 mm/pgtable-generic.c:87
page_mkclean_one+0x267/0x5c0 mm/rmap.c:915
rmap_walk_file+0x38d/0x8b0 mm/rmap.c:1829
rmap_walk+0xed/0x190 mm/rmap.c:1847
page_mkclean+0x162/0x1a0 mm/rmap.c:981
clear_page_dirty_for_io+0x1fb/0x7f0 mm/page-writeback.c:2707
mpage_submit_page+0x77/0x240 fs/ext4/inode.c:2193
mpage_process_page_bufs+0x418/0x510 fs/ext4/inode.c:2323
mpage_prepare_extent_to_map+0x489/0xb20 fs/ext4/inode.c:2695
ext4_writepages+0x105f/0x2fd0 fs/ext4/inode.c:2842
do_writepages+0xd0/0x250 mm/page-writeback.c:2364
__writeback_single_inode+0xe6/0x1120 fs/fs-writeback.c:1364
writeback_sb_inodes+0x4ce/0xeb0 fs/fs-writeback.c:1628
__writeback_inodes_wb+0xc3/0x210 fs/fs-writeback.c:1697
wb_writeback+0x735/0xba0 fs/fs-writeback.c:1806
wb_check_old_data_flush fs/fs-writeback.c:1919 [inline]
wb_do_writeback fs/fs-writeback.c:1943 [inline]
wb_workfn+0x943/0xf70 fs/fs-writeback.c:1972
process_one_work+0x863/0x1600 kernel/workqueue.c:2114
worker_thread+0x5d9/0x1050 kernel/workqueue.c:2248
kthread+0x319/0x430 kernel/kthread.c:232
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404
Code: e9 27 ff ff ff 48 8b 7d c8 e8 c2 20 3f 00 e9 60 ff ff ff e8 b8 20 3f
00 eb ac 66 0f 1f 44 00 00 48 b8 00 00 00 00 00 fc ff df 55 <48> 89 e5 41
55 41 54 49 89 fc 53 65 48 8b 1c 25 40 ee 01 00 48
rcu_preempt kthread starved for 12384 jiffies! g10918 c10917 f0x0
RCU_GP_WAIT_FQS(3) ->state=0x0 ->cpu=1
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: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
INFO: rcu_sched detected stalls on CPUs/tasks:
0-...: (1 ticks this GP) idle=772/140000000000001/0 softirq=44619/44619
fqs=0
(detected by 1, t=12384 jiffies, g=7685, c=7684, q=5)
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 29 Comm: kworker/u4:2 Not tainted 4.14.150 #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
Google 01/01/2011
Workqueue: writeback wb_workfn (flush-8:0)
task: ffff8880a9ec6000 task.stack: ffff8880a9ed8000
RIP: 0010:__sanitizer_cov_trace_pc+0x9/0x60 kernel/kcov.c:65
RSP: 0018:ffff8880aee07d80 EFLAGS: 00000046
RAX: ffff8880a9ec6000 RBX: 0000000000800000 RCX: 0000000000000017
RDX: 0000000000010000 RSI: 0000000000000000 RDI: 0000000000000001
RBP: ffff8880aee07dd0 R08: 000000a81dc78780 R09: ffff88821fff8008
R10: ffff88821fff8010 R11: 0000000000000001 R12: 00000000267c9879
R13: dffffc0000000000 R14: 1ffffffff0ee2a82 R15: 00000000000136fc
FS: 0000000000000000(0000) GS:ffff8880aee00000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 0000001b2c628000 CR3: 0000000087e81000 CR4: 00000000001426f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
<IRQ>
advance_periodic_target_expiration+0x1e/0x210 arch/x86/kvm/lapic.c:1493
apic_timer_fn+0x73/0x110 arch/x86/kvm/lapic.c:2117
__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: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
</IRQ>
RIP: 0010:__read_once_size include/linux/compiler.h:183 [inline]
RIP: 0010:csd_lock_wait kernel/smp.c:108 [inline]
RIP: 0010:smp_call_function_single+0xfd/0x370 kernel/smp.c:302
RSP: 0018:ffff8880a9edee60 EFLAGS: 00000297 ORIG_RAX: ffffffffffffff10
RAX: ffff8880a9ec6000 RBX: 1ffff110153dbdd0 RCX: 0000000000000830
RDX: 0000000000000000 RSI: 00000000000000fb RDI: 0000000000000830
RBP: ffff8880a9edef08 R08: 0000000000002095 R09: 0000000000000000
R10: ffff8880a9ec6948 R11: ffff8880a9ec6000 R12: 0000000000000000
R13: ffff8880a9edf010 R14: 0000000000000000 R15: 0000000000000040
smp_call_function_many+0x638/0x7c0 kernel/smp.c:434
native_flush_tlb_others+0x81/0x4a0 arch/x86/mm/tlb.c:663
flush_tlb_others arch/x86/include/asm/paravirt.h:309 [inline]
flush_tlb_mm_range+0x1ce/0x340 arch/x86/mm/tlb.c:712
flush_tlb_page arch/x86/include/asm/tlbflush.h:573 [inline]
ptep_clear_flush+0xe6/0x110 mm/pgtable-generic.c:87
page_mkclean_one+0x267/0x5c0 mm/rmap.c:915
rmap_walk_file+0x38d/0x8b0 mm/rmap.c:1829
rmap_walk+0xed/0x190 mm/rmap.c:1847
page_mkclean+0x162/0x1a0 mm/rmap.c:981
clear_page_dirty_for_io+0x1fb/0x7f0 mm/page-writeback.c:2707
mpage_submit_page+0x77/0x240 fs/ext4/inode.c:2193
mpage_process_page_bufs+0x418/0x510 fs/ext4/inode.c:2323
mpage_prepare_extent_to_map+0x489/0xb20 fs/ext4/inode.c:2695
ext4_writepages+0x105f/0x2fd0 fs/ext4/inode.c:2842
do_writepages+0xd0/0x250 mm/page-writeback.c:2364
__writeback_single_inode+0xe6/0x1120 fs/fs-writeback.c:1364
writeback_sb_inodes+0x4ce/0xeb0 fs/fs-writeback.c:1628
__writeback_inodes_wb+0xc3/0x210 fs/fs-writeback.c:1697
wb_writeback+0x735/0xba0 fs/fs-writeback.c:1806
wb_check_old_data_flush fs/fs-writeback.c:1919 [inline]
wb_do_writeback fs/fs-writeback.c:1943 [inline]
wb_workfn+0x943/0xf70 fs/fs-writeback.c:1972
process_one_work+0x863/0x1600 kernel/workqueue.c:2114
worker_thread+0x5d9/0x1050 kernel/workqueue.c:2248
kthread+0x319/0x430 kernel/kthread.c:232
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404
Code: 4c 89 35 9b 5e be 07 41 be f4 ff ff ff e8 a3 3b ee ff 48 c7 05 85 5e
be 07 00 00 00 00 e9 2f ec ff ff 65 48 8b 04 25 40 ee 01 00 <48> 85 c0 74
1a 65 8b 15 bb f9 a4 7e 81 e2 00 01 1f 00 75 0b 8b
rcu_sched kthread starved for 12384 jiffies! g7685 c7684 f0x0
RCU_GP_WAIT_FQS(3) ->state=0x0 ->cpu=1
rcu_sched R running task 29776 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: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
INFO: rcu_bh detected stalls on CPUs/tasks:
0-...: (1 ticks this GP) idle=772/140000000000001/0 softirq=44619/44619
fqs=0
(detected by 1, t=12384 jiffies, g=-274, c=-275, q=6)
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 29 Comm: kworker/u4:2 Not tainted 4.14.150 #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
Google 01/01/2011
Workqueue: writeback wb_workfn (flush-8:0)
task: ffff8880a9ec6000 task.stack: ffff8880a9ed8000
RIP: 0010:debug_object_deactivate+0x6a/0x350 lib/debugobjects.c:497
RSP: 0018:ffff8880aee07d70 EFLAGS: 00000806
RAX: ffffed1015dc0fb2 RBX: 0000009f02925aec RCX: ffff8880a9ec6880
RDX: 0000000000010000 RSI: ffffffff8779d8e0 RDI: ffff8880988fd450
RBP: ffff8880aee07e38 R08: ffff8880a5ad16d8 R09: 0000000000000007
R10: 0000000000000000 R11: ffff8880a9ec6000 R12: ffff8880988fd450
R13: dffffc0000000000 R14: 1ffff11015dc0fb2 R15: 0000000000000000
FS: 0000000000000000(0000) GS:ffff8880aee00000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 0000001b2c628000 CR3: 0000000087e81000 CR4: 00000000001426f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
<IRQ>
debug_hrtimer_deactivate kernel/time/hrtimer.c:406 [inline]
debug_deactivate kernel/time/hrtimer.c:453 [inline]
__run_hrtimer kernel/time/hrtimer.c:1190 [inline]
__hrtimer_run_queues+0x163/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: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
</IRQ>
RIP: 0010:__read_once_size include/linux/compiler.h:183 [inline]
RIP: 0010:csd_lock_wait kernel/smp.c:108 [inline]
RIP: 0010:smp_call_function_single+0xfd/0x370 kernel/smp.c:302
RSP: 0018:ffff8880a9edee60 EFLAGS: 00000297 ORIG_RAX: ffffffffffffff10
RAX: ffff8880a9ec6000 RBX: 1ffff110153dbdd0 RCX: 0000000000000830
RDX: 0000000000000000 RSI: 00000000000000fb RDI: 0000000000000830
RBP: ffff8880a9edef08 R08: 0000000000002095 R09: 0000000000000000
R10: ffff8880a9ec6948 R11: ffff8880a9ec6000 R12: 0000000000000000
R13: ffff8880a9edf010 R14: 0000000000000000 R15: 0000000000000040
smp_call_function_many+0x638/0x7c0 kernel/smp.c:434
native_flush_tlb_others+0x81/0x4a0 arch/x86/mm/tlb.c:663
flush_tlb_others arch/x86/include/asm/paravirt.h:309 [inline]
flush_tlb_mm_range+0x1ce/0x340 arch/x86/mm/tlb.c:712
flush_tlb_page arch/x86/include/asm/tlbflush.h:573 [inline]
ptep_clear_flush+0xe6/0x110 mm/pgtable-generic.c:87
page_mkclean_one+0x267/0x5c0 mm/rmap.c:915
rmap_walk_file+0x38d/0x8b0 mm/rmap.c:1829
rmap_walk+0xed/0x190 mm/rmap.c:1847
page_mkclean+0x162/0x1a0 mm/rmap.c:981
clear_page_dirty_for_io+0x1fb/0x7f0 mm/page-writeback.c:2707
mpage_submit_page+0x77/0x240 fs/ext4/inode.c:2193
mpage_process_page_bufs+0x418/0x510 fs/ext4/inode.c:2323
mpage_prepare_extent_to_map+0x489/0xb20 fs/ext4/inode.c:2695
ext4_writepages+0x105f/0x2fd0 fs/ext4/inode.c:2842
do_writepages+0xd0/0x250 mm/page-writeback.c:2364
__writeback_single_inode+0xe6/0x1120 fs/fs-writeback.c:1364
writeback_sb_inodes+0x4ce/0xeb0 fs/fs-writeback.c:1628
__writeback_inodes_wb+0xc3/0x210 fs/fs-writeback.c:1697
wb_writeback+0x735/0xba0 fs/fs-writeback.c:1806
wb_check_old_data_flush fs/fs-writeback.c:1919 [inline]
wb_do_writeback fs/fs-writeback.c:1943 [inline]
wb_workfn+0x943/0xf70 fs/fs-writeback.c:1972
process_one_work+0x863/0x1600 kernel/workqueue.c:2114
worker_thread+0x5d9/0x1050 kernel/workqueue.c:2248
kthread+0x319/0x430 kernel/kthread.c:232
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404
Code: 03 47 87 4b 8d 04 2e 48 c7 44 24 30 60 6f d8 82 c7 00 f1 f1 f1 f1 c7
40 04 f1 f1 00 00 c7 40 08 00 00 00 f3 c7 40 0c f3 f3 f3 f3 <8b> 15 78 37
4d 05 85 d2 75 2b 48 b8 00 00 00 00 00 fc ff df 49
rcu_bh kthread starved for 12384 jiffies! g18446744073709551342
c18446744073709551341 f0x0 RCU_GP_WAIT_FQS(3) ->state=0x0 ->cpu=1
rcu_bh R running task 30024 10 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: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

unread,
Feb 17, 2020, 3:22:06 AM2/17/20
to syzkaller...@googlegroups.com
Auto-closing this bug as obsolete.
Crashes did not happen for a while, no reproducer and no activity.
Reply all
Reply to author
Forward
0 new messages