From d60a98ec873d43dda2cdee28edabc12835898be2 Mon Sep 17 00:00:00 2001
From: Peter Steinberger <steipete@gmail.com>
Date: Thu, 13 Aug 2026 21:42:11 -0700
Subject: [PATCH] fix(diagnostics): suppress startup-only heartbeat delay
 warnings (#123461)

* fix(diagnostics): suppress startup heartbeat delay warning

* chore: leave release changelog generation to release tooling
---
 src/logging/diagnostic.test.ts | 20 ++++++++++++++++++++
 src/logging/diagnostic.ts      |  6 +++---
 2 files changed, 23 insertions(+), 3 deletions(-)

diff --git a/src/logging/diagnostic.test.ts b/src/logging/diagnostic.test.ts
index 0622a86120ed..2c1683c02106 100644
--- a/src/logging/diagnostic.test.ts
+++ b/src/logging/diagnostic.test.ts
@@ -520,6 +520,12 @@ describe("stuck session diagnostics threshold", () => {
     vi.advanceTimersByTime(30_000);
 
     expectLoggerMessageContaining(warnSpy, "liveness heartbeat delayed");
+    const delayedHeartbeat = loggerMessages(warnSpy).find((message) =>
+      message.includes("liveness heartbeat delayed"),
+    );
+    expect(delayedHeartbeat).toMatch(/overdue=\d+ms elapsed=\d+ms/u);
+    const timing = delayedHeartbeat?.match(/overdue=(\d+)ms elapsed=(\d+)ms/u);
+    expect(Number(timing?.[2]) - Number(timing?.[1])).toBe(30_000);
     expect(recoverStuckSession).not.toHaveBeenCalled();
 
     vi.advanceTimersByTime(30_000);
@@ -2394,6 +2400,7 @@ describe("stuck session diagnostics threshold", () => {
   it("suppresses liveness warnings during startupGraceMs while still sampling", () => {
     const warnSpy = vi.spyOn(diagnosticLogger, "warn").mockImplementation(() => undefined);
     const events: string[] = [];
+    const recoverStuckSession = vi.fn();
     const sampleLiveness = vi.fn(() => ({
       reasons: ["event_loop_delay" as const],
       intervalMs: 30_000,
@@ -2403,6 +2410,7 @@ describe("stuck session diagnostics threshold", () => {
     const unsubscribe = onDiagnosticEvent((event) => events.push(event.type));
 
     try {
+      vi.setSystemTime(0);
       startDiagnosticHeartbeat(
         {
           diagnostics: {
@@ -2411,23 +2419,35 @@ describe("stuck session diagnostics threshold", () => {
         },
         {
           emitMemorySample: createEmitMemorySampleMock(),
+          recoverStuckSession,
           sampleLiveness,
           startupGraceMs: 60_000,
+          testTimings: { stuckSessionWarnMs: 1_000, stuckSessionAbortMs: 1_000 },
         },
       );
 
       logMessageQueued({ sessionId: "s1", sessionKey: "main", source: "test" });
+      logSessionStateChange({ sessionId: "s1", sessionKey: "main", state: "processing" });
+      markDiagnosticEmbeddedRunStarted({ sessionId: "s1", sessionKey: "main" });
+      vi.setSystemTime(1_001);
       vi.advanceTimersByTime(30_000);
 
       expect(sampleLiveness).toHaveBeenCalledTimes(1);
+      expectNoLoggerMessageContaining(warnSpy, "liveness heartbeat delayed");
       expectNoLoggerMessageContaining(warnSpy, "liveness warning:");
       expect(events).not.toContain("diagnostic.liveness.warning");
+      expect(recoverStuckSession).not.toHaveBeenCalled();
 
       vi.advanceTimersByTime(30_000);
 
       expect(sampleLiveness).toHaveBeenCalledTimes(2);
       expectLoggerMessageContaining(warnSpy, "liveness warning:");
       expect(events).toContain("diagnostic.liveness.warning");
+      expectRecoveryCall(
+        recoverStuckSession,
+        { sessionId: "s1", sessionKey: "main", queueDepth: 0, allowActiveAbort: true },
+        ["ageMs", "stateGeneration"],
+      );
     } finally {
       unsubscribe();
     }
diff --git a/src/logging/diagnostic.ts b/src/logging/diagnostic.ts
index e10dd2ebf2f0..ecf5b4449695 100644
--- a/src/logging/diagnostic.ts
+++ b/src/logging/diagnostic.ts
@@ -1176,19 +1176,19 @@ export function startDiagnosticHeartbeat(
       lastDiagnosticHeartbeatTickAt === undefined ? 0 : now - lastDiagnosticHeartbeatTickAt;
     lastDiagnosticHeartbeatTickAt = now;
     const heartbeatOverdueMs = Math.max(0, heartbeatElapsedMs - DIAGNOSTIC_HEARTBEAT_INTERVAL_MS);
+    const inStartupGrace = livenessGraceUntil > 0 && now < livenessGraceUntil;
     // Observe ordinary timer jitter at the scheduled tick so it cannot consume
     // a run's remaining recovery budget. Material lateness can also hide queued
     // progress events, so the next healthy heartbeat owns recovery instead.
     const recoveryObservationNow = now - heartbeatOverdueMs;
     const shouldDeferRecovery = heartbeatOverdueMs >= DEFAULT_LIVENESS_EVENT_LOOP_DELAY_WARN_MS;
-    if (shouldDeferRecovery) {
+    if (shouldDeferRecovery && !inStartupGrace) {
       diag.warn(
-        `liveness heartbeat delayed ${Math.round(heartbeatElapsedMs)}ms; deferring recovery decisions`,
+        `liveness heartbeat delayed: overdue=${Math.round(heartbeatOverdueMs)}ms elapsed=${Math.round(heartbeatElapsedMs)}ms; deferring recovery decisions`,
       );
     }
     pruneDiagnosticSessionStates(now, true);
     const work = getDiagnosticWorkSnapshot(now);
-    const inStartupGrace = livenessGraceUntil > 0 && now < livenessGraceUntil;
     const rawLivenessSample = (opts?.sampleLiveness ?? sampleDiagnosticLiveness)(now, work);
     // Keep sampling during grace so event-loop delay baselines reset, but suppress startup-only reports.
     const livenessSample = inStartupGrace ? null : rawLivenessSample;