fix: log fetch timeout aborts (#73692)

* fix: log fetch timeout aborts

* fix: redact relative timeout urls

src/infra/net/fetch-guard.ts

@@ -318,6 +318,8 @@ export async function fetchWithSsrFGuard(params: GuardedFetchOptions): Promise<G
   const { signal, cleanup } = buildTimeoutAbortSignal({
     timeoutMs: params.timeoutMs,
     signal: params.signal,
+    operation: "fetchWithSsrFGuard",
+    url: params.url,
   });
 
   let released = false;

src/utils/fetch-timeout.test.ts

@@ -0,0 +1,81 @@
+import { afterEach, beforeEach, describe, expect, it, vi } from "vitest";
+
+const warn = vi.hoisted(() => vi.fn());
+
+vi.mock("../logging/subsystem.js", () => ({
+  createSubsystemLogger: vi.fn(() => ({
+    warn,
+  })),
+}));
+
+import { buildTimeoutAbortSignal } from "./fetch-timeout.js";
+
+describe("buildTimeoutAbortSignal", () => {
+  beforeEach(() => {
+    warn.mockClear();
+    vi.useFakeTimers();
+  });
+
+  afterEach(() => {
+    vi.useRealTimers();
+  });
+
+  it("logs when its own timeout aborts the signal", async () => {
+    const { signal, cleanup } = buildTimeoutAbortSignal({
+      timeoutMs: 25,
+      operation: "unit-test",
+      url: "https://user:pass@example.com/v1/responses?api-key=secret#fragment",
+    });
+
+    await vi.advanceTimersByTimeAsync(25);
+
+    expect(signal?.aborted).toBe(true);
+    expect(warn).toHaveBeenCalledTimes(1);
+    expect(warn).toHaveBeenCalledWith(
+      "fetch timeout reached; aborting operation",
+      expect.objectContaining({
+        timeoutMs: 25,
+        operation: "unit-test",
+        url: "https://example.com/v1/responses",
+      }),
+    );
+
+    cleanup();
+  });
+
+  it("strips query strings and hashes from relative timeout URL logs", async () => {
+    const { cleanup } = buildTimeoutAbortSignal({
+      timeoutMs: 25,
+      operation: "unit-test",
+      url: "/api/responses?api-key=secret#fragment",
+    });
+
+    await vi.advanceTimersByTimeAsync(25);
+
+    expect(warn).toHaveBeenCalledWith(
+      "fetch timeout reached; aborting operation",
+      expect.objectContaining({
+        url: "/api/responses",
+      }),
+    );
+
+    cleanup();
+  });
+
+  it("does not log when a parent signal aborts first", async () => {
+    const parent = new AbortController();
+    const { signal, cleanup } = buildTimeoutAbortSignal({
+      timeoutMs: 25,
+      signal: parent.signal,
+      operation: "unit-test",
+    });
+
+    parent.abort();
+    await vi.advanceTimersByTimeAsync(25);
+
+    expect(signal?.aborted).toBe(true);
+    expect(warn).not.toHaveBeenCalled();
+
+    cleanup();
+  });
+});

src/utils/fetch-timeout.ts

@@ -1,3 +1,16 @@
+import { createSubsystemLogger } from "../logging/subsystem.js";
+
+const log = createSubsystemLogger("fetch-timeout");
+const LOG_URL_MAX_CHARS = 500;
+const URL_SECRET_SUFFIX_PATTERN = /[?#]/;
+
+type TimeoutAbortSignalParams = {
+  timeoutMs?: number;
+  signal?: AbortSignal;
+  operation?: string;
+  url?: string;
+};
+
 /**
  * Relay abort without forwarding the Event argument as the abort reason.
  * Using .bind() avoids closure scope capture (memory leak prevention).
@@ -11,7 +24,56 @@ export function bindAbortRelay(controller: AbortController): () => void {
   return relayAbort.bind(controller);
 }
 
-export function buildTimeoutAbortSignal(params: { timeoutMs?: number; signal?: AbortSignal }): {
+function sanitizeTimeoutLogUrl(rawUrl: string | undefined): string | undefined {
+  const trimmed = rawUrl?.trim();
+  if (!trimmed) {
+    return undefined;
+  }
+  try {
+    const parsed = new URL(trimmed);
+    parsed.username = "";
+    parsed.password = "";
+    parsed.search = "";
+    parsed.hash = "";
+    const value = parsed.toString();
+    return value.length > LOG_URL_MAX_CHARS ? `${value.slice(0, LOG_URL_MAX_CHARS)}...` : value;
+  } catch {
+    const withoutQueryOrHash = trimmed.split(URL_SECRET_SUFFIX_PATTERN, 1)[0] ?? "";
+    const cleaned = withoutQueryOrHash
+      .replace(/[\r\n\u2028\u2029]+/g, " ")
+      .replace(/\p{Cc}+/gu, " ")
+      .replace(/\s+/g, " ")
+      .trim();
+    if (!cleaned) {
+      return undefined;
+    }
+    return cleaned.length > LOG_URL_MAX_CHARS
+      ? `${cleaned.slice(0, LOG_URL_MAX_CHARS)}...`
+      : cleaned;
+  }
+}
+
+function abortDueToTimeout(
+  controller: AbortController,
+  timeoutMs: number,
+  startedAtMs: number,
+  operation?: string,
+  url?: string,
+) {
+  if (controller.signal.aborted) {
+    return;
+  }
+  const sanitizedUrl = sanitizeTimeoutLogUrl(url);
+  log.warn("fetch timeout reached; aborting operation", {
+    timeoutMs,
+    elapsedMs: Math.max(0, Date.now() - startedAtMs),
+    ...(operation ? { operation } : {}),
+    ...(sanitizedUrl ? { url: sanitizedUrl } : {}),
+  });
+  controller.abort();
+}
+
+export function buildTimeoutAbortSignal(params: TimeoutAbortSignalParams): {
   signal?: AbortSignal;
   cleanup: () => void;
 } {
@@ -24,7 +86,16 @@ export function buildTimeoutAbortSignal(params: { timeoutMs?: number; signal?: A
   }
 
   const controller = new AbortController();
-  const timeoutId = setTimeout(controller.abort.bind(controller), timeoutMs);
+  const normalizedTimeoutMs = Math.max(1, Math.floor(timeoutMs));
+  const timeoutId = setTimeout(
+    abortDueToTimeout,
+    normalizedTimeoutMs,
+    controller,
+    normalizedTimeoutMs,
+    Date.now(),
+    params.operation,
+    params.url,
+  );
   const onAbort = bindAbortRelay(controller);
   if (signal) {
     if (signal.aborted) {
@@ -63,6 +134,8 @@ export async function fetchWithTimeout(
 ): Promise<Response> {
   const { signal, cleanup } = buildTimeoutAbortSignal({
     timeoutMs: Math.max(1, timeoutMs),
+    operation: "fetchWithTimeout",
+    url,
   });
   try {
     return await fetchFn(url, { ...init, signal });