INFO: rcu detected stall in hwrng_fillfn

From: Wei Chen
Date: Mon Oct 10 2022 - 12:12:26 EST


Dear Linux Developer,

Recently when using our tool to fuzz kernel, the following crash was triggered:

HEAD commit: c5eb0a61238d Linux 5.18-rc6
git tree: upstream
compiler: clang 12.0.0
console output:
https://drive.google.com/file/d/1JHFwMk9CWxcUbREbJehKSd98-AvyT3DA/view?usp=sharing
kernel config: https://drive.google.com/file/d/12fNP5UArsFqTi2jjGomWuCk5evtgU0Gu/view?usp=sharing

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: Wei Chen <harperchen1110@xxxxxxxxx>

rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
rcu: Tasks blocked on level-0 rcu_node (CPUs 0-0): P6559/1:b..l
(detected by 0, t=24003 jiffies, g=61277, q=132)
task:sshd state:R running task stack:22448 pid: 6559
ppid: 6396 flags:0x00004002
Call Trace:
<TASK>
__schedule+0xb8e/0x1140
preempt_schedule+0x12b/0x180
preempt_schedule_thunk+0x16/0x18
__local_bh_enable_ip+0x14b/0x1c0
ip_finish_output2+0xdb2/0x19b0
__ip_queue_xmit+0x11bb/0x1c20
__tcp_transmit_skb+0x1e33/0x3410
tcp_write_xmit+0x1b6e/0x77a0
__tcp_push_pending_frames+0x8e/0x260
tcp_sendmsg_locked+0x390e/0x4740
tcp_sendmsg+0x2c/0x40
sock_write_iter+0x398/0x520
vfs_write+0xa02/0xd20
ksys_write+0x16b/0x2a0
do_syscall_64+0x3d/0x90
entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7f59438db970
RSP: 002b:00007ffcf76d77b8 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
RAX: ffffffffffffffda RBX: 0000000000000034 RCX: 00007f59438db970
RDX: 0000000000000034 RSI: 000056378c676f48 RDI: 0000000000000003
RBP: 000056378c65dfa0 R08: 00007ffcf77cd080 R09: 0000000000000070
R10: 00007ffcf77cd118 R11: 0000000000000246 R12: 0000000000000000
R13: 00007ffcf76d784f R14: 000056378b47bbe7 R15: 0000000000000003
</TASK>
rcu: rcu_preempt kthread timer wakeup didn't happen for 20549 jiffies!
g61277 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402
rcu: Possible timer handling issue on cpu=0 timer-softirq=24406
rcu: rcu_preempt kthread starved for 20550 jiffies! g61277 f0x0
RCU_GP_WAIT_FQS(5) ->state=0x402 ->cpu=0
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:I stack:27792 pid: 16 ppid: 2 flags:0x00004000
Call Trace:
<TASK>
__schedule+0xb8e/0x1140
schedule+0xeb/0x1b0
schedule_timeout+0x1aa/0x2f0
rcu_gp_fqs_loop+0x1fd/0x770
rcu_gp_kthread+0xa5/0x340
kthread+0x266/0x300
ret_from_fork+0x1f/0x30
</TASK>
rcu: Stack dump where RCU GP kthread last ran:
NMI backtrace for cpu 0
CPU: 0 PID: 735 Comm: hwrng Not tainted 5.18.0-rc6 #2
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
1.13.0-1ubuntu1.1 04/01/2014
Call Trace:
<IRQ>
dump_stack_lvl+0x1b1/0x28e
nmi_cpu_backtrace+0x40e/0x440
nmi_trigger_cpumask_backtrace+0x16a/0x280
rcu_check_gp_kthread_starvation+0x1f9/0x270
rcu_sched_clock_irq+0x255f/0x2d60
update_process_times+0x197/0x200
tick_sched_timer+0x376/0x540
__hrtimer_run_queues+0x4cb/0xa60
hrtimer_interrupt+0x3b3/0x1040
__sysvec_apic_timer_interrupt+0xf9/0x280
sysvec_apic_timer_interrupt+0x8c/0xb0
</IRQ>
<TASK>
asm_sysvec_apic_timer_interrupt+0x12/0x20
RIP: 0010:iowrite16+0x1d/0x80
Code: 80 61 fd 5b 5d c3 0f 1f 80 00 00 00 00 55 53 48 89 f3 89 fd e8
c4 80 61 fd 48 81 fb 00 00 04 00 72 0a e8 b6 80 61 fd 66 89 2b <eb> 58
48 81 fb 01 00 01 00 72 0e e8 a3 80 61 fd 0f b7 d3 89 e8 66
RSP: 0018:ffffc900036dfd08 EFLAGS: 00000293
RAX: ffffffff8422337a RBX: ffffc90000093000 RCX: ffff888019864880
RDX: 0000000000000000 RSI: ffffc90000093000 RDI: 0000000000000000
RBP: 0000000000000000 R08: ffffffff8492ecd7 R09: ffff888105b34540
R10: fffff520006dbfc0 R11: 0000000000000000 R12: dffffc0000000000
R13: 0000000000000000 R14: dffffc0000000000 R15: ffff888105bedc00
vp_notify+0x52/0x70
virtqueue_kick+0x3bf/0x5e0
copy_data+0x24a/0x390
virtio_read+0xc5/0x200
hwrng_fillfn+0x14a/0x470
kthread+0x266/0x300
ret_from_fork+0x1f/0x30
</TASK>
----------------
Code disassembly (best guess):
0: 80 61 fd 5b andb $0x5b,-0x3(%rcx)
4: 5d pop %rbp
5: c3 retq
6: 0f 1f 80 00 00 00 00 nopl 0x0(%rax)
d: 55 push %rbp
e: 53 push %rbx
f: 48 89 f3 mov %rsi,%rbx
12: 89 fd mov %edi,%ebp
14: e8 c4 80 61 fd callq 0xfd6180dd
19: 48 81 fb 00 00 04 00 cmp $0x40000,%rbx
20: 72 0a jb 0x2c
22: e8 b6 80 61 fd callq 0xfd6180dd
27: 66 89 2b mov %bp,(%rbx)
* 2a: eb 58 jmp 0x84 <-- trapping instruction
2c: 48 81 fb 01 00 01 00 cmp $0x10001,%rbx
33: 72 0e jb 0x43
35: e8 a3 80 61 fd callq 0xfd6180dd
3a: 0f b7 d3 movzwl %bx,%edx
3d: 89 e8 mov %ebp,%eax
3f: 66 data16

Best,
Wei