[PATCH v2 0/3] locking/csd-lock: Report how long a CSD stall lasted

[PATCH v2 0/3] locking/csd-lock: Report how long a CSD stall lasted

[Breno Leitao]

The CSD lock debug code says when a CPU stops answering an IPI and when it
finally answers, but the recovery line leaves out how long the stall
lasted, even though csd_lock_wait_toolong() has the timestamp the wait
started from.  On Meta's fleet that line fired 211K times in the last 24
hours, none of them with a duration.

Patch 1 packs the state that csd_lock_wait_toolong() carries across the
polling loop into a struct, as suggested on v1, which gives the timestamps
names and leaves room for another one.  Patch 2 prints how long the lock
was stuck and, when the IPI was re-sent, how long after the last re-send
the target released it.

I've created a simple selftest to test both patches, and I am including
it here, given it might be helpful for whoever is hacking this code.

---
Changes in v2:
- Add patch 1, packing csd_lock_wait_toolong() state into a struct, as
  suggested by Dmitry Ilvokhin.
- Add patch 3, a module that stalls a CPU so the reporting can be exercised.
- Link to v1: https://patch.msgid.link/20260805-csd-stall-duration-v1-1-71134fafe150@debian.org

---
Breno Leitao (3):
      locking/csd-lock: Pack csd_lock_wait_toolong() state into a struct
      locking/csd-lock: Report how long a stuck CSD lock took to recover
      lib/test_csd_lock: Add a module to stall a CPU on a CSD lock

 kernel/smp.c        |  77 +++++++++++++++--------
 lib/Kconfig.debug   |  12 ++++
 lib/Makefile        |   1 +
 lib/test_csd_lock.c | 173 ++++++++++++++++++++++++++++++++++++++++++++++++++++
 4 files changed, 237 insertions(+), 26 deletions(-)
---
base-commit: f9a2394a23482bfd330911e9c8295b71724feacd
change-id: 20260805-csd-stall-duration-3385343d7a08

Best regards,
--  
Breno Leitao <leitao@debian.org>

[PATCH v2 1/3] locking/csd-lock: Pack csd_lock_wait_toolong() state into a struct

[Breno Leitao]

csd_lock_wait_toolong() has some fields and they are being expanded now,
separate them into a structure, that can be easily digestible.

This simplify the function aslo, given the fields were passed by
reference, and the ts0/ts1 names say nothing about what the two
timestamps hold.

Pack them into struct csd_wait_state and name the timestamps for what
they store, ts_start and ts_report.  The local ts2 becomes ts_now.

Reporting a further timestamp, such as next patch, then costs a struct
member rather than another argument.

No functional change.

Suggested-by: Dmitry Ilvokhin <d@ilvokhin.com>
Signed-off-by: Breno Leitao <leitao@debian.org>
---
 kernel/smp.c | 56 +++++++++++++++++++++++++++++++-------------------------
 1 file changed, 31 insertions(+), 25 deletions(-)

