github-mirror/linux
1
0
Fork 0
mirror of https://github.com/torvalds/linux.git synced 2026-10-22 23:01:49 +02:00
Code Issues Actions Packages Projects Releases Wiki Activity Graph

Report CSD-lock stall recovery time

Browse Source 
* Refactor to simplify csd_lock_wait_toolong() function prototype.
  * Report time required to recover from a CSD-lock stall.
  * Add a test of this reporting.
 -----BEGIN PGP SIGNATURE-----
 
 iQJHBAABCgAxFiEEbK7UrM+RBIrCoViJnr8S83LZ+4wFAmrNfTsTHHBhdWxtY2tA
 a2VybmVsLm9yZwAKCRCevxLzctn7jEVLD/9/yL6kJBQB1M6zXqzlCD6mbZ6zTJXy
 +VngewIiv4tGNODT5wx9CvRxl9eURiaobpGGbMl7CJF8k1YEbEfhKizsYicbkSpJ
 FzfoxudaZH8isld6JweY0ZpJ08VqiScHkIByp0Ybgh7dTNPkivULInxFqtJgcfvK
 06tQsMMle5oxiN/a+FJFSnkyVFNj9lAwwkzPfpFObsq3OotA7hU0LYmS6cp4m7HC
 7A8+6mJt/MsEOXlnq3NY4WaoxW/DwvznSIpxj3TO4cSsateUVfFDI3ks9KY+uNIy
 s+i+zBUQemgVQCGiWxY/0s3osimaGk7flU5L8mMjabuj1UWRPwudFUpY0I3xPrnd
 /giRHSTEe6n5e6jRqoMlPIvIaVMyG4FbEWzPfps/YOE1bLHzatLPisFqxwsbMbXG
 pYRmkyn93NoO+zYRJScD9C3DBsYY1OSF0MaUWImLo59/1Eo9PdZCBcLEtwUCP7te
 yIxZKzGiVJXUOevUVPW86nhFS4bnBvTAiZ8mH2nrlNKFplsHpnS3No6k5P0yx4as
 oFvE3vdGFJOK4fGvZ2ixVr0HpRtMzsroclAK+PP4qgK6CMqOD+oXYSITtCLycXBz
 yeKzIkTXxszkFJmOrd/x/MykMxEf4nmzg9WwdH0fVjrcjswpo/jRpJhCrQG0p9ar
 Fcj4dwgldy+7UQ==
 =eLu3
 -----END PGP SIGNATURE-----

Merge tag 'csd-lock.2026.10.12a' of git://git.kernel.org/pub/scm/linux/kernel/git/paulmck/linux-rcu

Pull CSD lock updates from Paul McKenney:
 "Report CSD-lock stall recovery time:

   - Refactor to simplify csd_lock_wait_toolong() function prototype

   - Report time required to recover from a CSD-lock stall

   - Add a test of this reporting"

* tag 'csd-lock.2026.10.12a' of git://git.kernel.org/pub/scm/linux/kernel/git/paulmck/linux-rcu:
  lib/test_csd_lock: Add a module to stall a CPU on a CSD lock
  locking/csd-lock: Report how long a stuck CSD lock took to recover
  locking/csd-lock: Pack csd_lock_wait_toolong() state into a struct
This commit is contained in:
Linus Torvalds 2026-10-21 11:03:28 -10:00
commit a56a18c14a
4 changed files with 237 additions and 26 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

77
kernel/smp.c
View File

