INFO: rcu detected stall in chrdev_open

7 views
Skip to first unread message

syzbot

unread,
Dec 21, 2021, 2:54:27 AM12/21/21
to syzkaller...@googlegroups.com
Hello,

syzbot found the following issue on:

HEAD commit: 9dfbac0e6b86 Linux 4.14.258
git tree: linux-4.14.y
console output: https://syzkaller.appspot.com/x/log.txt?x=13ed182bb00000
kernel config: https://syzkaller.appspot.com/x/.config?x=9cac3dc48a267418
dashboard link: https://syzkaller.appspot.com/bug?extid=929fa38ef7e406a27eb8
compiler: gcc version 10.2.1 20210110 (Debian 10.2.1-6)

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

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

can: notifier: receive list not found for dev tap0
INFO: rcu_sched detected stalls on CPUs/tasks:
(detected by 0, t=10502 jiffies, g=1611, c=1610, q=1)
All QSes seen, last rcu_sched kthread activity 10502 (4294963082-4294952580), jiffies_till_next_fqs=1, root ->qsmask 0x0
syz-executor.3 R running task 28008 11950 7983 0x00000000
Call Trace:
<IRQ>
sched_show_task.cold+0x333/0x39a kernel/sched/core.c:5168
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+0xd29/0xd8d kernel/rcu/tree.c:2792
update_process_times+0x29/0x60 kernel/time/timer.c:1591
tick_sched_handle+0x7d/0x150 kernel/time/tick-sched.c:165
tick_sched_timer+0x92/0x200 kernel/time/tick-sched.c:1223
__run_hrtimer kernel/time/hrtimer.c:1223 [inline]
__hrtimer_run_queues+0x30b/0xc80 kernel/time/hrtimer.c:1287
hrtimer_interrupt+0x1e6/0x5e0 kernel/time/hrtimer.c:1321
local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1079 [inline]
smp_apic_timer_interrupt+0x117/0x5e0 arch/x86/kernel/apic/apic.c:1104
apic_timer_interrupt+0x93/0xa0 arch/x86/entry/entry_64.S:793
</IRQ>
RIP: 0010:kasan_kmalloc+0x0/0x160 mm/kasan/kasan.c:531
RSP: 0018:ffff88806f6af978 EFLAGS: 00000206 ORIG_RAX: ffffffffffffff10
RAX: 0000000000000007 RBX: 00000000014000c0 RCX: 00000000014000c0
RDX: 0000000000000020 RSI: ffff8880aaf75f40 RDI: ffff88813fe741c0
RBP: ffff88813fe741c0 R08: ffffffff8b9a50c8 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000000 R12: ffff8880aaf75f40
R13: 00000000014000c0 R14: 0000000000000020 R15: ffff88813fe741c0
slab_post_alloc_hook mm/slab.h:442 [inline]
slab_alloc mm/slab.c:3390 [inline]
kmem_cache_alloc_trace+0x11b/0x3d0 mm/slab.c:3616
kmalloc include/linux/slab.h:488 [inline]
tty_alloc_file drivers/tty/tty_io.c:186 [inline]
tty_open+0x11a/0x8b0 drivers/tty/tty_io.c:2015
chrdev_open+0x23c/0x6d0 fs/char_dev.c:423
do_dentry_open+0x44b/0xec0 fs/open.c:777
vfs_open+0x105/0x220 fs/open.c:888
do_last fs/namei.c:3428 [inline]
path_openat+0x628/0x2970 fs/namei.c:3569
do_filp_open+0x179/0x3c0 fs/namei.c:3603
do_sys_open+0x296/0x410 fs/open.c:1081
do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
entry_SYSCALL_64_after_hwframe+0x46/0xbb
RIP: 0033:0x7f84163a4e99
RSP: 002b:00007f8414d1a168 EFLAGS: 00000246 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 00007f84164b7f60 RCX: 00007f84163a4e99
RDX: 0000000000000000 RSI: 0000000020000000 RDI: ffffffffffffff9c
RBP: 00007f84163feff1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 00007fff337dc4ff R14: 00007f8414d1a300 R15: 0000000000022000
rcu_sched kthread starved for 10502 jiffies! g1611 c1610 f0x2 RCU_GP_WAIT_FQS(3) ->state=0x0 ->cpu=1
rcu_sched R running task 30008 9 2 0x80000000
Call Trace:
context_switch kernel/sched/core.c:2811 [inline]
__schedule+0x88b/0x1de0 kernel/sched/core.c:3387
schedule+0x8d/0x1b0 kernel/sched/core.c:3431
schedule_timeout+0x4af/0xe90 kernel/time/timer.c:1747
rcu_gp_kthread+0xc0a/0x1e60 kernel/rcu/tree.c:2255
kthread+0x30d/0x420 kernel/kthread.c:232
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404
INFO: rcu_preempt detected stalls on CPUs/tasks:
(detected by 0, t=10540 jiffies, g=3570, c=3569, q=99)
All QSes seen, last rcu_preempt kthread activity 10540 (4294963121-4294952581), jiffies_till_next_fqs=1, root ->qsmask 0x0
syz-executor.3 R running task 28008 11950 7983 0x00000000
Call Trace:
<IRQ>
sched_show_task.cold+0x333/0x39a kernel/sched/core.c:5168
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+0xd29/0xd8d kernel/rcu/tree.c:2792
update_process_times+0x29/0x60 kernel/time/timer.c:1591
tick_sched_handle+0x7d/0x150 kernel/time/tick-sched.c:165
tick_sched_timer+0x92/0x200 kernel/time/tick-sched.c:1223
__run_hrtimer kernel/time/hrtimer.c:1223 [inline]
__hrtimer_run_queues+0x30b/0xc80 kernel/time/hrtimer.c:1287
hrtimer_interrupt+0x1e6/0x5e0 kernel/time/hrtimer.c:1321
local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1079 [inline]
smp_apic_timer_interrupt+0x117/0x5e0 arch/x86/kernel/apic/apic.c:1104
apic_timer_interrupt+0x93/0xa0 arch/x86/entry/entry_64.S:793
</IRQ>
RIP: 0010:kasan_kmalloc+0x0/0x160 mm/kasan/kasan.c:531
RSP: 0018:ffff88806f6af978 EFLAGS: 00000206 ORIG_RAX: ffffffffffffff10
RAX: 0000000000000007 RBX: 00000000014000c0 RCX: 00000000014000c0
RDX: 0000000000000020 RSI: ffff8880aaf75f40 RDI: ffff88813fe741c0
RBP: ffff88813fe741c0 R08: ffffffff8b9a50c8 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000000 R12: ffff8880aaf75f40
R13: 00000000014000c0 R14: 0000000000000020 R15: ffff88813fe741c0
slab_post_alloc_hook mm/slab.h:442 [inline]
slab_alloc mm/slab.c:3390 [inline]
kmem_cache_alloc_trace+0x11b/0x3d0 mm/slab.c:3616
kmalloc include/linux/slab.h:488 [inline]
tty_alloc_file drivers/tty/tty_io.c:186 [inline]
tty_open+0x11a/0x8b0 drivers/tty/tty_io.c:2015
chrdev_open+0x23c/0x6d0 fs/char_dev.c:423
do_dentry_open+0x44b/0xec0 fs/open.c:777
vfs_open+0x105/0x220 fs/open.c:888
do_last fs/namei.c:3428 [inline]
path_openat+0x628/0x2970 fs/namei.c:3569
do_filp_open+0x179/0x3c0 fs/namei.c:3603
do_sys_open+0x296/0x410 fs/open.c:1081
do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
entry_SYSCALL_64_after_hwframe+0x46/0xbb
RIP: 0033:0x7f84163a4e99
RSP: 002b:00007f8414d1a168 EFLAGS: 00000246 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 00007f84164b7f60 RCX: 00007f84163a4e99
RDX: 0000000000000000 RSI: 0000000020000000 RDI: ffffffffffffff9c
RBP: 00007f84163feff1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 00007fff337dc4ff R14: 00007f8414d1a300 R15: 0000000000022000
rcu_preempt kthread starved for 10540 jiffies! g3570 c3569 f0x2 RCU_GP_WAIT_FQS(3) ->state=0x0 ->cpu=0
rcu_preempt R running task 30008 8 2 0x80000000
Call Trace:
context_switch kernel/sched/core.c:2811 [inline]
__schedule+0x88b/0x1de0 kernel/sched/core.c:3387
schedule+0x8d/0x1b0 kernel/sched/core.c:3431
schedule_timeout+0x4af/0xe90 kernel/time/timer.c:1747
rcu_gp_kthread+0xc0a/0x1e60 kernel/rcu/tree.c:2255
kthread+0x30d/0x420 kernel/kthread.c:232
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404