diff --git a/kernel/smp.c b/kernel/smp.c
index 52dffc86555cd..e00b8f620c5d9 100644
--- a/kernel/smp.c
+++ b/kernel/smp.c
@@ -223,50 +223,58 @@ 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. */
+	int bug_id;
+	unsigned long nmessages;
+};
+
 /*
  * 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;
 		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);
+			 state->bug_id, raw_smp_processor_id(), cpu);
 		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;
@@ -274,11 +282,11 @@ static bool csd_lock_wait_toolong(call_single_data_t *csd, u64 ts0, u64 *ts1, in
 		cpux = cpu;
 	cpu_cur_csd = smp_load_acquire(&per_cpu(cur_csd, cpux)); /* Before func and info. */
 	/* 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);
 	/*
@@ -289,23 +297,23 @@ 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);
 		}
 	}
 	if (firsttime)
 		dump_stack();
-	*ts1 = ts2;
+	state->ts_report = ts_now;
 
 	return false;
 }
@@ -319,13 +327,11 @@ 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 = {};
 
-	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();
 	}

-- 
2.53.0-Meta

Re: [PATCH v2 1/3] locking/csd-lock: Pack csd_lock_wait_toolong() state into a struct

[Dmitry Ilvokhin]

On Mon, Aug 10, 2026 at 04:29:24AM -0700, Breno Leitao wrote:
> csd_lock_wait_toolong() has some fields and they are being expanded now,
> separate them into a structure, that can be easily digestible.
> 
> This simplify the function aslo, given the fields were passed by
> reference, and the ts0/ts1 names say nothing about what the two
> timestamps hold.
> 
> Pack them into struct csd_wait_state and name the timestamps for what
> they store, ts_start and ts_report.  The local ts2 becomes ts_now.
> 
> Reporting a further timestamp, such as next patch, then costs a struct
> member rather than another argument.
> 
> No functional change.
> 
> Suggested-by: Dmitry Ilvokhin <d@ilvokhin.com>
> Signed-off-by: Breno Leitao <leitao@debian.org>

Reviewed-by: Dmitry Ilvokhin <d@ilvokhin.com>

[PATCH v2 2/3] locking/csd-lock: Report how long a stuck CSD lock took to recover

[Breno Leitao]

The CSD lock debug output is a useful way to catch IPI stalls, but when
the lock finally recovers it only says that it did:

  smp: csd: CSD lock (#1) got unstuck on CPU#32, CPU#123 released the lock.

How long the target took to answer is left out, even though
csd_lock_wait_toolong() already has the timestamp the wait started from.

At Meta's fleet, that line fired 211K times in the last 24 hours, so
plenty of stalls get reported with no indication of how long they
lasted.

Print how long the lock was stuck, and, when an IPI was re-sent, how
long after that re-send the target released, as:

  smp: csd: CSD lock (#1) got unstuck on CPU#00, CPU#01 released the lock after 8000854660 ns, 3000825778 ns after the last IPI re-send.

Signed-off-by: Breno Leitao <leitao@debian.org>
Reviewed-by: Dmitry Ilvokhin <d@ilvokhin.com>
---
 kernel/smp.c | 23 +++++++++++++++++++++--
 1 file changed, 21 insertions(+), 2 deletions(-)

diff --git a/kernel/smp.c b/kernel/smp.c
index e00b8f620c5d9..c7475b3deb574 100644
--- a/kernel/smp.c
+++ b/kernel/smp.c
@@ -227,10 +227,28 @@ bool csd_lock_is_stuck(void)
 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,
@@ -249,9 +267,9 @@ static bool csd_lock_wait_toolong(call_single_data_t *csd, struct csd_wait_state
 	if (!(flags & CSD_FLAG_LOCK)) {
 		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",
-			 state->bug_id, raw_smp_processor_id(), cpu);
+		csd_lock_print_unstuck(state, cpu, ts_now);
 		atomic_dec(&n_csd_lock_stuck);
 		return true;
 	}
@@ -309,6 +327,7 @@ static bool csd_lock_wait_toolong(call_single_data_t *csd, struct csd_wait_state
 		if (!cpu_cur_csd) {
 			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)

-- 
2.53.0-Meta

[PATCH v2 3/3] lib/test_csd_lock: Add a module to stall a CPU on a CSD lock

[Breno Leitao]

Add test_csd_lock, a module that 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.  With in_handler=1 the CPU stalls inside a CSD
handler instead, which is the case where the IPI is not re-sent.

The module needs CONFIG_CSD_LOCK_WAIT_DEBUG and csdlock_debug=1.  Loading
it runs one stall and then fails the load with -EAGAIN, the way
test_lockup does, so that nothing is left loaded afterwards.

Signed-off-by: Breno Leitao <leitao@debian.org>
---
 lib/Kconfig.debug   |  12 ++++
 lib/Makefile        |   1 +
 lib/test_csd_lock.c | 173 ++++++++++++++++++++++++++++++++++++++++++++++++++++
 3 files changed, 186 insertions(+)

diff --git a/lib/Kconfig.debug b/lib/Kconfig.debug
index 1244dcac2294a..d693caaeae873 100644
--- a/lib/Kconfig.debug
+++ b/lib/Kconfig.debug
@@ -1372,6 +1372,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
diff --git a/lib/Makefile b/lib/Makefile
index 7f75cc6edf94a..92f0ab7b740b4 100644
--- a/lib/Makefile
+++ b/lib/Makefile
@@ -99,6 +99,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
diff --git a/lib/test_csd_lock.c b/lib/test_csd_lock.c
new file mode 100644
index 0000000000000..30c6c3332c3fc
--- /dev/null
+++ b/lib/test_csd_lock.c
@@ -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");

-- 
2.53.0-Meta

Re: [PATCH v2 0/3] locking/csd-lock: Report how long a CSD stall lasted

[Paul E. McKenney]

On Mon, Aug 10, 2026 at 04:29:23AM -0700, Breno Leitao wrote:
> The CSD lock debug code says when a CPU stops answering an IPI and when it
> finally answers, but the recovery line leaves out how long the stall
> lasted, even though csd_lock_wait_toolong() has the timestamp the wait
> started from.  On Meta's fleet that line fired 211K times in the last 24
> hours, none of them with a duration.
> 
> Patch 1 packs the state that csd_lock_wait_toolong() carries across the
> polling loop into a struct, as suggested on v1, which gives the timestamps
> names and leaves room for another one.  Patch 2 prints how long the lock
> was stuck and, when the IPI was re-sent, how long after the last re-send
> the target released it.
> 
> I've created a simple selftest to test both patches, and I am including
> it here, given it might be helpful for whoever is hacking this code.

Queued for testing.  If you would like to send this up some other path:

Acked-by: Paul E. McKenney <paulmck@kernel.org>

> ---
> Changes in v2:
> - Add patch 1, packing csd_lock_wait_toolong() state into a struct, as
>   suggested by Dmitry Ilvokhin.
> - Add patch 3, a module that stalls a CPU so the reporting can be exercised.
> - Link to v1: https://patch.msgid.link/20260805-csd-stall-duration-v1-1-71134fafe150@debian.org
> 
> ---
> Breno Leitao (3):
>       locking/csd-lock: Pack csd_lock_wait_toolong() state into a struct
>       locking/csd-lock: Report how long a stuck CSD lock took to recover
>       lib/test_csd_lock: Add a module to stall a CPU on a CSD lock
> 
>  kernel/smp.c        |  77 +++++++++++++++--------
>  lib/Kconfig.debug   |  12 ++++
>  lib/Makefile        |   1 +
>  lib/test_csd_lock.c | 173 ++++++++++++++++++++++++++++++++++++++++++++++++++++
>  4 files changed, 237 insertions(+), 26 deletions(-)
> ---
> base-commit: f9a2394a23482bfd330911e9c8295b71724feacd
> change-id: 20260805-csd-stall-duration-3385343d7a08
> 
> Best regards,
> --  
> Breno Leitao <leitao@debian.org>
>