@ -237,50 +237,76 @@ bool csd_lock_is_stuck(void)
return !!atomic_read(&n_csd_lock_stuck);
}
/* State that csd_lock_wait_toolong() carries across the __csd_lock_wait() loop. */
struct csd_wait_state {
u64 ts_start; /* When the wait began. */
u64 ts_report; /* When the last complaint was printed. */
u64 ts_resend; /* When the last IPI was re-sent, 0 if never. */
int bug_id;
unsigned long nmessages;
};
/*
* Report a CSD lock that came back, @ts_unstuck being when the release was
* noticed. Only mention the re-send delta if an IPI was actually re-sent.
*/
static void csd_lock_print_unstuck(struct csd_wait_state *state, int cpu, u64 ts_unstuck)
{
if (state->ts_resend)
pr_alert("csd: CSD lock (#%d) got unstuck on CPU#%02d, CPU#%02d released the lock after %lld ns, %lld ns after the last IPI re-send.\n",
state->bug_id, raw_smp_processor_id(), cpu,
(s64)(ts_unstuck - state->ts_start),
(s64)(ts_unstuck - state->ts_resend));
else
pr_alert("csd: CSD lock (#%d) got unstuck on CPU#%02d, CPU#%02d released the lock after %lld ns.\n",
state->bug_id, raw_smp_processor_id(), cpu,
(s64)(ts_unstuck - state->ts_start));
}
/*
* Complain if too much time spent waiting. Note that only
* the CSD_TYPE_SYNC/ASYNC types provide the destination CPU,
* so waiting on other types gets much less information.
*/
static bool csd_lock_wait_toolong(call_single_data_t *csd, u64 ts0, u64 *ts1, int *bug_id, unsigned long *nmessages)
static bool csd_lock_wait_toolong(call_single_data_t *csd, struct csd_wait_state *state)
{
int cpu = -1;
int cpux;
bool firsttime;
u64 ts2, ts_delta;
u64 ts_now, ts_delta;
call_single_data_t *cpu_cur_csd;
unsigned int flags = READ_ONCE(csd->node.u_flags);
unsigned long long csd_lock_timeout_ns = csd_lock_timeout * NSEC_PER_MSEC;
if (!(flags & CSD_FLAG_LOCK)) {
if (!unlikely(*bug_id))
if (!unlikely(state->bug_id))
return true;
ts_now = ktime_get_mono_fast_ns();
cpu = csd_lock_wait_getcpu(csd);
pr_alert("csd: CSD lock (#%d) got unstuck on CPU#%02d, CPU#%02d released the lock.\n",
*bug_id, raw_smp_processor_id(), cpu);
csd_lock_print_unstuck(state, cpu, ts_now);
atomic_dec(&n_csd_lock_stuck);
return true;
}
ts2 = ktime_get_mono_fast_ns();
ts_now = ktime_get_mono_fast_ns();
/* How long since we last checked for a stuck CSD lock.*/
ts_delta = ts2 - *ts1;
if (likely(ts_delta <= csd_lock_timeout_ns * (*nmessages + 1) *
(!*nmessages ? 1 : (ilog2(num_online_cpus()) / 2 + 1)) ||
ts_delta = ts_now - state->ts_report;
if (likely(ts_delta <= csd_lock_timeout_ns * (state->nmessages + 1) *
(!state->nmessages ? 1 : (ilog2(num_online_cpus()) / 2 + 1)) ||
csd_lock_timeout_ns == 0))
return false;
if (ts0 > ts2) {
if (state->ts_start > ts_now) {
/* Our own sched_clock went backward; don't blame another CPU. */
ts_delta = ts0 - ts2;
ts_delta = state->ts_start - ts_now;
pr_alert("sched_clock on CPU %d went backward by %llu ns\n", raw_smp_processor_id(), ts_delta);
*ts1 = ts2;
state->ts_report = ts_now;
return false;
}
firsttime = !*bug_id;
firsttime = !state->bug_id;
if (firsttime)
*bug_id = atomic_inc_return(&csd_bug_count);
state->bug_id = atomic_inc_return(&csd_bug_count);
cpu = csd_lock_wait_getcpu(csd);
if (WARN_ONCE(cpu < 0 || cpu >= nr_cpu_ids, "%s: cpu = %d\n", __func__, cpu))
cpux = 0;
@ -294,11 +320,11 @@ static bool csd_lock_wait_toolong(call_single_data_t *csd, u64 ts0, u64 *ts1, in
*/
cpu_cur_csd = smp_load_acquire(&per_cpu(cur_csd, cpux));
/* How long since this CSD lock was stuck. */
ts_delta = ts2 - ts0;
ts_delta = ts_now - state->ts_start;
pr_alert("csd: %s non-responsive CSD lock (#%d) on CPU#%d, waiting %lld ns for CPU#%02d %pS(%ps).\n",
firsttime ? "Detected" : "Continued", *bug_id, raw_smp_processor_id(), (s64)ts_delta,
firsttime ? "Detected" : "Continued", state->bug_id, raw_smp_processor_id(), (s64)ts_delta,
cpu, csd->func, csd->info);
(*nmessages)++;
state->nmessages++;
if (firsttime)
atomic_inc(&n_csd_lock_stuck);
/*
@ -309,23 +335,24 @@ static bool csd_lock_wait_toolong(call_single_data_t *csd, u64 ts0, u64 *ts1, in
BUG_ON(panic_on_ipistall > 0 && (s64)ts_delta > ((s64)panic_on_ipistall * NSEC_PER_MSEC));
if (cpu_cur_csd && csd != cpu_cur_csd) {
pr_alert("\tcsd: CSD lock (#%d) handling prior %pS(%ps) request.\n",
*bug_id, READ_ONCE(per_cpu(cur_csd_func, cpux)),
state->bug_id, READ_ONCE(per_cpu(cur_csd_func, cpux)),
READ_ONCE(per_cpu(cur_csd_info, cpux)));
} else {
pr_alert("\tcsd: CSD lock (#%d) %s.\n",
*bug_id, !cpu_cur_csd ? "unresponsive" : "handling this request");
state->bug_id, !cpu_cur_csd ? "unresponsive" : "handling this request");
}
if (cpu >= 0) {
if (atomic_cmpxchg_acquire(&per_cpu(trigger_backtrace, cpu), 1, 0))
dump_cpu_task(cpu);
if (!cpu_cur_csd) {
pr_alert("csd: Re-sending CSD lock (#%d) IPI from CPU#%02d to CPU#%02d\n", *bug_id, raw_smp_processor_id(), cpu);
pr_alert("csd: Re-sending CSD lock (#%d) IPI from CPU#%02d to CPU#%02d\n", state->bug_id, raw_smp_processor_id(), cpu);
arch_send_call_function_single_ipi(cpu);
state->ts_resend = ktime_get_mono_fast_ns();
}
}
if (firsttime)
dump_stack();
*ts1 = ts2;
state->ts_report = ts_now;
return false;
}
@ -339,15 +366,13 @@ static bool csd_lock_wait_toolong(call_single_data_t *csd, u64 ts0, u64 *ts1, in
*/
static void __csd_lock_wait(call_single_data_t *csd)
{
unsigned long nmessages = 0;
int bug_id = 0;
u64 ts0, ts1;
struct csd_wait_state state = {};
guard(preempt)();
ts1 = ts0 = ktime_get_mono_fast_ns();
state.ts_report = state.ts_start = ktime_get_mono_fast_ns();
for (;;) {
if (csd_lock_wait_toolong(csd, ts0, &ts1, &bug_id, &nmessages))
if (csd_lock_wait_toolong(csd, &state))
break;
cpu_relax();
}

12
lib/Kconfig.debug
View File

@ -1329,6 +1329,18 @@ config WQ_CPU_INTENSIVE_REPORT
triggering likely indicates that the work item should be switched
to use an unbound workqueue.
config TEST_CSD_LOCK
tristate "Test module to stall a CPU on a CSD lock"
depends on m
depends on CSD_LOCK_WAIT_DEBUG
help
This builds the "test_csd_lock" module, which keeps one CPU from
answering an IPI for as long as its stall_ms parameter says, so
that the CSD-lock debug code has a stall to report. It needs
csdlock_debug=1 to be of any use.
If unsure, say N.
config TEST_LOCKUP
tristate "Test module to generate lockups"
depends on m

1
lib/Makefile
View File

@ -100,6 +100,7 @@ obj-$(CONFIG_TEST_DEBUG_VIRTUAL) += test_debug_virtual.o
obj-$(CONFIG_TEST_MEMCAT_P) += test_memcat_p.o
obj-$(CONFIG_TEST_OBJAGG) += test_objagg.o
obj-$(CONFIG_TEST_MEMINIT) += test_meminit.o
obj-$(CONFIG_TEST_CSD_LOCK) += test_csd_lock.o
obj-$(CONFIG_TEST_LOCKUP) += test_lockup.o
obj-$(CONFIG_TEST_HMM) += test_hmm.o
obj-$(CONFIG_TEST_FREE_PAGES) += test_free_pages.o

173
lib/test_csd_lock.c Normal file
View File

@ -0,0 +1,173 @@
// SPDX-License-Identifier: GPL-2.0-only
/*
* Keep one CPU from answering an IPI, so that the CSD-lock debug code in
* kernel/smp.c has a stall to report.
*
* Copyright (c) 2026 Meta Platforms, Inc. and affiliates
* Copyright (c) 2026 Breno Leitao <leitao@debian.org>
*
* The target either spins with interrupts disabled, which leaves it idle as
* far as the debug code can tell and gets the IPI re-sent, or spins inside a
* CSD handler, which does not. The recovery message differs between the two.
*
* Loading the module runs one stall, then fails the load with -EAGAIN so
* that nothing is left loaded afterwards:
*
* echo 500 > /sys/module/smp/parameters/csd_lock_timeout
* modprobe test_csd_lock stall_ms=1000 in_handler=0
*
* csd_lock_timeout has to be below stall_ms for the stall to be reported at
* all, and the report has to come out before the CPU answers, so leave it
* some room.
*/
#define pr_fmt(fmt) KBUILD_MODNAME ": " fmt
#include <linux/completion.h>
#include <linux/cpu.h>
#include <linux/cpumask.h>
#include <linux/ktime.h>
#include <linux/module.h>
#include <linux/smp.h>
#include <linux/workqueue.h>
#define STALL_MS_MAX 10000
static unsigned int stall_ms = 1000;
module_param(stall_ms, uint, 0444);
MODULE_PARM_DESC(stall_ms, "Time the target CPU ignores the IPI, in milliseconds.");
static int stall_cpu = -1;
module_param(stall_cpu, int, 0444);
MODULE_PARM_DESC(stall_cpu, "CPU to stall, or -1 for the first online one.");
static bool in_handler;
module_param(in_handler, bool, 0444);
MODULE_PARM_DESC(in_handler, "Stall inside a CSD handler instead of with interrupts disabled.");
static int target_cpu;
static bool target_stalling;
static bool hog_launched;
static struct work_struct irqoff_work;
static struct work_struct sender_work;
static call_single_data_t hog_csd;
static DECLARE_COMPLETION(hog_done);
static void csd_test_nop(void *unused)
{
}
static void csd_test_spin(void)
{
u64 end = ktime_get_mono_fast_ns() + (u64)stall_ms * NSEC_PER_MSEC;
while (ktime_get_mono_fast_ns() < end)
cpu_relax();
}
/* Nothing is running for the target while interrupts are off, so it gets a new IPI. */
static void csd_test_irqoff_fn(struct work_struct *work)
{
local_irq_disable();
/* Pairs with the load in csd_test_sender_fn(), which waits for this. */
smp_store_release(&target_stalling, true);
csd_test_spin();
local_irq_enable();
}
/* Here cur_csd stays set on the target, which suppresses the re-send. */
static void csd_test_hog_fn(void *unused)
{
/* Pairs with the load in csd_test_sender_fn(), which waits for this. */
smp_store_release(&target_stalling, true);
csd_test_spin();
complete(&hog_done);
}
/*
* Start the stall from here rather than from module init, so that however
* long this work item waits to be scheduled comes off before the target
* stops answering, not out of the middle of the stall.
*/
static void csd_test_sender_fn(struct work_struct *work)
{
u64 deadline, ts;
int err;
if (in_handler) {
hog_csd.func = csd_test_hog_fn;
err = smp_call_function_single_async(target_cpu, &hog_csd);
if (err) {
pr_err("cannot queue the CSD handler on CPU%d: %d\n", target_cpu, err);
return;
}
} else {
queue_work_on(target_cpu, system_highpri_wq, &irqoff_work);
}
WRITE_ONCE(hog_launched, true);
deadline = ktime_get_mono_fast_ns() + (u64)STALL_MS_MAX * NSEC_PER_MSEC;
/* Pairs with the store in the stall functions: send once it is stuck. */
while (!smp_load_acquire(&target_stalling)) {
if (ktime_get_mono_fast_ns() > deadline) {
pr_err("CPU%d never stopped answering\n", target_cpu);
return;
}
cpu_relax();
}
ts = ktime_get_mono_fast_ns();
smp_call_function_single(target_cpu, csd_test_nop, NULL, 1);
pr_info("CPU%d answered after %llu ns\n", target_cpu,
ktime_get_mono_fast_ns() - ts);
}
static int __init test_csd_lock_init(void)
{
int sender_cpu;
int ret = 0;
if (!stall_ms || stall_ms > STALL_MS_MAX) {
pr_err("stall_ms must be between 1 and %d\n", STALL_MS_MAX);
return -EINVAL;
}
INIT_WORK(&irqoff_work, csd_test_irqoff_fn);
INIT_WORK(&sender_work, csd_test_sender_fn);
cpus_read_lock();
target_cpu = stall_cpu < 0 ? cpumask_first(cpu_online_mask) : stall_cpu;
sender_cpu = nr_cpu_ids;
if (target_cpu < nr_cpu_ids && cpu_online(target_cpu))
sender_cpu = cpumask_any_but(cpu_online_mask, target_cpu);
if (sender_cpu >= nr_cpu_ids) {
pr_err("need CPU%d and one other CPU online\n", target_cpu);
ret = -EINVAL;
goto unlock;
}
pr_info("stalling CPU%d for %u ms %s, IPI from CPU%d\n", target_cpu, stall_ms,
in_handler ? "inside a CSD handler" : "with interrupts disabled", sender_cpu);
queue_work_on(sender_cpu, system_highpri_wq, &sender_work);
flush_work(&sender_work);
flush_work(&irqoff_work);
/* The CSD has to be idle again before this module goes away. */
if (in_handler && READ_ONCE(hog_launched) &&
!wait_for_completion_timeout(&hog_done, msecs_to_jiffies(2 * STALL_MS_MAX)))
pr_err("CSD handler on CPU%d never finished\n", target_cpu);
/* The stall is over and there is nothing left to hold, so go away. */
ret = -EAGAIN;
unlock:
cpus_read_unlock();
return ret;
}
module_init(test_csd_lock_init);
MODULE_LICENSE("GPL");
MODULE_AUTHOR("Breno Leitao <leitao@debian.org>");
MODULE_DESCRIPTION("Test module to stall a CPU on a CSD lock");