linux-kernel - RCU stall on 6.1-rc4 (and some previous releases) related to ftrace

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]

Message-ID: <1ef5fe19-a82f-835e-fda5-455e9c2b94b4@igalia.com>
Date:   Thu, 10 Nov 2022 18:25:41 -0300
From:   "Guilherme G. Piccoli" <gpiccoli@...lia.com>
To:     linux-kernel <linux-kernel@...r.kernel.org>,
        Steven Rostedt <rostedt@...dmis.org>
Cc:     Masami Hiramatsu <mhiramat@...nel.org>,
        Mark Rutland <mark.rutland@....com>,
        "rcu@...r.kernel.org" <rcu@...r.kernel.org>,
        "kernel-dev@...lia.com" <kernel-dev@...lia.com>,
        "Guilherme G. Piccoli" <kernel@...ccoli.net>
Subject: RCU stall on 6.1-rc4 (and some previous releases) related to ftrace

Hi folks, I've noticed some RCU stalls when enabling ftrace filtering in
6.1-rc4 (also 6.1-rc3 and I guess I've seen this before, but only in
6.0+). Here is the full dmesg: https://termbin.com/4xo6 , see below for
a small snippet of the stall [0].

I've briefly talked to Steve on IRC, and he mentioned that my kernel
seemed to have PREEMPT_VOLUNTARY=y (and indeed, this is the case - see
the full config here: https://termbin.com/t48d), saying that maybe
adding a cond_resched() in the loop would help.

So, I've cooked a small hack (see the patch attached) and it seems to
work. Steve: lemme know if you want to send it (since it's your idea and
maybe my hack is not covering all cases), or if you prefer, I can work a
commit message and send myself.

Any other advice / tests required, please lemme me know and I'll be glad
in contributing.

Cheers,

Guilherme

[0]
rcu: INFO: rcu_preempt detected expedited stalls on CPUs/tasks: { 1-....
} 6 jiffies s: 1289 root: 0x2/.
rcu: blocking rcu_node structures (internal RCU debug):
Sending NMI from CPU 4 to CPUs 1:
NMI backtrace for cpu 1
[...]
RIP: 0010:find_kallsyms_symbol+0x85/0x1a0
[...]
Call Trace:
 <TASK>
 ? get_refcyc_per_delivery.constprop.0+0x200/0x200 [amdgpu]
 module_address_lookup+0x63/0xc0
 ? get_refcyc_per_delivery.constprop.0+0x200/0x200 [amdgpu]
 kallsyms_lookup_buildid+0xb6/0x130
 ftrace_match_record+0x43/0xf0
 ? match_records+0x210/0x3b0
 ? __kmem_cache_alloc_node+0x165/0x260
 match_records+0x13a/0x3b0
 ftrace_process_regex.isra.0+0x101/0x120
 ftrace_filter_write+0x57/0x90
[...]
rcu: INFO: rcu_preempt detected expedited stalls on CPUs/tasks: { 1-....
} 25 jiffies s: 1289 root: 0x2/.
rcu: blocking rcu_node structures (internal RCU debug):
Sending NMI from CPU 4 to CPUs 1:
[...]
RIP: 0010:find_kallsyms_symbol+0x8f/0x1a0
[...]
Call Trace:
 <TASK>
 ? dcn21_dmcu_create+0xd0/0xd0 [amdgpu]
 module_address_lookup+0x63/0xc0
 ? dcn21_dmcu_create+0xd0/0xd0 [amdgpu]
 kallsyms_lookup_buildid+0xb6/0x130
 ftrace_match_record+0x43/0xf0
 ? match_records+0x210/0x3b0
 ? __kmem_cache_alloc_node+0x165/0x260
 match_records+0x13a/0x3b0
 ftrace_process_regex.isra.0+0x101/0x120
 ftrace_filter_write+0x57/0x90
[...]
View attachment "0001-ftrace-hack-Add-cond_resched-to-prevent-RCU-stall.patch" of type "text/x-patch" (798 bytes)