diff --git a/src/routes/health.ts b/src/routes/health.ts index 92050f3..2a9895a 100644 --- a/src/routes/health.ts +++ b/src/routes/health.ts @@ -12,9 +12,20 @@ const startTime = Date.now(); const HEALTH_CACHE_TTL_MS = 5_000; let cachedHealth: { body: unknown; statusCode: number; checkedAt: number } | null = null; +// The RPC check previously only verified that getSlot() resolved within the +// timeout — a stale/lagging-but-responsive RPC node (returns a valid slot +// every time, just one that never advances) would pass indefinitely. Track +// the last reading and require the slot to have actually advanced once +// enough wall-clock time has passed for any genuinely-live node to have +// produced new slots (Solana's slot time is ~400-600ms even under +// congestion, so 30s is a wide margin, not a tight one). +const STALE_RPC_THRESHOLD_MS = 30_000; +let lastRpcReading: { slot: number; checkedAt: number } | null = null; + /** @internal Reset cache — used by tests to ensure isolation */ export function __resetHealthCache(): void { cachedHealth = null; + lastRpcReading = null; } export function healthRoutes(): Hono { @@ -27,15 +38,31 @@ export function healthRoutes(): Hono { const checks: { db: boolean; rpc: boolean; ws: boolean } = { db: false, rpc: false, ws: false }; let status: "ok" | "degraded" | "down" = "ok"; - // Check RPC connectivity + // Check RPC connectivity — and that it isn't just responding with a + // stale, non-advancing slot (see STALE_RPC_THRESHOLD_MS comment above). try { - await withRpcFallback( + const slot = await withRpcFallback( (conn) => conn.getSlot(), getConnection(), "healthcheck:getSlot", HEALTH_RPC_TIMEOUT_MS, ); - checks.rpc = true; + const now = Date.now(); + if ( + lastRpcReading && + slot <= lastRpcReading.slot && + now - lastRpcReading.checkedAt > STALE_RPC_THRESHOLD_MS + ) { + logger.error("RPC check failed: slot has not advanced", { + lastSlot: lastRpcReading.slot, + slot, + elapsedMs: now - lastRpcReading.checkedAt, + }); + checks.rpc = false; + } else { + checks.rpc = true; + } + lastRpcReading = { slot, checkedAt: now }; } catch (err) { logger.error("RPC check failed", { error: truncateErrorMessage(err instanceof Error ? err.message : err, 120) }); checks.rpc = false; diff --git a/tests/routes/health.test.ts b/tests/routes/health.test.ts index 6e08651..b137322 100644 --- a/tests/routes/health.test.ts +++ b/tests/routes/health.test.ts @@ -1,4 +1,4 @@ -import { describe, it, expect, vi, beforeEach } from "vitest"; +import { describe, it, expect, vi, beforeEach, afterEach } from "vitest"; import { healthRoutes, __resetHealthCache } from "../../src/routes/health.js"; // Mock ws module @@ -54,6 +54,63 @@ describe("health routes", () => { vi.mocked(getSupabase).mockReturnValue(mockSupabase); }); + describe("RPC staleness detection (BUG-109)", () => { + afterEach(() => { + vi.useRealTimers(); + }); + + it("detects a stale/lagging RPC node whose slot stops advancing", async () => { + vi.useFakeTimers(); + mockConnection.getSlot.mockResolvedValue(100); + mockSupabase.select.mockResolvedValue({ count: 5, error: null }); + + const app = healthRoutes(); + + // First check establishes the baseline reading — no prior reading + // exists yet, so this is healthy regardless of the slot value. + const res1 = await app.request("/health"); + const data1 = await res1.json(); + expect(data1.checks.rpc).toBe(true); + + // Advance past both the 5s health-response cache and the 30s + // staleness threshold, with the node still returning the SAME slot — + // a genuinely live node would have advanced by many slots by now. + await vi.advanceTimersByTimeAsync(35_000); + + const res2 = await app.request("/health"); + const data2 = await res2.json(); + expect(data2.checks.rpc).toBe(false); + expect(data2.status).not.toBe("ok"); + }); + + it("does not flag staleness when the slot has genuinely advanced", async () => { + vi.useFakeTimers(); + mockConnection.getSlot.mockResolvedValueOnce(100).mockResolvedValueOnce(200); + mockSupabase.select.mockResolvedValue({ count: 5, error: null }); + + const app = healthRoutes(); + await app.request("/health"); + await vi.advanceTimersByTimeAsync(35_000); + const res2 = await app.request("/health"); + const data2 = await res2.json(); + expect(data2.checks.rpc).toBe(true); + }); + + it("does not flag staleness on rapid successive checks within the threshold window", async () => { + vi.useFakeTimers(); + mockConnection.getSlot.mockResolvedValue(100); + mockSupabase.select.mockResolvedValue({ count: 5, error: null }); + + const app = healthRoutes(); + await app.request("/health"); + // Past the 5s response cache, but well under the 30s staleness threshold. + await vi.advanceTimersByTimeAsync(10_000); + const res2 = await app.request("/health"); + const data2 = await res2.json(); + expect(data2.checks.rpc).toBe(true); + }); + }); + it("should return 200 with ok status when RPC and DB work", async () => { mockConnection.getSlot.mockResolvedValue(123456789); mockSupabase.select.mockResolvedValue({ count: 5, error: null });