INFO: rcu detected stall in mod_timer

17 views
Skip to first unread message

syzbot

unread,
Feb 26, 2020, 8:26:14 PM2/26/20
to syzkaller...@googlegroups.com
Hello,

syzbot found the following crash on:

HEAD commit: 98db2bf2 Linux 4.14.171
git tree: linux-4.14.y
console output: https://syzkaller.appspot.com/x/log.txt?x=14bebefde00000
kernel config: https://syzkaller.appspot.com/x/.config?x=49cf7d1ab0dd7451
dashboard link: https://syzkaller.appspot.com/bug?extid=b74b04dae431ac24a9fd
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+b74b04...@syzkaller.appspotmail.com

sg_write: data in/out 2097152/1 bytes for SCSI command 0x4-- guessing data in;
program syz-executor.0 not setting count and/or reply_len properly
INFO: rcu_preempt self-detected stall on CPU
1-...: (1 GPs behind) idle=1ba/140000000000002/0 softirq=55513/55517 fqs=11
(t=10500 jiffies g=16861 c=16860 q=98)
rcu_preempt kthread starved for 10473 jiffies! g16861 c16860 f0x0 RCU_GP_WAIT_FQS(3) ->state=0x0 ->cpu=0
rcu_preempt R running task 29920 8 2 0x80000000
Call Trace:
schedule+0x8d/0x1b0 kernel/sched/core.c:3428
schedule_timeout+0x43c/0xe40 kernel/time/timer.c:1746
rcu_gp_kthread+0xb8e/0x1ce0 kernel/rcu/tree.c:2255
kthread+0x30d/0x420 kernel/kthread.c:232
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404
NMI backtrace for cpu 1
CPU: 1 PID: 24099 Comm: syz-executor.2 Not tainted 4.14.171-syzkaller #0
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+0x13e/0x194 lib/dump_stack.c:58
nmi_cpu_backtrace.cold+0x57/0x93 lib/nmi_backtrace.c:101
nmi_trigger_cpumask_backtrace+0x139/0x17e lib/nmi_backtrace.c:62
trigger_single_cpu_backtrace include/linux/nmi.h:158 [inline]
rcu_dump_cpu_stacks+0x16d/0x1b8 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+0x490/0xdaa kernel/rcu/tree.c:2792
update_process_times+0x29/0x60 kernel/time/timer.c:1590
tick_sched_handle+0x7d/0x150 kernel/time/tick-sched.c:165
tick_sched_timer+0x3e/0x120 kernel/time/tick-sched.c:1223
__run_hrtimer kernel/time/hrtimer.c:1223 [inline]
__hrtimer_run_queues+0x25c/0xbb0 kernel/time/hrtimer.c:1287
hrtimer_interrupt+0x1e6/0x5e0 kernel/time/hrtimer.c:1321
local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1075 [inline]
smp_apic_timer_interrupt+0x117/0x5e0 arch/x86/kernel/apic/apic.c:1100
apic_timer_interrupt+0x8f/0xa0 arch/x86/entry/entry_64.S:792
RIP: 0010:arch_local_irq_restore arch/x86/include/asm/paravirt.h:779 [inline]
RIP: 0010:__raw_spin_unlock_irqrestore include/linux/spinlock_api_smp.h:160 [inline]
RIP: 0010:_raw_spin_unlock_irqrestore+0x91/0xe0 kernel/locking/spinlock.c:192
RSP: 0018:ffff8880aeb07ca8 EFLAGS: 00000286 ORIG_RAX: ffffffffffffff10
RAX: 1ffffffff0fa2cd9 RBX: 0000000000000286 RCX: 1ffff1101488b144
RDX: dffffc0000000000 RSI: ffff8880a4458a00 RDI: 0000000000000286
RBP: ffff8880aeb239c0 R08: 0000000000000001 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000001
R13: ffff888096b68608 R14: 0000000000000000 R15: ffff8880aeb239c0
__mod_timer kernel/time/timer.c:1026 [inline]
mod_timer+0x541/0xe70 kernel/time/timer.c:1069
call_timer_fn+0x14a/0x650 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+0x52a/0x1390 kernel/time/timer.c:1649
__do_softirq+0x254/0x9bf kernel/softirq.c:288
invoke_softirq kernel/softirq.c:368 [inline]
irq_exit+0x15b/0x1a0 kernel/softirq.c:409
exiting_irq arch/x86/include/asm/apic.h:648 [inline]
smp_apic_timer_interrupt+0x141/0x5e0 arch/x86/kernel/apic/apic.c:1102
apic_timer_interrupt+0x8f/0xa0 arch/x86/entry/entry_64.S:792
</IRQ>
RIP: 0010:__sanitizer_cov_trace_pc+0x46/0x50 kernel/kcov.c:89
RSP: 0018:ffff88803e7d7dc8 EFLAGS: 00000212 ORIG_RAX: ffffffffffffff10
RAX: 0000000000040000 RBX: ffff88803e7d7eb0 RCX: ffffc9000a841000
RDX: 000000000000214d RSI: ffffffff82fdd965 RDI: ffffffff86e450c0
RBP: ffffffff86e450c0 R08: 0000000000000001 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000001
R13: ffffffff86e45080 R14: 000000005e571a2c R15: 0000000000014d22
check_preemption_disabled+0x35/0x240 lib/smp_processor_id.c:52
kvm_clock_read+0xc/0x30 arch/x86/kernel/kvmclock.c:86
tk_clock_read kernel/time/timekeeping.c:144 [inline]
timekeeping_get_delta kernel/time/timekeeping.c:238 [inline]
timekeeping_get_ns kernel/time/timekeeping.c:344 [inline]
ktime_get_ts64+0x17e/0x3a0 kernel/time/timekeeping.c:875
posix_ktime_get_ts+0x11/0x20 kernel/time/posix-timers.c:222
SYSC_clock_gettime kernel/time/posix-timers.c:1073 [inline]
SyS_clock_gettime+0xe3/0x180 kernel/time/posix-timers.c:1063
do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
entry_SYSCALL_64_after_hwframe+0x42/0xb7
RIP: 0033:0x45f28a
RSP: 002b:00007f8bb5530c58 EFLAGS: 00000246 ORIG_RAX: 00000000000000e4
RAX: ffffffffffffffda RBX: 000000000076bf28 RCX: 000000000045f28a
RDX: 00000000000f4240 RSI: 00007f8bb5530c60 RDI: 0000000000000001
RBP: 000000000076bf20 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 000000000076bf2c
R13: 0000000000000b7b R14: 00000000004cd6d1 R15: 000000000076bf2c
INFO: rcu_sched detected stalls on CPUs/tasks:
1-...: (1 GPs behind) idle=1ba/140000000000000/0 softirq=55514/55517 fqs=11
(detected by 0, t=10544 jiffies, g=13144, c=13143, q=2)
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 PID: 7476 Comm: syz-executor.5 Not tainted 4.14.171-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
task: ffff88808e66a0c0 task.stack: ffff88809d918000
RIP: 0010:rcu_is_watching+0x0/0xb0 kernel/rcu/tree.c:1126
RSP: 0018:ffff88809d91f778 EFLAGS: 00000202
RAX: 0000000000000001 RBX: ffffea00026ee680 RCX: 1ffffffff1027934
RDX: 0000000000000000 RSI: ffffffff86e45080 RDI: ffff88808e66a93c
RBP: ffffea00026ee680 R08: 0000000000000000 R09: 0000000000020012
R10: ffff88808e66a968 R11: ffff88808e66a0c0 R12: dead000000000100
R13: dead000000000100 R14: ffffea00026ee6a0 R15: 0000000000000020
FS: 0000000000000000(0000) GS:ffff8880aeb00000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007f0391c04000 CR3: 000000007c8f9000 CR4: 00000000001406e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
rcu_read_lock_held+0x7c/0xc0 kernel/rcu/update.c:328
page_memcg_rcu include/linux/mm.h:1063 [inline]
workingset_activation+0x5c/0x2c0 mm/workingset.c:320
mark_page_accessed+0x4a0/0x600 mm/swap.c:394
zap_pte_range mm/memory.c:1339 [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+0x977/0x1930 mm/memory.c:1515
unmap_single_vma+0x147/0x2b0 mm/memory.c:1560
unmap_vmas+0x9d/0x160 mm/memory.c:1590
exit_mmap+0x26d/0x4b0 mm/mmap.c:3056
__mmput kernel/fork.c:930 [inline]
mmput+0x103/0x420 kernel/fork.c:951
exit_mm kernel/exit.c:545 [inline]
do_exit+0x933/0x2b00 kernel/exit.c:845
do_group_exit+0x100/0x310 kernel/exit.c:955
get_signal+0x385/0x1ca0 kernel/signal.c:2418
do_signal+0x7c/0x1690 arch/x86/kernel/signal.c:814
exit_to_usermode_loop+0x159/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+0x4a3/0x640 arch/x86/entry/common.c:297
entry_SYSCALL_64_after_hwframe+0x42/0xb7
RIP: 0033:0x41628a
RSP: 002b:00007ffdc788c5b8 EFLAGS: 00000246 ORIG_RAX: 000000000000003d
RAX: fffffffffffffe00 RBX: 0000000000001d39 RCX: 000000000041628a
RDX: 0000000040000000 RSI: 00007ffdc788c5c4 RDI: ffffffffffffffff
RBP: 00000000000000f8 R08: 0000000000001d34 R09: 0000000002534940
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000417f50
R13: 00007ffdc788c848 R14: 0000000000000000 R15: 0000000000000000
Code: 02 74 06 48 83 c4 08 5b c3 0f 0b 48 83 c4 08 5b c3 48 89 04 24 e8 71 31 38 00 48 8b 04 24 eb cd 90 66 2e 0f 1f 84 00 00 00 00 00 <53> 48 83 ec 08 65 ff 05 64 84 b6 7e e8 ff 71 b2 01 48 c7 c3 40


---
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,
Mar 1, 2020, 11:10:13 PM3/1/20
to syzkaller...@googlegroups.com
Hello,

syzbot found the following crash on:

HEAD commit: a083db76 Linux 4.19.107
git tree: linux-4.19.y
console output: https://syzkaller.appspot.com/x/log.txt?x=16365a81e00000
kernel config: https://syzkaller.appspot.com/x/.config?x=c32f76aaadd644de
dashboard link: https://syzkaller.appspot.com/bug?extid=7eeef512f087e0630c9c
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+7eeef5...@syzkaller.appspotmail.com

netlink: 20 bytes leftover after parsing attributes in process `syz-executor.4'.
device vlan508 entered promiscuous mode
IPv6: ADDRCONF(NETDEV_UP): veth1179: link is not ready
device veth1179 entered promiscuous mode
IPv6: ADDRCONF(NETDEV_UP): vlan508: link is not ready
rcu: INFO: rcu_preempt self-detected stall on CPU
rcu: 1-....: (10499 ticks this GP) idle=dda/1/0x4000000000000004 softirq=76480/76480 fqs=5103
rcu: (t=10500 jiffies g=100349 q=1232)
NMI backtrace for cpu 1
CPU: 1 PID: 12140 Comm: syz-executor.1 Not tainted 4.19.107-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
<IRQ>
__dump_stack lib/dump_stack.c:77 [inline]
dump_stack+0x188/0x20d lib/dump_stack.c:118
nmi_cpu_backtrace.cold+0x63/0xa2 lib/nmi_backtrace.c:101
nmi_trigger_cpumask_backtrace+0x1a6/0x1eb lib/nmi_backtrace.c:62
trigger_single_cpu_backtrace include/linux/nmi.h:164 [inline]
rcu_dump_cpu_stacks+0x170/0x1bb kernel/rcu/tree.c:1340
print_cpu_stall kernel/rcu/tree.c:1478 [inline]
check_cpu_stall kernel/rcu/tree.c:1550 [inline]
__rcu_pending kernel/rcu/tree.c:3293 [inline]
rcu_pending kernel/rcu/tree.c:3336 [inline]
rcu_check_callbacks.cold+0x634/0xddc kernel/rcu/tree.c:2682
update_process_times+0x2a/0x70 kernel/time/timer.c:1638
tick_sched_handle+0x9b/0x180 kernel/time/tick-sched.c:168
tick_sched_timer+0x42/0x130 kernel/time/tick-sched.c:1278
__run_hrtimer kernel/time/hrtimer.c:1401 [inline]
__hrtimer_run_queues+0x2fc/0xd50 kernel/time/hrtimer.c:1463
hrtimer_interrupt+0x312/0x770 kernel/time/hrtimer.c:1521
local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1067 [inline]
smp_apic_timer_interrupt+0x10c/0x550 arch/x86/kernel/apic/apic.c:1092
apic_timer_interrupt+0xf/0x20 arch/x86/entry/entry_64.S:893
RIP: 0010:arch_local_irq_restore arch/x86/include/asm/paravirt.h:789 [inline]
RIP: 0010:__raw_spin_unlock_irqrestore include/linux/spinlock_api_smp.h:160 [inline]
RIP: 0010:_raw_spin_unlock_irqrestore+0x91/0xe0 kernel/locking/spinlock.c:184
Code: 48 c7 c0 88 56 b2 88 48 ba 00 00 00 00 00 fc ff df 48 c1 e8 03 80 3c 10 00 75 37 48 83 3d fe 5d 92 01 00 74 22 48 89 df 57 9d <0f> 1f 44 00 00 bf 01 00 00 00 e8 c0 a1 26 fa 65 8b 05 29 f5 e1 78
RSP: 0018:ffff8880ae707c50 EFLAGS: 00000282 ORIG_RAX: ffffffffffffff13
RAX: 1ffffffff1164ad1 RBX: 0000000000000282 RCX: 1ffff110077f8941
RDX: dffffc0000000000 RSI: ffff88803bfc49e8 RDI: 0000000000000282
RBP: ffff8880ae723a00 R08: ffff88803bfc4140 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000
R13: 1ffff11015ce0f95 R14: 0000000000000000 R15: ffff8880ae723a00
__mod_timer kernel/time/timer.c:1059 [inline]
mod_timer+0x530/0xfb0 kernel/time/timer.c:1102
call_timer_fn+0x177/0x700 kernel/time/timer.c:1326
expire_timers kernel/time/timer.c:1363 [inline]
__run_timers kernel/time/timer.c:1684 [inline]
__run_timers kernel/time/timer.c:1652 [inline]
run_timer_softirq+0x5d0/0x1540 kernel/time/timer.c:1697
__do_softirq+0x26c/0x93c kernel/softirq.c:292
invoke_softirq kernel/softirq.c:372 [inline]
irq_exit+0x17b/0x1c0 kernel/softirq.c:412
exiting_irq arch/x86/include/asm/apic.h:544 [inline]
smp_apic_timer_interrupt+0x136/0x550 arch/x86/kernel/apic/apic.c:1094
apic_timer_interrupt+0xf/0x20 arch/x86/entry/entry_64.S:893
</IRQ>
RIP: 0010:get_current arch/x86/include/asm/current.h:15 [inline]
RIP: 0010:__sanitizer_cov_trace_pc+0x4/0x50 kernel/kcov.c:100
Code: 2c 6e 87 4c 89 25 5c 23 06 0a 41 bc f4 ff ff ff e8 4a 1c eb ff 48 c7 05 46 23 06 0a 00 00 00 00 e9 24 ec ff ff 90 48 8b 34 24 <65> 48 8b 04 25 40 ee 01 00 65 8b 15 fc 54 9a 7e 81 e2 00 01 1f 00
RSP: 0018:ffff88807a35fa78 EFLAGS: 00000202 ORIG_RAX: ffffffffffffff13
RAX: 0000000000000002 RBX: ffff88803bfc4140 RCX: ffffffff83264683
RDX: 0000000000000001 RSI: ffffffff83264690 RDI: 0000000000000005
RBP: 0000000000000002 R08: ffff88803bfc4140 R09: ffffed1015ce4733
R10: ffffed1015ce4732 R11: ffff8880ae723993 R12: 0000000000000004
R13: 0000000000000074 R14: 0000000000000001 R15: ffff88809ffe6940
task_css include/linux/cgroup.h:482 [inline]
task_devcgroup security/device_cgroup.c:53 [inline]
__devcgroup_check_permission+0xd0/0x3b8 security/device_cgroup.c:811
devcgroup_check_permission include/linux/device_cgroup.h:32 [inline]
devcgroup_inode_permission include/linux/device_cgroup.h:54 [inline]
inode_permission+0x45b/0x550 fs/namei.c:455
may_open.isra.0+0x1a5/0x310 fs/namei.c:2974
do_last fs/namei.c:3417 [inline]
path_openat+0xfb0/0x4200 fs/namei.c:3537
do_filp_open+0x1a1/0x280 fs/namei.c:3567
do_sys_open+0x3c0/0x500 fs/open.c:1088
do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x416211
Code: 75 14 b8 02 00 00 00 0f 05 48 3d 01 f0 ff ff 0f 83 04 19 00 00 c3 48 83 ec 08 e8 0a fa ff ff 48 89 04 24 b8 02 00 00 00 0f 05 <48> 8b 3c 24 48 89 c2 e8 53 fa ff ff 48 89 d0 48 83 c4 08 48 3d 01
RSP: 002b:00007f372659e7a0 EFLAGS: 00000293 ORIG_RAX: 0000000000000002
RAX: ffffffffffffffda RBX: 6666666666666667 RCX: 0000000000416211
RDX: 0000000000000000 RSI: 0000000000000001 RDI: 00007f372659e850
RBP: 000000000076bf20 R08: 000000000000000f R09: 0000000000000000
R10: ffffffffffffffff R11: 0000000000000293 R12: 00000000ffffffff
R13: 0000000000000c09 R14: 00000000004cdf35 R15: 000000000076bf2c
rcu: INFO: rcu_sched detected stalls on CPUs/tasks:
rcu: 1-....: (0 ticks this GP) idle=dda/1/0x4000000000000000 softirq=76481/76481 fqs=5079
rcu: (detected by 0, t=10504 jiffies, g=16769, q=3)

syzbot

unread,
Aug 10, 2020, 8:01:21 AM8/10/20
to syzkaller...@googlegroups.com
Auto-closing this bug as obsolete.
Crashes did not happen for a while, no reproducer and no activity.

syzbot

unread,
Jan 2, 2021, 8:48:14 PM1/2/21
to syzkaller...@googlegroups.com
Reply all
Reply to author
Forward
0 new messages