---
This report 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 issue. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.

syzbot

unread,
Jan 20, 2022, 9:14:23 AM1/20/22
to syzkaller...@googlegroups.com
syzbot has found a reproducer for the following issue on:

HEAD commit: 4ba8e26127c3 Linux 4.14.262
git tree: linux-4.14.y
console output: https://syzkaller.appspot.com/x/log.txt?x=1541dff7b00000
kernel config: https://syzkaller.appspot.com/x/.config?x=51e11aabddb4cf62
dashboard link: https://syzkaller.appspot.com/bug?extid=929fa38ef7e406a27eb8
compiler: gcc version 10.2.1 20210110 (Debian 10.2.1-6)
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=1096bbdfb00000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=165454ffb00000

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

INFO: rcu_preempt detected stalls on CPUs/tasks:
(detected by 0, t=10502 jiffies, g=1144, c=1143, q=65)
All QSes seen, last rcu_preempt kthread activity 10502 (4294994573-4294984071), jiffies_till_next_fqs=1, root ->qsmask 0x0
syz-executor271 R running task 27976 8228 7974 0x00000000
Call Trace:
<IRQ>
sched_show_task.cold+0x333/0x39a kernel/sched/core.c:5168
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+0xd29/0xd8d kernel/rcu/tree.c:2792
update_process_times+0x29/0x60 kernel/time/timer.c:1591
tick_sched_handle+0x7d/0x150 kernel/time/tick-sched.c:165
tick_sched_timer+0x92/0x200 kernel/time/tick-sched.c:1223
__run_hrtimer kernel/time/hrtimer.c:1223 [inline]
__hrtimer_run_queues+0x30b/0xc80 kernel/time/hrtimer.c:1287
hrtimer_interrupt+0x1e6/0x5e0 kernel/time/hrtimer.c:1321
local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1079 [inline]
smp_apic_timer_interrupt+0x117/0x5e0 arch/x86/kernel/apic/apic.c:1104
apic_timer_interrupt+0x93/0xa0 arch/x86/entry/entry_64.S:793
</IRQ>
RIP: 0010:__mutex_unlock_slowpath+0x261/0x770 kernel/locking/mutex.c:1013
RSP: 0018:ffff8880aaa57928 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff10
RAX: ffff88809df1c240 RBX: 0000000000000000 RCX: fffffbfff17d93a8
RDX: 0000000000000000 RSI: 0000000000000001 RDI: 0000000000000286
RBP: ffffffff89472920 R08: ffff88809df1c240 R09: dffffc0000000000
R10: 0000000000000000 R11: ffff88809df1c240 R12: ffffffff8bec9d40
R13: 1ffff1101554af29 R14: ffff8880aaa57968 R15: 0000000000000003
tty_open_by_driver drivers/tty/tty_io.c:1958 [inline]
tty_open+0x3d5/0x8b0 drivers/tty/tty_io.c:2021
chrdev_open+0x23c/0x6d0 fs/char_dev.c:423
do_dentry_open+0x44b/0xec0 fs/open.c:777
vfs_open+0x105/0x220 fs/open.c:888
do_last fs/namei.c:3428 [inline]
path_openat+0x628/0x2970 fs/namei.c:3569
do_filp_open+0x179/0x3c0 fs/namei.c:3603
do_sys_open+0x296/0x410 fs/open.c:1081
do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
entry_SYSCALL_64_after_hwframe+0x46/0xbb
RIP: 0033:0x7f0578eadaf9
RSP: 002b:00007f0578e5f318 EFLAGS: 00000246 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 00007f0578f353e8 RCX: 00007f0578eadaf9
RDX: 0000000000000802 RSI: 0000000020000840 RDI: ffffffffffffff9c
RBP: 00007f0578f353e0 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 7974742f7665642f
R13: 00007fffc41d99af R14: 00007f0578e5f400 R15: 0000000000022000
rcu_preempt kthread starved for 10502 jiffies! g1144 c1143 f0x2 RCU_GP_WAIT_FQS(3) ->state=0x0 ->cpu=0
rcu_preempt R running task 30008 8 2 0x80000000
Call Trace:
context_switch kernel/sched/core.c:2811 [inline]
__schedule+0x88b/0x1de0 kernel/sched/core.c:3387
schedule+0x8d/0x1b0 kernel/sched/core.c:3431
schedule_timeout+0x4af/0xe90 kernel/time/timer.c:1747
rcu_gp_kthread+0xc0a/0x1e60 kernel/rcu/tree.c:2255
kthread+0x30d/0x420 kernel/kthread.c:232
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404
INFO: rcu_sched detected stalls on CPUs/tasks:
(detected by 0, t=10539 jiffies, g=297, c=296, q=5)
All QSes seen, last rcu_sched kthread activity 10539 (4294994611-4294984072), jiffies_till_next_fqs=1, root ->qsmask 0x0
syz-executor271 R running task 27976 8228 7974 0x00000000
Call Trace:
<IRQ>
sched_show_task.cold+0x333/0x39a kernel/sched/core.c:5168
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+0xd29/0xd8d kernel/rcu/tree.c:2792
update_process_times+0x29/0x60 kernel/time/timer.c:1591
tick_sched_handle+0x7d/0x150 kernel/time/tick-sched.c:165
tick_sched_timer+0x92/0x200 kernel/time/tick-sched.c:1223
__run_hrtimer kernel/time/hrtimer.c:1223 [inline]
__hrtimer_run_queues+0x30b/0xc80 kernel/time/hrtimer.c:1287
hrtimer_interrupt+0x1e6/0x5e0 kernel/time/hrtimer.c:1321
local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1079 [inline]
smp_apic_timer_interrupt+0x117/0x5e0 arch/x86/kernel/apic/apic.c:1104
apic_timer_interrupt+0x93/0xa0 arch/x86/entry/entry_64.S:793
</IRQ>
RIP: 0010:__mutex_unlock_slowpath+0x261/0x770 kernel/locking/mutex.c:1013
RSP: 0018:ffff8880aaa57928 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff10
RAX: ffff88809df1c240 RBX: 0000000000000000 RCX: fffffbfff17d93a8
RDX: 0000000000000000 RSI: 0000000000000001 RDI: 0000000000000286
RBP: ffffffff89472920 R08: ffff88809df1c240 R09: dffffc0000000000
R10: 0000000000000000 R11: ffff88809df1c240 R12: ffffffff8bec9d40
R13: 1ffff1101554af29 R14: ffff8880aaa57968 R15: 0000000000000003
tty_open_by_driver drivers/tty/tty_io.c:1958 [inline]
tty_open+0x3d5/0x8b0 drivers/tty/tty_io.c:2021
chrdev_open+0x23c/0x6d0 fs/char_dev.c:423
do_dentry_open+0x44b/0xec0 fs/open.c:777
vfs_open+0x105/0x220 fs/open.c:888
do_last fs/namei.c:3428 [inline]
path_openat+0x628/0x2970 fs/namei.c:3569
do_filp_open+0x179/0x3c0 fs/namei.c:3603
do_sys_open+0x296/0x410 fs/open.c:1081
do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
entry_SYSCALL_64_after_hwframe+0x46/0xbb
RIP: 0033:0x7f0578eadaf9
RSP: 002b:00007f0578e5f318 EFLAGS: 00000246 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 00007f0578f353e8 RCX: 00007f0578eadaf9
RDX: 0000000000000802 RSI: 0000000020000840 RDI: ffffffffffffff9c
RBP: 00007f0578f353e0 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 7974742f7665642f
R13: 00007fffc41d99af R14: 00007f0578e5f400 R15: 0000000000022000
rcu_sched kthread starved for 10539 jiffies! g297 c296 f0x2 RCU_GP_WAIT_FQS(3) ->state=0x0 ->cpu=1
Reply all
Reply to author
Forward
0 new messages