From nobody Tue Sep 29 09:08:36 2026 Received: from stravinsky.debian.org (stravinsky.debian.org [82.195.75.108]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by smtp.subspace.kernel.org (Postfix) with ESMTPS id 9C8953C197E for ; Mon, 10 Aug 2026 11:31:17 +0000 (UTC) Authentication-Results: smtp.subspace.kernel.org; arc=none smtp.client-ip=82.195.75.108 ARC-Seal: i=1; a=rsa-sha256; d=subspace.kernel.org; s=arc-20240116; t=1786361479; cv=none; b=RY3TbVqWztzOo6RPFgzsqNZBgCwJKJWSL4sD6xV25am0IBt8CXoRhSBkBSRuGX+9q45O7dzxUzQUO9EfZy9ZZpNA+41cp3VXMdE/jBFh9eGmU/+eqkemxCpaiLHORaJt5DfLuMczIvmGNiuUQMpUvuEXC03S5pmFk1ng364ymHM= ARC-Message-Signature: i=1; a=rsa-sha256; d=subspace.kernel.org; s=arc-20240116; t=1786361479; c=relaxed/simple; bh=ZLFHzsTzu0vgm8YRib6oX/5dJRrmsdclFpM3jyMEPwE=; h=From:Date:Subject:MIME-Version:Content-Type:Message-Id:References: In-Reply-To:To:Cc; b=Kwmd3JgOT1o8PT6z2L/Cbxn60wDXtbDKeLQcW5Psb0YV8pyTg4RX9P8dg6fKeCQQT2Ry5e+VpyoNTT+Ydhc3qjsALbviAODo23y/QKGpCsh09gTHeHNLj528GvdgJpVVr/QenR46CAP1TZb6fqRMiugceBee9qDlFrYQ4IZ3gtA= ARC-Authentication-Results: i=1; smtp.subspace.kernel.org; dmarc=pass (p=none dis=none) header.from=debian.org; spf=pass smtp.mailfrom=debian.org; dkim=pass (2048-bit key) header.d=debian.org header.i=@debian.org header.b=RYlPkncc; arc=none smtp.client-ip=82.195.75.108 Authentication-Results: smtp.subspace.kernel.org; dmarc=pass (p=none dis=none) header.from=debian.org Authentication-Results: smtp.subspace.kernel.org; spf=pass smtp.mailfrom=debian.org Authentication-Results: smtp.subspace.kernel.org; dkim=pass (2048-bit key) header.d=debian.org header.i=@debian.org header.b="RYlPkncc" DKIM-Signature: v=1; a=rsa-sha256; q=dns/txt; c=relaxed/relaxed; d=debian.org; s=smtpauto.stravinsky; h=X-Debian-User:Cc:To:In-Reply-To:References: Message-Id:Content-Transfer-Encoding:Content-Type:MIME-Version:Subject:Date: From:Reply-To:Content-ID:Content-Description; bh=H+dKeUvpI1Nc29+6fm2OUGnH7BUfm7XFw0QlxPVxFpc=; b=RYlPknccucYC579350n+kZTGy6 8pKpZph4KoE2n98uNeXKR6mfYbgf/Xs0n2Qwka+psJE7h8hlnogG7rPhGWk4nm42LoPIOdr+wDVFT UpSff/1Q272mpY37Af6OqB2vm3YbzezPbSzeuuatDNS/dAPdUaEH5EfCOKqhQNQzoC/6Eivkpwh+k 9w9w3rPxH3G0X/2Dm+ur7F5+US9H0xKi2DEr4C5ZoQ5+C1FyxdQuL/wSl51dp1/2dh+lWV6v7oZy6 SyTjCBhwJiHKkS7NBdyzyrPQTErCccFvf6THok+tkPzrVKU6rF1z2syLNYK6oSy2Gom9AZwhm/m9P q0BiiIpw==; Received: from authenticated-user by stravinsky.debian.org with esmtpsa (TLS1.3:ECDHE_X25519__RSA_PSS_RSAE_SHA256__AES_256_GCM:256) (Exim 4.96) (envelope-from ) id 1wtODo-002iey-1k; Mon, 10 Aug 2026 11:31:13 +0000 From: Breno Leitao Date: Mon, 10 Aug 2026 04:29:24 -0700 Subject: [PATCH v2 1/3] locking/csd-lock: Pack csd_lock_wait_toolong() state into a struct Precedence: bulk X-Mailing-List: linux-kernel@vger.kernel.org List-Id: List-Subscribe: List-Unsubscribe: MIME-Version: 1.0 Content-Type: text/plain; charset="utf-8" Content-Transfer-Encoding: quoted-printable Message-Id: <20260810-csd-stall-duration-v2-1-795083bf04a4@debian.org> References: <20260810-csd-stall-duration-v2-0-795083bf04a4@debian.org> In-Reply-To: <20260810-csd-stall-duration-v2-0-795083bf04a4@debian.org> To: paulmck@kernel.org, Andrew Morton , d@ilvokhin.com Cc: linux-kernel@vger.kernel.org, Peter Zijlstra , Ingo Molnar , Sebastian Andrzej Siewior , linux-kernel@vger.kernel.org, kernel-team@meta.com, Thomas Gleixner , Breno Leitao X-Mailer: b4 0.16-dev-f8e9d X-Developer-Signature: v=1; a=openpgp-sha256; l=6140; i=leitao@debian.org; h=from:subject:message-id; bh=ZLFHzsTzu0vgm8YRib6oX/5dJRrmsdclFpM3jyMEPwE=; b=owEBbQKS/ZANAwAIATWjk5/8eHdtAcsmYgBqebZxtjjFaEdmihQkr2b6XVVrWLDmlJI8ssC7f WhTUvAArTKJAjMEAAEIAB0WIQSshTmm6PRnAspKQ5s1o5Of/Hh3bQUCanm2cQAKCRA1o5Of/Hh3 bQ0bD/0fgZrOZ0dJw5IqCjQbYyFtgYxeduecvCnI9zzQf4EgJ6TUSZCtfODKg7vdQe20jROZ6pS cz1WNYZLef5iRH+SrbeNi1/bAlYli3VAREYyU1THUo+LrSVm4/Kb4Ms2hvJFq0H2V2CWLp/QC25 RHB1EHAuGUmOAIsQ7ic3XcPPce39hGGwytnJ/WmKww18BFrzmzPf7TgvmE0NIA49zkzSph85ZUX MWG2Y/VPDmv6Vs+gNpceczpjVYB2580tGAlCA8SfaOkpY8VuRAe/2WIWDGJQ+y9dYCPnigN8ba/ UBWtGDHT7DVq2fGZSEeJzxclTl7ZzCdZ23hmkj0a0Fm5cWAGYOoM6YM6NdTgy6Gq2kTq1hpuA3T SCgBt3vceLe5IlYsjtRda35Fc8YA4tHOvPfZ3yphDLnWtxICg2qsQFIRaOj9wO4XUC8nMV7B74c 2GYJze11XnBTgqfzHTUfJ92XyMXkNCHU0XzJO9iED9GMfTOVB4M+gvMyTKU3AuLtDj0hWTNqwNC pO5pvMHkzG0+SUjqmlFzo5CKJkTrh9wO8DtjrI0LxF/AGOkQHwhhWoH3n2AHTmmvH7sfztJCgci S9lPEeBK7ITrWW6StwEiKSbYb53xyQX8UZBFU7bB3dHPW7l/G6h+nLcNhiZwwv71NTxwApsN5yh 9A/xaNF45VRaoig== X-Developer-Key: i=leitao@debian.org; a=openpgp; fpr=AC8539A6E8F46702CA4A439B35A3939FFC78776D X-Debian-User: 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 Signed-off-by: Breno Leitao Acked-by: Paul E. McKenney Reviewed-by: Dmitry Ilvokhin --- 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); } =20 +/* 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 *t= s1, int *bug_id, unsigned long *nmessages) +static bool csd_lock_wait_toolong(call_single_data_t *csd, struct csd_wait= _state *state) { int cpu =3D -1; int cpux; bool firsttime; - u64 ts2, ts_delta; + u64 ts_now, ts_delta; call_single_data_t *cpu_cur_csd; unsigned int flags =3D READ_ONCE(csd->node.u_flags); unsigned long long csd_lock_timeout_ns =3D csd_lock_timeout * NSEC_PER_MS= EC; =20 if (!(flags & CSD_FLAG_LOCK)) { - if (!unlikely(*bug_id)) + if (!unlikely(state->bug_id)) return true; cpu =3D 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; } =20 - ts2 =3D ktime_get_mono_fast_ns(); + ts_now =3D ktime_get_mono_fast_ns(); /* How long since we last checked for a stuck CSD lock.*/ - ts_delta =3D ts2 - *ts1; - if (likely(ts_delta <=3D csd_lock_timeout_ns * (*nmessages + 1) * - (!*nmessages ? 1 : (ilog2(num_online_cpus()) / 2 + 1)) || + ts_delta =3D ts_now - state->ts_report; + if (likely(ts_delta <=3D csd_lock_timeout_ns * (state->nmessages + 1) * + (!state->nmessages ? 1 : (ilog2(num_online_cpus()) / 2 + 1)) || csd_lock_timeout_ns =3D=3D 0)) return false; =20 - if (ts0 > ts2) { + if (state->ts_start > ts_now) { /* Our own sched_clock went backward; don't blame another CPU. */ - ts_delta =3D ts0 - ts2; + ts_delta =3D state->ts_start - ts_now; pr_alert("sched_clock on CPU %d went backward by %llu ns\n", raw_smp_pro= cessor_id(), ts_delta); - *ts1 =3D ts2; + state->ts_report =3D ts_now; return false; } =20 - firsttime =3D !*bug_id; + firsttime =3D !state->bug_id; if (firsttime) - *bug_id =3D atomic_inc_return(&csd_bug_count); + state->bug_id =3D atomic_inc_return(&csd_bug_count); cpu =3D csd_lock_wait_getcpu(csd); if (WARN_ONCE(cpu < 0 || cpu >=3D nr_cpu_ids, "%s: cpu =3D %d\n", __func_= _, cpu)) cpux =3D 0; @@ -274,11 +282,11 @@ static bool csd_lock_wait_toolong(call_single_data_t = *csd, u64 ts0, u64 *ts1, in cpux =3D cpu; cpu_cur_csd =3D smp_load_acquire(&per_cpu(cur_csd, cpux)); /* Before func= and info. */ /* How long since this CSD lock was stuck. */ - ts_delta =3D ts2 - ts0; + ts_delta =3D ts_now - state->ts_start; pr_alert("csd: %s non-responsive CSD lock (#%d) on CPU#%d, waiting %lld n= s 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 !=3D 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 >=3D 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 =3D ts2; + state->ts_report =3D ts_now; =20 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 =3D 0; - int bug_id =3D 0; - u64 ts0, ts1; + struct csd_wait_state state =3D {}; =20 - ts1 =3D ts0 =3D ktime_get_mono_fast_ns(); + state.ts_report =3D state.ts_start =3D 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(); } --=20 2.53.0-Meta From nobody Tue Sep 29 09:08:36 2026 Received: from stravinsky.debian.org (stravinsky.debian.org [82.195.75.108]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by smtp.subspace.kernel.org (Postfix) with ESMTPS id 2188D3C197E for ; Mon, 10 Aug 2026 11:31:23 +0000 (UTC) Authentication-Results: smtp.subspace.kernel.org; arc=none smtp.client-ip=82.195.75.108 ARC-Seal: i=1; a=rsa-sha256; d=subspace.kernel.org; s=arc-20240116; t=1786361485; cv=none; b=s+gI2FMYMAM1PrC9pkTMrkB7M7/v0H+wb4WLjg5SO+AUKcdBrG5jq0wW5ntYhK+Uosqfk9TyEIeoOApgpQEG8ZQqX3Sw67DCXsCN4WcMUxcscMzlhBd6KDBIHmmatfGM1/JKtBXwPSOcjPdv5ID4jB2X/KCjynn5Yz8ouJv1rGU= ARC-Message-Signature: i=1; a=rsa-sha256; d=subspace.kernel.org; s=arc-20240116; t=1786361485; c=relaxed/simple; bh=UBzg63/2N1mzgAab5bdr1tIaH6KgwUvGi23oBtwkdm0=; h=From:Date:Subject:MIME-Version:Content-Type:Message-Id:References: In-Reply-To:To:Cc; b=tk6XUB9gcJhFSe0OpidV2fnRRZuWiqtj3/iikeiZkC5/5kj7fnd5e9DJ7j7FNmW8hQTResyKWcJ39fi1U/RsTfvF0ANq/N56+8+cfJ83RPjMMTdp8jzIMBIWdCTSmcVpl2Rdjqi5HyWTuH53RsewJugv4LthWySu7NarltO5vps= ARC-Authentication-Results: i=1; smtp.subspace.kernel.org; dmarc=pass (p=none dis=none) header.from=debian.org; spf=pass smtp.mailfrom=debian.org; dkim=pass (2048-bit key) header.d=debian.org header.i=@debian.org header.b=I6pPP8b+; arc=none smtp.client-ip=82.195.75.108 Authentication-Results: smtp.subspace.kernel.org; dmarc=pass (p=none dis=none) header.from=debian.org Authentication-Results: smtp.subspace.kernel.org; spf=pass smtp.mailfrom=debian.org Authentication-Results: smtp.subspace.kernel.org; dkim=pass (2048-bit key) header.d=debian.org header.i=@debian.org header.b="I6pPP8b+" DKIM-Signature: v=1; a=rsa-sha256; q=dns/txt; c=relaxed/relaxed; d=debian.org; s=smtpauto.stravinsky; h=X-Debian-User:Cc:To:In-Reply-To:References: Message-Id:Content-Transfer-Encoding:Content-Type:MIME-Version:Subject:Date: From:Reply-To:Content-ID:Content-Description; bh=MN0xfPztgxg2Gg0bh5XmoEswYR1K6oRv9+HujuAICEQ=; b=I6pPP8b+6Ttki9WFSxb5ruvGui GoSlv/EzIkKWhF6ZkLaw16UwtaMG2yf6TfKrBjJoHobKZNoNx3MtNmYbFoM4Jmurid6kXY4QI+qba 0MI2YexxP6Eo1PTPXlKPYDSUqUBgsZtwmceQ/HhocTzaqJHx6mNqlBg43VCy3Vg4pc9Q1JaMa3McR r4HCLHmcntJxQmLVwfy0qq+YQGcgMn3C9jYzaLKdPlRfG4ZlttC7qofoMNg24+syP7DO4pxZXfvdo v93ljyg8msVPnxzeCouRNtVwMT8/tOsOTqNNwcb2StqdzvegWoQtE7AFa2/zVvB3VXDqLeEqEJRDE rJwE2zxg==; Received: from authenticated-user by stravinsky.debian.org with esmtpsa (TLS1.3:ECDHE_X25519__RSA_PSS_RSAE_SHA256__AES_256_GCM:256) (Exim 4.96) (envelope-from ) id 1wtODu-002if7-2Q; Mon, 10 Aug 2026 11:31:19 +0000 From: Breno Leitao Date: Mon, 10 Aug 2026 04:29:25 -0700 Subject: [PATCH v2 2/3] locking/csd-lock: Report how long a stuck CSD lock took to recover Precedence: bulk X-Mailing-List: linux-kernel@vger.kernel.org List-Id: List-Subscribe: List-Unsubscribe: MIME-Version: 1.0 Content-Type: text/plain; charset="utf-8" Content-Transfer-Encoding: quoted-printable Message-Id: <20260810-csd-stall-duration-v2-2-795083bf04a4@debian.org> References: <20260810-csd-stall-duration-v2-0-795083bf04a4@debian.org> In-Reply-To: <20260810-csd-stall-duration-v2-0-795083bf04a4@debian.org> To: paulmck@kernel.org, Andrew Morton , d@ilvokhin.com Cc: linux-kernel@vger.kernel.org, Peter Zijlstra , Ingo Molnar , Sebastian Andrzej Siewior , linux-kernel@vger.kernel.org, kernel-team@meta.com, Thomas Gleixner , Breno Leitao X-Mailer: b4 0.16-dev-f8e9d X-Developer-Signature: v=1; a=openpgp-sha256; l=3201; i=leitao@debian.org; h=from:subject:message-id; bh=UBzg63/2N1mzgAab5bdr1tIaH6KgwUvGi23oBtwkdm0=; b=owEBbQKS/ZANAwAIATWjk5/8eHdtAcsmYgBqebZxd57YC56uaNF9o1WtmoW433JIa6e3w0Avx cui/UGcSReJAjMEAAEIAB0WIQSshTmm6PRnAspKQ5s1o5Of/Hh3bQUCanm2cQAKCRA1o5Of/Hh3 bUybD/0a02ZFS/PrXL5vGteXO+ZYt0pJer7dpgF1A8Arid4iXUopKZdQENG2FTnlPOiDCbQqM90 Q5WQWHcRymGwyDwp9oVVj0Bu/1osGfmRE0ejMLN8BBd5Pd66bfTyC5WYlupd0iT+Pty1WJwvmNq hPWyVEis+mLVSOm82gIrII22jDA+15JofYF+vkiSy7hZyul8emM1ktlhmmVeDewozHLBSfvYsI4 mJDrHYdSg7fGyIUhVSaCAwcdxXhrHSfZRI+OHR7ZvyTmTv4ZJh9KQgoYXAlG8mj+wo0vVXZY/jl H4cyUiW+eep0ijlwRfpRi6WKL5JCoh/0QwaJd2wT3+puwyaQUoPPcgZLR2UoJBwB7OKI1Q87xIa qtCWhdYLM7xakX+R69DrulcozuKhDhkpVkmWA0geIe4QL+uP6D3LoSber8mJbrCnaOKH3rSjuGh dYEloj34byOilDRj8W5BtLIW1ByKLduKSWCB3d3fQyYCWuEOdvzQyk61GHpZnlEkPCw3QE74gua AF75HMBpAHD4K6GA7bQN5aUnvVJlQVagRu2VIG4+1ylPU80afihZOEMBbIrkhRJgBnjm2lgxgVa VUvB0s2OcqkyCndAPV408O/ofiWx8Z483Lae6hdCf85rkViB9RK1fZCvspua2W7z0qxughDCLDA wEtjaasYyAv7BTA== X-Developer-Key: i=leitao@debian.org; a=openpgp; fpr=AC8539A6E8F46702CA4A439B35A3939FFC78776D X-Debian-User: 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 a= fter 8000854660 ns, 3000825778 ns after the last IPI re-send. Signed-off-by: Breno Leitao Reviewed-by: Dmitry Ilvokhin Acked-by: Paul E. McKenney --- 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; }; =20 +/* + * 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 *c= sd, struct csd_wait_state if (!(flags & CSD_FLAG_LOCK)) { if (!unlikely(state->bug_id)) return true; + ts_now =3D ktime_get_mono_fast_ns(); cpu =3D 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 *c= sd, 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 =3D ktime_get_mono_fast_ns(); } } if (firsttime) --=20 2.53.0-Meta From nobody Tue Sep 29 09:08:36 2026 Received: from stravinsky.debian.org (stravinsky.debian.org [82.195.75.108]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by smtp.subspace.kernel.org (Postfix) with ESMTPS id 20A723C1D6E for ; Mon, 10 Aug 2026 11:31:30 +0000 (UTC) Authentication-Results: smtp.subspace.kernel.org; arc=none smtp.client-ip=82.195.75.108 ARC-Seal: i=1; a=rsa-sha256; d=subspace.kernel.org; s=arc-20240116; t=1786361492; cv=none; b=Ww8bKSqXucALZ75IeYdX6wYFoWX8FQsTkqnYvnl5IBg0VdFXUNHAqjnQPL8sWrywIRfqcys3NpzGQFUgfM1OQYrt54ajaZR5N9gv5YwkclQr0p2gtGY/JDJloPs0g7C8dhMTGqBv/13jZbxSf2efNgUZXJcwqNQC85Tr+aOEXZA= ARC-Message-Signature: i=1; a=rsa-sha256; d=subspace.kernel.org; s=arc-20240116; t=1786361492; c=relaxed/simple; bh=oBQO/paOC3jfNxmP9QwllDlFbaL1M6c2lFtXhCl5NWE=; h=From:Date:Subject:MIME-Version:Content-Type:Message-Id:References: In-Reply-To:To:Cc; b=L7piFTfuRVAA8+nIGG+BRnCFjMX67cLoCS712aSX8sn0m5hzTUjoM+M7QVxmv3FhOaJ8SbePV/7q6y8rYThQPxcy2OaSAZzrZGmwEtvOQ3O8e+bjA27to0GnJH9zJwKdEQ1erfE4XLPEwQCSq0bD+K6pgU0e/rfe6EPH/raPSVI= ARC-Authentication-Results: i=1; smtp.subspace.kernel.org; dmarc=pass (p=none dis=none) header.from=debian.org; spf=pass smtp.mailfrom=debian.org; dkim=pass (2048-bit key) header.d=debian.org header.i=@debian.org header.b=NWvzi6sA; arc=none smtp.client-ip=82.195.75.108 Authentication-Results: smtp.subspace.kernel.org; dmarc=pass (p=none dis=none) header.from=debian.org Authentication-Results: smtp.subspace.kernel.org; spf=pass smtp.mailfrom=debian.org Authentication-Results: smtp.subspace.kernel.org; dkim=pass (2048-bit key) header.d=debian.org header.i=@debian.org header.b="NWvzi6sA" DKIM-Signature: v=1; a=rsa-sha256; q=dns/txt; c=relaxed/relaxed; d=debian.org; s=smtpauto.stravinsky; h=X-Debian-User:Cc:To:In-Reply-To:References: Message-Id:Content-Transfer-Encoding:Content-Type:MIME-Version:Subject:Date: From:Reply-To:Content-ID:Content-Description; bh=zGnUzUyt/C6WSaBd30rtxolkfTV1jDrlJuBWJFZGKvA=; b=NWvzi6sArpfv/oVjTlWzn9Ufh0 A3E8VQEono3pO/7ZKNo3EgFx+hqKptBx6n5sSBWUS0ZmzKvNBg6ig/49ijYz2tDHX9IcEMHSu9IPQ A59qBgcs4jRFv3FaZVgCe4suVVkOLO9J5yX3M0rVwLaRD3MRAekZ0U90ENr5SNFNkg9hxsiYXXzds GXdNHk6opcAmCjs7syypvfjjfDw34l1CcOcuaIgEQR5Y59vteWPtyRRh0fduKohMl7Fch7REPvOMF 2QU9UPboOZz39XT01o6vMXxuFm2rxm040mvTLqRk3iNA+VckE5tYC4nBQC478PxRkYyIqog5COgps RFgLYnig==; Received: from authenticated-user by stravinsky.debian.org with esmtpsa (TLS1.3:ECDHE_X25519__RSA_PSS_RSAE_SHA256__AES_256_GCM:256) (Exim 4.96) (envelope-from ) id 1wtOE2-002ifb-0Y; Mon, 10 Aug 2026 11:31:27 +0000 From: Breno Leitao Date: Mon, 10 Aug 2026 04:29:26 -0700 Subject: [PATCH v2 3/3] lib/test_csd_lock: Add a module to stall a CPU on a CSD lock Precedence: bulk X-Mailing-List: linux-kernel@vger.kernel.org List-Id: List-Subscribe: List-Unsubscribe: MIME-Version: 1.0 Content-Type: text/plain; charset="utf-8" Content-Transfer-Encoding: quoted-printable Message-Id: <20260810-csd-stall-duration-v2-3-795083bf04a4@debian.org> References: <20260810-csd-stall-duration-v2-0-795083bf04a4@debian.org> In-Reply-To: <20260810-csd-stall-duration-v2-0-795083bf04a4@debian.org> To: paulmck@kernel.org, Andrew Morton , d@ilvokhin.com Cc: linux-kernel@vger.kernel.org, Peter Zijlstra , Ingo Molnar , Sebastian Andrzej Siewior , linux-kernel@vger.kernel.org, kernel-team@meta.com, Thomas Gleixner , Breno Leitao X-Mailer: b4 0.16-dev-f8e9d X-Developer-Signature: v=1; a=openpgp-sha256; l=7932; i=leitao@debian.org; h=from:subject:message-id; bh=oBQO/paOC3jfNxmP9QwllDlFbaL1M6c2lFtXhCl5NWE=; b=owEBbQKS/ZANAwAIATWjk5/8eHdtAcsmYgBqebZxdYDV1OyZZxOFaMpvBwHLh8MbbQoPZgFXc e9jgbg3WESJAjMEAAEIAB0WIQSshTmm6PRnAspKQ5s1o5Of/Hh3bQUCanm2cQAKCRA1o5Of/Hh3 bRH5D/9w0Ff1vB7zY5cgtI8g/rS0+rEAmvDR8bhil1OFCAPJ1s0X1Ppr5xhbUQmm1x+lL2NZzXi spOxJUqYG6PIXojEnjJmLZIDriCt+ZmiD9lcrCuS053p21lIaZvfVUCa0ip3us588lGP5bdrcOA XCmZuC3+tGIbVGAt0w73U8iVjf/E3JXHA+tFVQt20OpLh+8TH2+bEPvDqnAsNDnIdy6/hiyo8DM 6zYCHdDPQId4CPrHoFy4KK3L/dg38LRP+L2FKhmVxfat6THdkCEw+5idbYUtBAZ/O3dhQUAxeev DpyVeI0Dr0yUutlYTu0p1o+ICQ38QuG/s4TNsl+DpUoctfu1L8wtpE583cTE59JKGrtDl0gPVbY vMHxSM2tMKWOw4mAB3dw8no5Up10f31jj3VIxrwWqtswdcNqdxWWhDyqCgsnNczyqhB6Ey/LFAm hJQA0mT2JgTcLe6xclIPD9AxIRuaOXsd8QE+sYV6/Vbqt0W+BXrbi6ZIKTKFkYijJA2j16C99mq 0zncwnYpGHcdkMG+hEG/QKZpWs/bw67OZeRg/6iVabyveyBMw+8o9BkT0ZSYufqkqZp6W2wuBTi 3XQxYgTrFLpprT8Mhtu7vkyJkGSU59an/IBmxNO1ONssXFWhQZTXt78em4qK65cppe4+xfE2cNx HV8CTeXFC0mj0zQ== X-Developer-Key: i=leitao@debian.org; a=openpgp; fpr=AC8539A6E8F46702CA4A439B35A3939FFC78776D X-Debian-User: 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=3D1 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=3D1. 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 Acked-by: Paul E. McKenney --- 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. =20 +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=3D1 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) +=3D test_debug_virtual.o obj-$(CONFIG_TEST_MEMCAT_P) +=3D test_memcat_p.o obj-$(CONFIG_TEST_OBJAGG) +=3D test_objagg.o obj-$(CONFIG_TEST_MEMINIT) +=3D test_meminit.o +obj-$(CONFIG_TEST_CSD_LOCK) +=3D test_csd_lock.o obj-$(CONFIG_TEST_LOCKUP) +=3D test_lockup.o obj-$(CONFIG_TEST_HMM) +=3D test_hmm.o obj-$(CONFIG_TEST_FREE_PAGES) +=3D 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 + * + * 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 insid= e 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=3D1000 in_handler=3D0 + * + * 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 +#include +#include +#include +#include +#include +#include + +#define STALL_MS_MAX 10000 + +static unsigned int stall_ms =3D 1000; +module_param(stall_ms, uint, 0444); +MODULE_PARM_DESC(stall_ms, "Time the target CPU ignores the IPI, in millis= econds."); + +static int stall_cpu =3D -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 i= nterrupts 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 =3D 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 =3D csd_test_hog_fn; + err =3D 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 =3D 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 =3D 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 =3D 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 =3D stall_cpu < 0 ? cpumask_first(cpu_online_mask) : stall_cpu; + sender_cpu =3D nr_cpu_ids; + if (target_cpu < nr_cpu_ids && cpu_online(target_cpu)) + sender_cpu =3D cpumask_any_but(cpu_online_mask, target_cpu); + if (sender_cpu >=3D nr_cpu_ids) { + pr_err("need CPU%d and one other CPU online\n", target_cpu); + ret =3D -EINVAL; + goto unlock; + } + + pr_info("stalling CPU%d for %u ms %s, IPI from CPU%d\n", target_cpu, stal= l_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 =3D -EAGAIN; +unlock: + cpus_read_unlock(); + + return ret; +} +module_init(test_csd_lock_init); + +MODULE_LICENSE("GPL"); +MODULE_AUTHOR("Breno Leitao "); +MODULE_DESCRIPTION("Test module to stall a CPU on a CSD lock"); --=20 2.53.0-Meta