linux-kernel - INFO: rcu detected stall in hwrng

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<prev] [next>] [thread-next>] [day] [month] [year] [list]
Date:   Tue, 11 Oct 2022 00:11:39 +0800
From:   Wei Chen <harperchen1110@...il.com>
To:     mpm@...enic.com, herbert@...dor.apana.org.au,
        linux@...inikbrodowski.net, ebiggers@...gle.com, Jason@...c4.com
Cc:     linux-crypto@...r.kernel.org, linux-kernel@...r.kernel.org
Subject: INFO: rcu detected stall in hwrng_fillfn

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@...il.com>

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