[v6.1] INFO: rcu detected stall in sys_symlinkat

0 views
Skip to first unread message

syzbot

unread,
Apr 26, 2023, 11:28:45 PM4/26/23
to syzkaller...@googlegroups.com
Hello,

syzbot found the following issue on:

HEAD commit: ca1c9012c941 Linux 6.1.26
git tree: linux-6.1.y
console output: https://syzkaller.appspot.com/x/log.txt?x=16a21078280000
kernel config: https://syzkaller.appspot.com/x/.config?x=1fd4f42b64f6be23
dashboard link: https://syzkaller.appspot.com/bug?extid=e7522db4f894fa428f83
compiler: Debian clang version 15.0.7, GNU ld (GNU Binutils for Debian) 2.35.2

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

Downloadable assets:
disk image: https://storage.googleapis.com/syzbot-assets/a25fb5b2082b/disk-ca1c9012.raw.xz
vmlinux: https://storage.googleapis.com/syzbot-assets/42b008ccf60d/vmlinux-ca1c9012.xz
kernel image: https://storage.googleapis.com/syzbot-assets/9af57b62e8fa/bzImage-ca1c9012.xz

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

rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
rcu: 0-...!: (1 GPs behind) idle=8aac/1/0x4000000000000000 softirq=117382/117383 fqs=0
rcu: Tasks blocked on level-0 rcu_node (CPUs 0-1): P3273/1:b..l
(detected by 1, t=10505 jiffies, g=177253, q=70 ncpus=2)
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 3269 Comm: syz-executor.1 Not tainted 6.1.26-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 04/14/2023
RIP: 0010:hlock_class kernel/locking/lockdep.c:240 [inline]
RIP: 0010:check_wait_context kernel/locking/lockdep.c:4755 [inline]
RIP: 0010:__lock_acquire+0x796/0x1f80 kernel/locking/lockdep.c:5006
Code: 00 81 e3 ff 1f 00 00 48 89 d8 48 c1 e8 06 48 8d 3c c5 80 11 27 90 be 08 00 00 00 e8 c4 1d 76 00 48 0f a3 1d 4c 6c bd 0e 73 1b <48> 8d 04 5b 48 c1 e0 06 48 8d 98 80 70 f6 8f 48 ba 00 00 00 00 00
RSP: 0018:ffffc90000007a00 EFLAGS: 00000057
RAX: 0000000000000001 RBX: 0000000000000062 RCX: ffffffff8169a52c
RDX: 0000000000000000 RSI: 0000000000000008 RDI: ffffffff90271188
RBP: ffff88802147a800 R08: dffffc0000000000 R09: fffffbfff204e232
R10: 0000000000000000 R11: dffffc0000000001 R12: 0000000000000002
R13: ffff88802147a800 R14: 0000000000000002 R15: 1ffff1100428f502
FS: 00005555563bc400(0000) GS:ffff8880b9800000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007f7d6b50e801 CR3: 000000007ddc4000 CR4: 00000000003506f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
<IRQ>
lock_acquire+0x1f8/0x5a0 kernel/locking/lockdep.c:5669
__raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
_raw_spin_lock_irqsave+0xd1/0x120 kernel/locking/spinlock.c:162
debug_object_deactivate+0x61/0x3f0 lib/debugobjects.c:739
debug_hrtimer_deactivate kernel/time/hrtimer.c:425 [inline]
debug_deactivate+0x1d/0x280 kernel/time/hrtimer.c:481
__run_hrtimer kernel/time/hrtimer.c:1653 [inline]
__hrtimer_run_queues+0x334/0xe50 kernel/time/hrtimer.c:1749
hrtimer_interrupt+0x392/0x980 kernel/time/hrtimer.c:1811
local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1096 [inline]
__sysvec_apic_timer_interrupt+0x156/0x580 arch/x86/kernel/apic/apic.c:1113
sysvec_apic_timer_interrupt+0x8c/0xb0 arch/x86/kernel/apic/apic.c:1107
</IRQ>
<TASK>
asm_sysvec_apic_timer_interrupt+0x16/0x20 arch/x86/include/asm/idtentry.h:649
RIP: 0010:__find_get_block+0x2b9/0x1120 fs/buffer.c:1305
Code: 8b ff 49 83 fc f1 74 11 e8 94 21 8b ff 49 83 c7 08 49 ff cc e9 f8 fe ff ff e8 83 21 8b ff 45 31 ed e8 bb d2 91 ff fb 4d 85 ed <74> 6b e8 70 21 8b ff 4c 89 ef e8 28 d5 ff ff 48 c7 44 24 40 0e 36
RSP: 0018:ffffc90004f5f640 EFLAGS: 00000246
RAX: a758ea71cf50bc00 RBX: 0000000000021ec2 RCX: ffffffff816a047a
RDX: dffffc0000000000 RSI: ffffffff8aebc620 RDI: ffffffff8b3cb520
RBP: ffffc90004f5f770 R08: dffffc0000000000 R09: fffffbfff204e245
R10: 0000000000000000 R11: dffffc0000000001 R12: fffffffffffffff1
R13: 0000000000000000 R14: 000000000000164c R15: 0000000000035db0
__getblk_gfp+0x2d/0xa20 fs/buffer.c:1329
sb_getblk include/linux/buffer_head.h:356 [inline]
ext4_getblk+0x2a7/0x7c0 fs/ext4/inode.c:874
ext4_bread_batch+0x5f/0x4d0 fs/ext4/inode.c:941
__ext4_find_entry+0xfd1/0x1b20 fs/ext4/namei.c:1650
ext4_lookup_entry fs/ext4/namei.c:1751 [inline]
ext4_lookup+0x176/0x740 fs/ext4/namei.c:1819
__lookup_hash+0x117/0x240 fs/namei.c:1601
filename_create+0x28d/0x530 fs/namei.c:3808
do_symlinkat+0xf6/0x600 fs/namei.c:4420
__do_sys_symlinkat fs/namei.c:4447 [inline]
__se_sys_symlinkat fs/namei.c:4444 [inline]
__x64_sys_symlinkat+0x95/0xa0 fs/namei.c:4444
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x3d/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x63/0xcd
RIP: 0033:0x7f7d6b48baa7
Code: 73 01 c3 48 c7 c1 b8 ff ff ff f7 d8 64 89 01 48 83 c8 ff c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 b8 0a 01 00 00 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:00007ffeb0c6d1b8 EFLAGS: 00000206 ORIG_RAX: 000000000000010a
RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007f7d6b48baa7
RDX: 00007f7d6b4e7d4d RSI: 00000000ffffff9c RDI: 00007ffeb0c6d280
RBP: 0000000000000001 R08: 0000000000000000 R09: 00007ffeb0c6d050
R10: 00007ffeb0c6cf07 R11: 0000000000000206 R12: 0000000000000001
R13: 0000000000000000 R14: 0000000000000001 R15: 00007ffeb0c6d280
</TASK>
task:syz-executor.3 state:R running task stack:24968 pid:3273 ppid:2421 flags:0x00004000
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5241 [inline]
__schedule+0x132c/0x4330 kernel/sched/core.c:6554
preempt_schedule_irq+0xf7/0x1c0 kernel/sched/core.c:6866
irqentry_exit+0x53/0x80 kernel/entry/common.c:433
asm_sysvec_apic_timer_interrupt+0x16/0x20 arch/x86/include/asm/idtentry.h:649
RIP: 0010:check_kcov_mode kernel/kcov.c:173 [inline]
RIP: 0010:write_comp_data kernel/kcov.c:236 [inline]
RIP: 0010:__sanitizer_cov_trace_switch+0x64/0xe0 kernel/kcov.c:340
Code: c5 f0 cc ef 8a 4c 8b 4c 24 20 65 4c 8b 1d e4 d9 78 7e 31 d2 eb 08 48 ff c2 49 39 d2 74 71 4c 8b 74 d6 10 65 8b 05 d4 d9 78 7e <a9> 00 01 ff 00 74 11 a9 00 01 00 00 74 de 41 83 bb 8c 15 00 00 00
RSP: 0018:ffffc90005a2f4f8 EFLAGS: 00000202
RAX: 0000000080000000 RBX: ffff888074dd6a0c RCX: 000000000000008b
RDX: 0000000000000001 RSI: ffffffff8e3bdb90 RDI: 0000000000000001
RBP: ffffc90005a2f710 R08: 0000000000000005 R09: ffffffff8a74f00f
R10: 0000000000000003 R11: ffff888029a8ba80 R12: ffff88801ea59898
R13: ffffc90005a2f688 R14: 0000000000000002 R15: 0000000000000001
ma_pivots lib/maple_tree.c:630 [inline]
mas_validate_child_slot lib/maple_tree.c:7067 [inline]
mt_validate+0x17ff/0x5ba0 lib/maple_tree.c:7239
validate_mm_mt+0x165/0x670 mm/mmap.c:295
validate_mm+0x16e/0x380 mm/mmap.c:332
__vma_adjust+0x1d30/0x1f30 mm/mmap.c:857
__split_vma+0x36e/0x530
mprotect_fixup+0x6a2/0x840 mm/mprotect.c:617
do_mprotect_pkey+0x8b6/0xbe0 mm/mprotect.c:792
__do_sys_mprotect mm/mprotect.c:819 [inline]
__se_sys_mprotect mm/mprotect.c:816 [inline]
__x64_sys_mprotect+0x7c/0x90 mm/mprotect.c:816
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x3d/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x63/0xcd
RIP: 0033:0x7fd63808c277
RSP: 002b:00007fff578677b8 EFLAGS: 00000206 ORIG_RAX: 000000000000000a
RAX: ffffffffffffffda RBX: 0000000000021000 RCX: 00007fd63808c277
RDX: 0000000000000003 RSI: 0000000000020000 RDI: 00007fd638d22000
RBP: 00007fff57867890 R08: 00000000ffffffff R09: 00007fd638d41700
R10: 0000000000020022 R11: 0000000000000206 R12: 00007fff578679b0
R13: 00007fd638d41700 R14: 0000000000000000 R15: 0000000000022000
</TASK>
rcu: rcu_preempt kthread starved for 10505 jiffies! g177253 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x0 ->cpu=1
rcu: Unless rcu_preempt kthread gets sufficient CPU time, OOM is now expected behavior.
rcu: RCU grace-period kthread stack dump:
task:rcu_preempt state:R running task stack:26712 pid:16 ppid:2 flags:0x00004000
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5241 [inline]
__schedule+0x132c/0x4330 kernel/sched/core.c:6554
schedule+0xbf/0x180 kernel/sched/core.c:6630
schedule_timeout+0x1b9/0x300 kernel/time/timer.c:1935
rcu_gp_fqs_loop+0x2c2/0x1010 kernel/rcu/tree.c:1660
rcu_gp_kthread+0xa3/0x3a0 kernel/rcu/tree.c:1859
kthread+0x268/0x300 kernel/kthread.c:376
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:306
</TASK>
rcu: Stack dump where RCU GP kthread last ran:
CPU: 1 PID: 30407 Comm: kworker/u4:60 Not tainted 6.1.26-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 04/14/2023
Workqueue: events_unbound toggle_allocation_gate
RIP: 0010:csd_lock_wait kernel/smp.c:413 [inline]
RIP: 0010:smp_call_function_many_cond+0x1f67/0x33d0 kernel/smp.c:987
Code: e6 01 31 ff e8 9a 0c 0b 00 41 83 e5 01 49 bd 00 00 00 00 00 fc ff df 75 0a e8 25 09 0b 00 e9 1b ff ff ff f3 90 42 0f b6 04 2b <84> c0 75 14 41 f7 07 01 00 00 00 0f 84 fe fe ff ff e8 03 09 0b 00
RSP: 0000:ffffc9000b6175a0 EFLAGS: 00000293
RAX: 0000000000000000 RBX: 1ffff11017308415 RCX: ffff888017f01d40
RDX: 0000000000000000 RSI: 0000000000000001 RDI: 0000000000000000
RBP: ffffc9000b617980 R08: ffffffff817e8776 R09: fffffbfff204e231
R10: 0000000000000000 R11: dffffc0000000001 R12: 0000000800000000
R13: dffffc0000000000 R14: 0000000000000000 R15: ffff8880b98420a8
FS: 0000000000000000(0000) GS:ffff8880b9900000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007f624e384c18 CR3: 000000000cc8e000 CR4: 00000000003506e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
<TASK>
on_each_cpu_cond_mask+0x3b/0x80 kernel/smp.c:1155
on_each_cpu include/linux/smp.h:71 [inline]
text_poke_sync arch/x86/kernel/alternative.c:1316 [inline]
text_poke_bp_batch+0x2bb/0x940 arch/x86/kernel/alternative.c:1516
text_poke_flush arch/x86/kernel/alternative.c:1707 [inline]
text_poke_finish+0x16/0x30 arch/x86/kernel/alternative.c:1714
arch_jump_label_transform_apply+0x13/0x20 arch/x86/kernel/jump_label.c:146
static_key_enable_cpuslocked+0x12e/0x250 kernel/jump_label.c:177
static_key_enable+0x16/0x20 kernel/jump_label.c:190
toggle_allocation_gate+0xbf/0x480 mm/kfence/core.c:804
process_one_work+0x8aa/0x11f0 kernel/workqueue.c:2289
worker_thread+0xa5f/0x1210 kernel/workqueue.c:2436
kthread+0x268/0x300 kernel/kthread.c:376
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:306
</TASK>


---
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,
Aug 23, 2023, 5:07:35 AM8/23/23
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