INFO: rcu detected stall in proc_reg_read

8 views
Skip to first unread message

syzbot

unread,
Jan 17, 2021, 3:31:21 PM1/17/21
to syzkaller...@googlegroups.com
Hello,

syzbot found the following issue on:

HEAD commit: c110fed0 Linux 4.19.168
git tree: linux-4.19.y
console output: https://syzkaller.appspot.com/x/log.txt?x=155ca010d00000
kernel config: https://syzkaller.appspot.com/x/.config?x=ab04f4c73d0ab4a8
dashboard link: https://syzkaller.appspot.com/bug?extid=4ea78af6ad1c826a825b
compiler: gcc (GCC) 10.1.0-syz 20200507

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+4ea78a...@syzkaller.appspotmail.com

rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
rcu: (detected by 1, t=10502 jiffies, g=11245, q=436)
rcu: All QSes seen, last rcu_preempt kthread activity 10503 (4294981307-4294970804), jiffies_till_next_fqs=1, root ->qsmask 0x0
syz-executor.4 R running task 23920 10316 8156 0x8000000a
Call Trace:
<IRQ>
sched_show_task.cold+0x332/0x396 kernel/sched/core.c:5337
print_other_cpu_stall kernel/rcu/tree.c:1430 [inline]
check_cpu_stall kernel/rcu/tree.c:1557 [inline]
__rcu_pending kernel/rcu/tree.c:3293 [inline]
rcu_pending kernel/rcu/tree.c:3336 [inline]
rcu_check_callbacks.cold+0xb37/0xe19 kernel/rcu/tree.c:2682
update_process_times+0x2a/0x70 kernel/time/timer.c:1650
tick_sched_handle+0x9b/0x180 kernel/time/tick-sched.c:168
tick_sched_timer+0xfc/0x290 kernel/time/tick-sched.c:1278
__run_hrtimer kernel/time/hrtimer.c:1401 [inline]
__hrtimer_run_queues+0x3f6/0xe60 kernel/time/hrtimer.c:1463
hrtimer_interrupt+0x32a/0x930 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:894
</IRQ>
RIP: 0010:pv_wait_head_or_lock kernel/locking/qspinlock_paravirt.h:435 [inline]
RIP: 0010:__pv_queued_spin_lock_slowpath+0x3a6/0xae0 kernel/locking/qspinlock.c:474
Code: eb c6 45 01 01 41 bc 00 80 00 00 48 c1 e9 03 83 e3 07 41 be 01 00 00 00 48 b8 00 00 00 00 00 fc ff df 4c 8d 2c 01 eb 0c f3 90 <41> 83 ec 01 0f 84 38 04 00 00 41 0f b6 45 00 38 d8 7f 08 84 c0 0f
RSP: 0018:ffff888051c8f3c0 EFLAGS: 00000206 ORIG_RAX: ffffffffffffff13
RAX: 0000000000000003 RBX: 0000000000000000 RCX: 1ffffffff14030c8
RDX: 0000000000000001 RSI: ffffffff81677df5 RDI: 0000000000000286
RBP: ffffffff8a018640 R08: 0000000000000001 R09: 0000000000000000
R10: 0000000000000001 R11: 0000000000000000 R12: 0000000000006471
R13: fffffbfff14030c8 R14: 0000000000000001 R15: ffff8880ba12bd80
pv_queued_spin_lock_slowpath arch/x86/include/asm/paravirt.h:679 [inline]
queued_spin_lock_slowpath arch/x86/include/asm/qspinlock.h:53 [inline]
queued_spin_lock include/asm-generic/qspinlock.h:88 [inline]
do_raw_spin_lock+0x189/0x220 kernel/locking/spinlock_debug.c:113
spin_lock include/linux/spinlock.h:329 [inline]
s_start+0x15/0x50 mm/vmalloc.c:2665
seq_read+0x2a0/0x1160 fs/seq_file.c:224
proc_reg_read+0x1bd/0x2d0 fs/proc/inode.c:231
do_loop_readv_writev fs/read_write.c:701 [inline]
do_loop_readv_writev fs/read_write.c:688 [inline]
do_iter_read+0x471/0x630 fs/read_write.c:925
vfs_readv+0xe5/0x150 fs/read_write.c:987
kernel_readv fs/splice.c:362 [inline]
default_file_splice_read+0x457/0xa00 fs/splice.c:417
do_splice_to+0x10e/0x160 fs/splice.c:881
splice_direct_to_actor+0x2b9/0x8d0 fs/splice.c:959
do_splice_direct+0x1a7/0x270 fs/splice.c:1068
do_sendfile+0x550/0xc30 fs/read_write.c:1447
__do_sys_sendfile64 fs/read_write.c:1508 [inline]
__se_sys_sendfile64+0x147/0x160 fs/read_write.c:1494
do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x45e219
Code: 0d b4 fb ff c3 66 2e 0f 1f 84 00 00 00 00 00 66 90 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 db b3 fb ff c3 66 2e 0f 1f 84 00 00 00 00
RSP: 002b:00007febc9189c68 EFLAGS: 00000246 ORIG_RAX: 0000000000000028
RAX: ffffffffffffffda RBX: 0000000000000004 RCX: 000000000045e219
RDX: 0000000000000000 RSI: 0000000000000005 RDI: 0000000000000003
RBP: 000000000119bfc8 R08: 0000000000000000 R09: 0000000000000000
R10: 4000000000010046 R11: 0000000000000246 R12: 000000000119bf8c
R13: 00007ffcb257ab1f R14: 00007febc918a9c0 R15: 000000000119bf8c
rcu: rcu_preempt kthread starved for 10545 jiffies! g11245 f0x2 RCU_GP_WAIT_FQS(5) ->state=0x0 ->cpu=0
rcu: RCU grace-period kthread stack dump:
rcu_preempt R running task 29208 10 2 0x80000000
Call Trace:
context_switch kernel/sched/core.c:2828 [inline]
__schedule+0x887/0x2040 kernel/sched/core.c:3517
schedule+0x8d/0x1b0 kernel/sched/core.c:3561
schedule_timeout+0x4cf/0xfe0 kernel/time/timer.c:1818
rcu_gp_kthread+0xdad/0x21c0 kernel/rcu/tree.c:2202
kthread+0x33f/0x460 kernel/kthread.c:259
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415


