From nobody Sat Oct 3 09:51:45 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 52CBE46EF71 for ; Wed, 5 Aug 2026 12:53:36 +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=1785934420; cv=none; b=kTNzP9jNYDM3jPqsOvLX07LzwhW3LhnuDdCxefToQ7SJwN8twCUTQomHZSq4ydt+7OfPe6ZOAvuYR/yNgeXspCvQHyE1Teh1hd4te5xBoRIBtJbV6cQ1/YMKvDF1l10fmVTBg+7md9dsq+HobcIqzu965lxef6FD+atQMkXNH60= ARC-Message-Signature: i=1; a=rsa-sha256; d=subspace.kernel.org; s=arc-20240116; t=1785934420; c=relaxed/simple; bh=xD0YoVEXKj1702xtW0H+VlaTaBqMqQU3x8D8By3l86U=; h=From:Date:Subject:MIME-Version:Content-Type:Message-Id:To:Cc; b=Vndnopg8lTjA02mU3snjzvf63QYykRIylQSClrIQKpMsZ5JSNOcGN+peyNwdCP0ArEXmpZIGa6k1Lj1ImuseVxFpw7XNwnnpX67GXpnOWKPPXt8pCbH+tFHFN7jHXGZo1l2OP/7FgXXBXbXh9pww/h3TV7DrK2AHdw7yBct3M6g= 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=UIxo5KTr; 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="UIxo5KTr" 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:Message-Id: Content-Transfer-Encoding:Content-Type:MIME-Version:Subject:Date:From: Reply-To:Content-ID:Content-Description:In-Reply-To:References; bh=MXGZ/i1MAGcUwokC/fTPbSk5Hr0s0/fb+bHndBJQlMk=; b=UIxo5KTrFncoONdJk0p7Mi5Cgr fG5+LqrMFggAHES6p+I9RvwBAiQAEpXZI/ouNPg2Iw2yXv0OvN+yeClGsCnU1tyOCpivwjkg4yf+K 3ihRBgERe7WIS935kOVylCDdZkHPfzf4RSMFw99tlQkSYhDlR3cX8rUqg0IZYwmNVvZ4j74rNd/3Q MTrG685OdMo4O0I0z54hxONycsFfhdqCxSpr0ovohOWhRY6jUJOgXgoBk7wkyTBwET6m5dqA8ak/V eeTLKjEycmIUpqQ3g0TV3fiexqefFzpNXDXGcfyW/mzmS8WovuwPDqtcswcj0uymaJ8ZKPtOhsSU8 bU2I8AkQ==; 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 1wrb7E-00Dvh4-0v; Wed, 05 Aug 2026 12:53:00 +0000 From: Breno Leitao Date: Wed, 05 Aug 2026 05:51:54 -0700 Subject: [PATCH] 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: <20260805-csd-stall-duration-v1-1-71134fafe150@debian.org> X-B4-Tracking: v=1; b=H4sIAOkxc2oC/x3MQQqDMBAF0KsMf+1AatSGXKW4CGZaBySWjEpBv HvBd4B3wqSqGCKdqHKo6VoQ6dEQpjmVj7BmRELr2sEF1/NkmW1Ly8J5r2nTtbD3ofedz8/kAhr Ct8pbf3f6Gq/rD/qsFjBkAAAA X-Change-ID: 20260805-csd-stall-duration-3385343d7a08 To: paulmck@kernel.org Cc: linux-kernel@vger.kernel.org, Peter Zijlstra , Ingo Molnar , Sebastian Andrzej Siewior , kernel-team@meta.com, Thomas Gleixner , Breno Leitao X-Mailer: b4 0.16-dev-f8e9d X-Developer-Signature: v=1; a=openpgp-sha256; l=4057; i=leitao@debian.org; h=from:subject:message-id; bh=xD0YoVEXKj1702xtW0H+VlaTaBqMqQU3x8D8By3l86U=; b=owEBbQKS/ZANAwAIATWjk5/8eHdtAcsmYgBqczIoCpDT8uoDMe5g3GWoKZJ3Oez60Anpz7/xX RigbT2vmH+JAjMEAAEIAB0WIQSshTmm6PRnAspKQ5s1o5Of/Hh3bQUCanMyKAAKCRA1o5Of/Hh3 bdlOEACgib+AehpZpbuvW6tO6xp+M/gzN8ez0U9sfWRitGuf6h0nlGoJV6P2t5b6fJ8BCs4gdMN rOuFo/2Vkh2JbRSt/C40UB8YeaHQEVN5GP9ah3OL8DbF7Ajp6QYFVkesIIRQGSQ7VQw2FKXjVJE oE3IHmcXzUrzNiWEY34LlM/+mnmPj8LuVRRBc4RvSJ3FnclOeJdaEbcVNZiqISsfhn4j3ZHbfIX brt+CgJdw1P8o4ZMhRWFfFvOqiUq3ATIKQoIHa+T9OBSuEHf6ZOCku52IImrtyOizJKGJGJt+tS 5GUdekvricpmlGlxWdDaW+LG9+sI5mpGDbwKWh7aYLg2Gs5PSrGZBYWuo74Tbt7AAixh/6s/wh3 FebVqfsPVt0tAgpslk959iha8AtugA0FHK0LBjiIcP4fL6xJeqe7wUfi6yU7Zf6tzVNK+Ms8D2q 8jYgEOoXgm0o3h8Ux0gyEklRI2khbmmLGlnTkcODMMP6/+aCANuZqTCUKxp3rgq+SNj+G6luKUW Np6ucuDrx1/yiZyoMU7aSXLza1+xCpz6CJUgSiN43lkFSpFtNrM8ZjeNpaVzYAyLc4qtySHyM8/ 8EUxq0zkhIOkngYPUO029nPpfglaMmQLf73puoKpOnETGD3Sag48AUSyr/NhGZOiNPm1RGpKae4 B0JgXJFqOl/C9rw== 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 --- kernel/smp.c | 30 +++++++++++++++++++++++++----- 1 file changed, 25 insertions(+), 5 deletions(-) diff --git a/kernel/smp.c b/kernel/smp.c index b696bcc60c08f..c09d5ca0c7ed6 100644 --- a/kernel/smp.c +++ b/kernel/smp.c @@ -236,12 +236,31 @@ bool csd_lock_is_stuck(void) return !!atomic_read(&n_csd_lock_stuck); } =20 +/* + * Report a CSD lock that came back. @ts_start is when the wait began and + * @ts_unstuck is when the release was noticed, both from + * ktime_get_mono_fast_ns(). A zero @ts_resend means no IPI was re-sent, = so + * there is no re-send delta to report. + */ +static void csd_lock_print_unstuck(int bug_id, int cpu, u64 ts_start, u64 = ts_unstuck, + u64 ts_resend) +{ + if (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", + bug_id, raw_smp_processor_id(), cpu, (s64)(ts_unstuck - ts_start), + (s64)(ts_unstuck - ts_resend)); + else + pr_alert("csd: CSD lock (#%d) got unstuck on CPU#%02d, CPU#%02d released= the lock after %lld ns.\n", + bug_id, raw_smp_processor_id(), cpu, (s64)(ts_unstuck - 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 *t= s1, int *bug_id, unsigned long *nmessages) +static bool csd_lock_wait_toolong(call_single_data_t *csd, u64 ts0, u64 *t= s1, u64 *ts_resend, + int *bug_id, unsigned long *nmessages) { int cpu =3D -1; int cpux; @@ -254,9 +273,9 @@ static bool csd_lock_wait_toolong(call_single_data_t *c= sd, u64 ts0, u64 *ts1, in if (!(flags & CSD_FLAG_LOCK)) { if (!unlikely(*bug_id)) return true; + ts2 =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", - *bug_id, raw_smp_processor_id(), cpu); + csd_lock_print_unstuck(*bug_id, cpu, ts0, ts2, *ts_resend); atomic_dec(&n_csd_lock_stuck); return true; } @@ -320,6 +339,7 @@ static bool csd_lock_wait_toolong(call_single_data_t *c= sd, u64 ts0, u64 *ts1, in 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); arch_send_call_function_single_ipi(cpu); + *ts_resend =3D ktime_get_mono_fast_ns(); } } if (firsttime) @@ -339,14 +359,14 @@ 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; + u64 ts0, ts1, ts_resend =3D 0; int bug_id =3D 0; - u64 ts0, ts1; =20 guard(preempt)(); =20 ts1 =3D ts0 =3D ktime_get_mono_fast_ns(); for (;;) { - if (csd_lock_wait_toolong(csd, ts0, &ts1, &bug_id, &nmessages)) + if (csd_lock_wait_toolong(csd, ts0, &ts1, &ts_resend, &bug_id, &nmessage= s)) break; cpu_relax(); } --- base-commit: 0f6da28aab51b16762ed82e8fdeaa5042da45b08 change-id: 20260805-csd-stall-duration-3385343d7a08 Best regards, -- =20 Breno Leitao