---
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 22, 2022, 11:29:26 AM1/22/22
to syzkaller...@googlegroups.com
syzbot has found a reproducer for the following issue on:

HEAD commit: 3f8a27f9e27b Linux 4.19.211
git tree: linux-4.19.y
console output: https://syzkaller.appspot.com/x/log.txt?x=148698a8700000
kernel config: https://syzkaller.appspot.com/x/.config?x=9b9277b418617afe
dashboard link: https://syzkaller.appspot.com/bug?extid=4ea78af6ad1c826a825b
compiler: gcc version 10.2.1 20210110 (Debian 10.2.1-6)
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=1256bf88700000

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

wlan1: Created IBSS using preconfigured BSSID 50:50:50:50:50:50
wlan1: Creating new IBSS network, BSSID 50:50:50:50:50:50
IPv6: ADDRCONF(NETDEV_CHANGE): wlan1: link becomes ready
watchdog: BUG: soft lockup - CPU#0 stuck for 22s! [syz-executor.4:10907]
Modules linked in:
irq event stamp: 2941346
hardirqs last enabled at (2941345): [<ffffffff81003ce4>] trace_hardirqs_on_thunk+0x1a/0x1c
hardirqs last disabled at (2941346): [<ffffffff81003d00>] trace_hardirqs_off_thunk+0x1a/0x1c
softirqs last enabled at (2935832): [<ffffffff88400678>] __do_softirq+0x678/0x980 kernel/softirq.c:318
softirqs last disabled at (2935659): [<ffffffff813927d5>] invoke_softirq kernel/softirq.c:372 [inline]
softirqs last disabled at (2935659): [<ffffffff813927d5>] irq_exit+0x215/0x260 kernel/softirq.c:412
CPU: 0 PID: 10907 Comm: syz-executor.4 Not tainted 4.19.211-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
RIP: 0010:pv_wait_head_or_lock kernel/locking/qspinlock_paravirt.h:435 [inline]
RIP: 0010:__pv_queued_spin_lock_slowpath+0x3a6/0xae0 kernel/locking/qspinlock.c:474
Code: eb c6 45 01 01 41 bc 00 80 00 00 48 c1 e9 03 83 e3 07 41 be 01 00 00 00 48 b8 00 00 00 00 00 fc ff df 4c 8d 2c 01 eb 0c f3 90 <41> 83 ec 01 0f 84 38 04 00 00 41 0f b6 45 00 38 d8 7f 08 84 c0 0f
RSP: 0018:ffff8880894a7380 EFLAGS: 00000206 ORIG_RAX: ffffffffffffff13
RAX: 0000000000000003 RBX: 0000000000000000 RCX: 1ffffffff1479ff4
RDX: 0000000000000001 RSI: ffffffff8167a995 RDI: 0000000000000286
RBP: ffffffff8a3cffa0 R08: 0000000000000001 R09: 0000000000000000
R10: 0000000000000001 R11: 0000000000000000 R12: 00000000000074ea
R13: fffffbfff1479ff4 R14: 0000000000000001 R15: ffff8880ba02be00
FS: 00007fe7d461d700(0000) GS:ffff8880ba000000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007fb1ba58e718 CR3: 00000000a5a6f000 CR4: 00000000003406f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
pv_queued_spin_lock_slowpath arch/x86/include/asm/paravirt.h:679 [inline]
queued_spin_lock_slowpath arch/x86/include/asm/qspinlock.h:53 [inline]
queued_spin_lock include/asm-generic/qspinlock.h:88 [inline]
do_raw_spin_lock+0x189/0x220 kernel/locking/spinlock_debug.c:113
spin_lock include/linux/spinlock.h:329 [inline]
proc_keys_start+0x4d/0x450 security/keys/proc.c:123
seq_read+0x2a0/0x11c0 fs/seq_file.c:227
proc_reg_read+0x1bd/0x2d0 fs/proc/inode.c:231
do_loop_readv_writev fs/read_write.c:701 [inline]
do_loop_readv_writev fs/read_write.c:688 [inline]
do_iter_read+0x471/0x630 fs/read_write.c:925
vfs_readv+0xe5/0x150 fs/read_write.c:987
kernel_readv fs/splice.c:362 [inline]
default_file_splice_read+0x457/0xa00 fs/splice.c:417
do_splice_to+0x10e/0x160 fs/splice.c:881
splice_direct_to_actor+0x2b9/0x8d0 fs/splice.c:959
do_splice_direct+0x1a7/0x270 fs/splice.c:1068
do_sendfile+0x550/0xc30 fs/read_write.c:1447
__do_sys_sendfile64 fs/read_write.c:1508 [inline]
__se_sys_sendfile64+0x147/0x160 fs/read_write.c:1494
do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x7fe7d4ea8059
Code: ff ff c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 40 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 73 01 c3 48 c7 c1 b8 ff ff ff f7 d8 64 89 01 48
RSP: 002b:00007fe7d461d168 EFLAGS: 00000246 ORIG_RAX: 0000000000000028
RAX: ffffffffffffffda RBX: 00007fe7d4fbaf60 RCX: 00007fe7d4ea8059
RDX: 0000000000000000 RSI: 0000000000000004 RDI: 000000000000000d
RBP: 00007fe7d4f0208d R08: 0000000000000000 R09: 0000000000000000
R10: 000000007ffff06c R11: 0000000000000246 R12: 0000000000000000
R13: 00007ffc3665bc9f R14: 00007fe7d461d300 R15: 0000000000022000
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 PID: 10909 Comm: syz-executor.1 Not tainted 4.19.211-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
RIP: 0010:lockdep_hardirqs_off+0x22/0x2c0 kernel/locking/lockdep.c:2895
Code: 0f 1f 84 00 00 00 00 00 48 c7 c0 60 f1 45 8a 41 54 48 ba 00 00 00 00 00 fc ff df 48 89 c1 55 83 e0 07 48 89 fd 48 c1 e9 03 53 <83> c0 03 0f b6 14 11 65 48 8b 1c 25 c0 df 01 00 38 d0 7c 08 84 d2
RSP: 0018:ffff8880ba107450 EFLAGS: 00000802
RAX: 0000000000000000 RBX: ffff8880ba124cc0 RCX: 1ffffffff148be2c
RDX: dffffc0000000000 RSI: ffffffff8167adc4 RDI: ffffffff88194e05
RBP: ffffffff88194e05 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000005 R11: ffffffff8c66505b R12: 0000000000000000
R13: ffff8880a15c41d8 R14: ffff8880ba124d40 R15: dffffc0000000000
FS: 00007fb1ba5af700(0000) GS:ffff8880ba100000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 0000555555c0b108 CR3: 00000000a593f000 CR4: 00000000003406e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
<IRQ>
__raw_spin_lock_irq include/linux/spinlock_api_smp.h:126 [inline]
_raw_spin_lock_irq+0x35/0x80 kernel/locking/spinlock.c:160
__run_hrtimer kernel/time/hrtimer.c:1467 [inline]
__hrtimer_run_queues+0x45d/0xe60 kernel/time/hrtimer.c:1527
hrtimer_interrupt+0x326/0x9e0 kernel/time/hrtimer.c:1585
local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1071 [inline]
smp_apic_timer_interrupt+0x10c/0x550 arch/x86/kernel/apic/apic.c:1096
apic_timer_interrupt+0xf/0x20 arch/x86/entry/entry_64.S:894
RIP: 0010:unwind_next_frame+0xb08/0x1400 arch/x86/kernel/unwind_orc.c:548
Code: 84 c6 0f 85 13 07 00 00 48 89 c8 83 e0 07 38 c2 40 0f 9e c6 84 d2 0f 95 c0 40 84 c6 0f 85 f9 06 00 00 41 0f b6 47 04 c0 e8 04 <3c> 01 0f 84 fc 03 00 00 3c 04 0f 84 78 04 00 00 84 c0 0f 84 c7 02
RSP: 0018:ffff8880ba107730 EFLAGS: 00000202 ORIG_RAX: ffffffffffffff13
RAX: 0000000000000001 RBX: 1ffff11017420eef RCX: ffffffff8c092621
RDX: 0000000000000000 RSI: 0000000000000001 RDI: ffff8880ba1078b8
RBP: 0000000000000002 R08: ffffffff8c092620 R09: ffffffff8c092610
R10: ffff8880ba1078bf R11: 0000000000074071 R12: ffff8880ba107ea0
R13: ffff8880ba107895 R14: ffff8880ba107860 R15: ffffffff8c09261c
__save_stack_trace+0x9f/0x190 arch/x86/kernel/stacktrace.c:44
save_stack mm/kasan/kasan.c:448 [inline]
set_track mm/kasan/kasan.c:460 [inline]
kasan_kmalloc+0xeb/0x160 mm/kasan/kasan.c:553
kmem_cache_alloc_node_trace+0x151/0x3b0 mm/slab.c:3668
__do_kmalloc_node mm/slab.c:3688 [inline]
__kmalloc_node_track_caller+0x38/0x70 mm/slab.c:3703
__kmalloc_reserve net/core/skbuff.c:137 [inline]
__alloc_skb+0xae/0x560 net/core/skbuff.c:205
skb_copy+0x139/0x2f0 net/core/skbuff.c:1358
mac80211_hwsim_tx_frame_no_nl.isra.0+0xb8a/0x1330 drivers/net/wireless/mac80211_hwsim.c:1353
mac80211_hwsim_tx_frame+0x12b/0x210 drivers/net/wireless/mac80211_hwsim.c:1556
mac80211_hwsim_beacon_tx+0x3f8/0x680 drivers/net/wireless/mac80211_hwsim.c:1595
__iterate_interfaces+0x2e1/0x4a0 net/mac80211/util.c:614
ieee80211_iterate_active_interfaces_atomic+0x8d/0x170 net/mac80211/util.c:650
mac80211_hwsim_beacon+0xc9/0x190 drivers/net/wireless/mac80211_hwsim.c:1615
__tasklet_hrtimer_trampoline+0x29/0xa0 kernel/softirq.c:601
tasklet_action_common.constprop.0+0x265/0x360 kernel/softirq.c:522
__do_softirq+0x265/0x980 kernel/softirq.c:292
invoke_softirq kernel/softirq.c:372 [inline]
irq_exit+0x215/0x260 kernel/softirq.c:412
exiting_irq arch/x86/include/asm/apic.h:536 [inline]
smp_apic_timer_interrupt+0x136/0x550 arch/x86/kernel/apic/apic.c:1098
apic_timer_interrupt+0xf/0x20 arch/x86/entry/entry_64.S:894
</IRQ>
RIP: 0010:vsnprintf+0xf1b/0x14f0 lib/vsprintf.c:2269
Code: f9 48 8b 4c 24 68 4c 89 f2 4c 89 e7 48 8b 74 24 18 e8 a9 44 ff ff 4c 89 ea 49 89 c4 4c 89 e8 83 e2 07 48 c1 e8 03 0f b6 04 18 <38> d0 0f 8f 1d f3 ff ff 84 c0 0f 84 15 f3 ff ff 4c 89 ef e8 7d a4
RSP: 0018:ffff88808db7f128 EFLAGS: 00000a03 ORIG_RAX: ffffffffffffff13
RAX: 0000000000000000 RBX: dffffc0000000000 RCX: ffffffff87f00771
RDX: 0000000000000007 RSI: ffffffff87f007da RDI: 0000000000000005
RBP: 0000000000000030 R08: 0000000000000010 R09: 0000000000000000
R10: 0000000000000005 R11: 00000000a8d1f317 R12: ffff8880a22f9114
R13: ffffffff88ab7f97 R14: 0000000000000001 R15: ffff88808db7f240
seq_vprintf fs/seq_file.c:394 [inline]
seq_printf+0x195/0x240 fs/seq_file.c:409
proc_keys_show+0x783/0xbf0 security/keys/proc.c:228
seq_read+0xc22/0x11c0 fs/seq_file.c:271
proc_reg_read+0x1bd/0x2d0 fs/proc/inode.c:231
do_loop_readv_writev fs/read_write.c:701 [inline]
do_loop_readv_writev fs/read_write.c:688 [inline]
do_iter_read+0x471/0x630 fs/read_write.c:925
vfs_readv+0xe5/0x150 fs/read_write.c:987
kernel_readv fs/splice.c:362 [inline]
default_file_splice_read+0x457/0xa00 fs/splice.c:417
do_splice_to+0x10e/0x160 fs/splice.c:881
splice_direct_to_actor+0x2b9/0x8d0 fs/splice.c:959
do_splice_direct+0x1a7/0x270 fs/splice.c:1068
do_sendfile+0x550/0xc30 fs/read_write.c:1447
__do_sys_sendfile64 fs/read_write.c:1508 [inline]
__se_sys_sendfile64+0x147/0x160 fs/read_write.c:1494
do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x7fb1bae3a059
Code: ff ff c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 40 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 73 01 c3 48 c7 c1 b8 ff ff ff f7 d8 64 89 01 48
RSP: 002b:00007fb1ba5af168 EFLAGS: 00000246 ORIG_RAX: 0000000000000028
RAX: ffffffffffffffda RBX: 00007fb1baf4cf60 RCX: 00007fb1bae3a059
RDX: 0000000000000000 RSI: 0000000000000004 RDI: 000000000000000d
RBP: 00007fb1bae9408d R08: 0000000000000000 R09: 0000000000000000
R10: 000000007ffff06c R11: 0000000000000246 R12: 0000000000000000
R13: 00007ffd31aa6
----------------
Code disassembly (best guess):
0: eb c6 jmp 0xffffffc8
2: 45 01 01 add %r8d,(%r9)
5: 41 bc 00 80 00 00 mov $0x8000,%r12d
b: 48 c1 e9 03 shr $0x3,%rcx
f: 83 e3 07 and $0x7,%ebx
12: 41 be 01 00 00 00 mov $0x1,%r14d
18: 48 b8 00 00 00 00 00 movabs $0xdffffc0000000000,%rax
1f: fc ff df
22: 4c 8d 2c 01 lea (%rcx,%rax,1),%r13
26: eb 0c jmp 0x34
28: f3 90 pause
* 2a: 41 83 ec 01 sub $0x1,%r12d <-- trapping instruction
2e: 0f 84 38 04 00 00 je 0x46c
34: 41 0f b6 45 00 movzbl 0x0(%r13),%eax
39: 38 d8 cmp %bl,%al
3b: 7f 08 jg 0x45
3d: 84 c0 test %al,%al
3f: 0f .byte 0xf

Reply all
Reply to author
Forward
0 new messages