Users/chskelt/debug logging2 (#2503)

* Adding further console logging but also fixed lines with JSON.stringify(error)

* Added retry mechanism for GETs for armRequest workflow

* Moved stringifyError into its own file as it was causing strict compile issues in ErrorHandlingUtils

src/Utils/AuthorizationUtils.ts

@@ -1,5 +1,6 @@
 import * as msal from "@azure/msal-browser";
 import { getEnvironmentScopeEndpoint } from "Common/EnvironmentUtility";
+import { stringifyError } from "Common/stringifyError";
 import { Action, ActionModifiers } from "Shared/Telemetry/TelemetryConstants";
 import { hasProxyServer, isDataplaneRbacSupported } from "Utils/APITypeUtils";
 import { AuthType } from "../AuthType";
@@ -154,9 +155,9 @@ export async function acquireMsalTokenForAccount(
       traceFailure(Action.SignInAad, {
         request: JSON.stringify(loginRequest),
         acquireTokenType: silent ? "silent" : "interactive",
-        errorMessage: JSON.stringify(error),
+        errorMessage: stringifyError(error),
       });
-      traceFailure(Action.AcquireMsalToken, { error: JSON.stringify(error) }, msalStartKey);
+      traceFailure(Action.AcquireMsalToken, { error: stringifyError(error) }, msalStartKey);
       // Mark expected failure for health metrics so timeout emits healthy
       if (isExpectedError(error)) {
         scenarioMonitor.markExpectedFailure();

src/Utils/FetchWithTimeout.test.ts

@@ -0,0 +1,136 @@
+import { fetchWithTimeout, tryFetchWithTimeout } from "./FetchWithTimeout";
+
+describe("fetchWithTimeout", () => {
+  const originalFetch = global.fetch;
+
+  afterEach(() => {
+    global.fetch = originalFetch;
+    jest.useRealTimers();
+  });
+
+  it("forwards init and resolves with the fetch response", async () => {
+    const fakeResponse = { ok: true } as Response;
+    const fetchMock = jest.fn().mockResolvedValue(fakeResponse);
+    global.fetch = fetchMock as unknown as typeof global.fetch;
+
+    const result = await fetchWithTimeout("https://example.com", { method: "GET" }, 1000);
+
+    expect(result).toBe(fakeResponse);
+    expect(fetchMock).toHaveBeenCalledTimes(1);
+    const [url, init] = fetchMock.mock.calls[0];
+    expect(url).toBe("https://example.com");
+    expect((init as RequestInit).method).toBe("GET");
+    expect((init as RequestInit).signal).toBeDefined();
+  });
+
+  it("aborts the fetch when the internal timeout fires", async () => {
+    jest.useFakeTimers();
+    let receivedSignal: AbortSignal | undefined;
+    global.fetch = jest.fn().mockImplementation((_url: string, init: RequestInit) => {
+      receivedSignal = init.signal ?? undefined;
+      return new Promise<Response>((_resolve, reject) => {
+        init.signal?.addEventListener("abort", () => {
+          const err = new Error("aborted");
+          err.name = "AbortError";
+          reject(err);
+        });
+      });
+    }) as unknown as typeof global.fetch;
+
+    const pending = fetchWithTimeout("https://example.com", {}, 50);
+    jest.advanceTimersByTime(50);
+    await expect(pending).rejects.toMatchObject({ name: "AbortError" });
+    expect(receivedSignal?.aborted).toBe(true);
+  });
+
+  it("throws immediately when the external signal is already aborted", async () => {
+    const fetchMock = jest.fn();
+    global.fetch = fetchMock as unknown as typeof global.fetch;
+
+    const controller = new AbortController();
+    const reason = new Error("user-cancelled");
+    controller.abort(reason);
+
+    await expect(fetchWithTimeout("https://example.com", { signal: controller.signal }, 1000)).rejects.toBe(reason);
+    expect(fetchMock).not.toHaveBeenCalled();
+  });
+
+  it("aborts mid-fetch when the external signal aborts and propagates the reason", async () => {
+    const reason = new Error("user-cancelled");
+    let internalSignal: AbortSignal | undefined;
+    global.fetch = jest.fn().mockImplementation((_url: string, init: RequestInit) => {
+      internalSignal = init.signal ?? undefined;
+      return new Promise<Response>((_resolve, reject) => {
+        init.signal?.addEventListener("abort", () => reject(init.signal?.reason ?? new Error("aborted")));
+      });
+    }) as unknown as typeof global.fetch;
+
+    const controller = new AbortController();
+    const pending = fetchWithTimeout("https://example.com", { signal: controller.signal }, 60000);
+    // Let the fetch wire up its abort listener before triggering.
+    await Promise.resolve();
+    controller.abort(reason);
+
+    await expect(pending).rejects.toBe(reason);
+    expect(internalSignal?.aborted).toBe(true);
+  });
+
+  it("skips the timer when timeoutMs is Infinity", async () => {
+    const setTimeoutSpy = jest.spyOn(global, "setTimeout");
+    global.fetch = jest.fn().mockResolvedValue({ ok: true } as Response) as unknown as typeof global.fetch;
+
+    await fetchWithTimeout("https://example.com", {}, Infinity);
+
+    expect(setTimeoutSpy).not.toHaveBeenCalled();
+    setTimeoutSpy.mockRestore();
+  });
+
+  it("cleans up the timer and external listener after a successful fetch", async () => {
+    const clearTimeoutSpy = jest.spyOn(global, "clearTimeout");
+    global.fetch = jest.fn().mockResolvedValue({ ok: true } as Response) as unknown as typeof global.fetch;
+
+    const controller = new AbortController();
+    const removeListenerSpy = jest.spyOn(controller.signal, "removeEventListener");
+
+    await fetchWithTimeout("https://example.com", { signal: controller.signal }, 1000);
+
+    expect(clearTimeoutSpy).toHaveBeenCalled();
+    expect(removeListenerSpy).toHaveBeenCalledWith("abort", expect.any(Function));
+    clearTimeoutSpy.mockRestore();
+  });
+
+  it("cleans up the timer and listener when the fetch rejects", async () => {
+    const clearTimeoutSpy = jest.spyOn(global, "clearTimeout");
+    const networkError = new Error("network down");
+    global.fetch = jest.fn().mockRejectedValue(networkError) as unknown as typeof global.fetch;
+
+    const controller = new AbortController();
+    const removeListenerSpy = jest.spyOn(controller.signal, "removeEventListener");
+
+    await expect(fetchWithTimeout("https://example.com", { signal: controller.signal }, 1000)).rejects.toBe(
+      networkError,
+    );
+
+    expect(clearTimeoutSpy).toHaveBeenCalled();
+    expect(removeListenerSpy).toHaveBeenCalledWith("abort", expect.any(Function));
+    clearTimeoutSpy.mockRestore();
+  });
+});
+
+describe("tryFetchWithTimeout", () => {
+  const originalFetch = global.fetch;
+  afterEach(() => {
+    global.fetch = originalFetch;
+  });
+
+  it("returns null on fetch failure", async () => {
+    global.fetch = jest.fn().mockRejectedValue(new Error("boom")) as unknown as typeof global.fetch;
+    await expect(tryFetchWithTimeout("https://example.com")).resolves.toBeNull();
+  });
+
+  it("returns the response on success", async () => {
+    const response = { ok: true } as Response;
+    global.fetch = jest.fn().mockResolvedValue(response) as unknown as typeof global.fetch;
+    await expect(tryFetchWithTimeout("https://example.com")).resolves.toBe(response);
+  });
+});

src/Utils/FetchWithTimeout.ts

@@ -3,6 +3,11 @@
  *
  * Usage: await fetchWithTimeout(url, { method: 'GET', headers: {...} }, 10000);
  *
+ * If `init.signal` is provided, it is combined with the internal timeout: aborting
+ * the caller's signal aborts the fetch (propagating the caller's abort reason), and
+ * the timeout still applies. Pass `timeoutMs: Infinity` to disable the timeout entirely
+ * (useful for long-running operations that should rely solely on caller cancellation).
+ *
  * A shared helper to remove duplicated inline implementations across the codebase.
  */
 export async function fetchWithTimeout(
@@ -10,13 +15,30 @@ export async function fetchWithTimeout(
   init: RequestInit = {},
   timeoutMs: number = 5000,
 ): Promise<Response> {
+  const externalSignal = init.signal;
+  if (externalSignal?.aborted) {
+    throw externalSignal.reason ?? new DOMException("The operation was aborted.", "AbortError");
+  }
+
   const controller = new AbortController();
-  const id = setTimeout(() => controller.abort(), timeoutMs);
+  const hasTimeout = Number.isFinite(timeoutMs);
+  const timeoutId = hasTimeout ? setTimeout(() => controller.abort(), timeoutMs) : undefined;
+
+  let onExternalAbort: (() => void) | undefined;
+  if (externalSignal) {
+    onExternalAbort = () => controller.abort(externalSignal.reason);
+    externalSignal.addEventListener("abort", onExternalAbort, { once: true });
+  }
+
   try {
-    const response = await fetch(url, { ...init, signal: controller.signal });
-    return response;
+    return await fetch(url, { ...init, signal: controller.signal });
   } finally {
-    clearTimeout(id);
+    if (timeoutId !== undefined) {
+      clearTimeout(timeoutId);
+    }
+    if (externalSignal && onExternalAbort) {
+      externalSignal.removeEventListener("abort", onExternalAbort);
+    }
   }
 }
 

src/Utils/arm/generatedClients/cosmos/sqlResources.ts

@@ -6,9 +6,10 @@
   Generated from: https://raw.githubusercontent.com/Azure/azure-rest-api-specs/main/specification/cosmos-db/resource-manager/Microsoft.DocumentDB/DocumentDB/preview/2025-11-01-preview/cosmos-db.json
 */
 
+import { stringifyError } from "Common/stringifyError";
+import { configContext } from "../../../../ConfigContext";
 import { armRequest } from "../../request";
 import * as Types from "./types";
-import { configContext } from "../../../../ConfigContext";
 const apiVersion = "2025-11-01-preview";
 
 /* Lists the SQL databases under an existing Azure Cosmos DB database account. */
@@ -18,7 +19,14 @@ export async function listSqlDatabases(
   accountName: string,
 ): Promise<Types.SqlDatabaseListResult> {
   const path = `/subscriptions/${subscriptionId}/resourceGroups/${resourceGroupName}/providers/Microsoft.DocumentDB/databaseAccounts/${accountName}/sqlDatabases`;
-  return armRequest({ host: configContext.ARM_ENDPOINT, path, method: "GET", apiVersion });
+  console.log("{{cdbp}} in listSqlDatabases(): path: " + path);
+  try {
+    console.log("{{cdbp}} in listSqlDatabases(): calling armRequest");
+    return armRequest({ host: configContext.ARM_ENDPOINT, path, method: "GET", apiVersion });
+  } catch (error) {
+    console.log("{{cdbp}} in listSqlDatabases(): ERROR: " + stringifyError(error));
+    throw error;
+  }
 }
 
 /* Gets the SQL database under an existing Azure Cosmos DB database account with the provided name. */

src/Utils/arm/request.test.ts

@@ -75,4 +75,200 @@ describe("ARM request", () => {
       armRequest({ apiVersion: "2001-01-01", host: "https://foo.com", path: "foo", method: "GET" }),
     ).rejects.toThrow("No authority token provided");
   });
+
+  describe("timeout and retry behavior", () => {
+    beforeEach(() => {
+      updateUserContext({
+        authType: AuthType.AAD,
+        authorizationToken: "some-token",
+      });
+    });
+
+    const makeAbortError = () => Object.assign(new Error("aborted"), { name: "AbortError" });
+    const okResponse = () => ({
+      ok: true,
+      headers: new Headers(),
+      json: async () => ({}),
+    });
+
+    it("forwards timeoutMs to the underlying fetch timer", async () => {
+      const setTimeoutSpy = jest.spyOn(global, "setTimeout");
+      window.fetch = jest.fn().mockResolvedValue(okResponse());
+
+      await armRequest({
+        apiVersion: "2001-01-01",
+        host: "https://foo.com",
+        path: "foo",
+        method: "POST",
+        timeoutMs: 12345,
+      });
+
+      const timeoutValues = setTimeoutSpy.mock.calls.map((c) => c[1]);
+      expect(timeoutValues).toContain(12345);
+      setTimeoutSpy.mockRestore();
+    });
+
+    it("uses the default 5000ms timeout when timeoutMs is not provided", async () => {
+      const setTimeoutSpy = jest.spyOn(global, "setTimeout");
+      window.fetch = jest.fn().mockResolvedValue(okResponse());
+
+      await armRequest({ apiVersion: "2001-01-01", host: "https://foo.com", path: "foo", method: "POST" });
+
+      const timeoutValues = setTimeoutSpy.mock.calls.map((c) => c[1]);
+      expect(timeoutValues).toContain(5000);
+      setTimeoutSpy.mockRestore();
+    });
+
+    it("skips the timer when timeoutMs is Infinity", async () => {
+      const setTimeoutSpy = jest.spyOn(global, "setTimeout");
+      window.fetch = jest.fn().mockResolvedValue(okResponse());
+
+      await armRequest({
+        apiVersion: "2001-01-01",
+        host: "https://foo.com",
+        path: "foo",
+        method: "POST",
+        timeoutMs: Infinity,
+      });
+
+      // No timer should be created by fetchWithTimeout.
+      expect(setTimeoutSpy).not.toHaveBeenCalled();
+      setTimeoutSpy.mockRestore();
+    });
+
+    it("retries GET on timeout with escalating timeouts and eventually succeeds", async () => {
+      const setTimeoutSpy = jest.spyOn(global, "setTimeout");
+      const fetchMock = jest
+        .fn()
+        .mockRejectedValueOnce(makeAbortError())
+        .mockRejectedValueOnce(makeAbortError())
+        .mockResolvedValueOnce(okResponse());
+      window.fetch = fetchMock;
+
+      await armRequest({
+        apiVersion: "2001-01-01",
+        host: "https://foo.com",
+        path: "foo",
+        method: "GET",
+        timeoutMs: 1000,
+      });
+
+      expect(fetchMock).toHaveBeenCalledTimes(3);
+      const timeoutValues = setTimeoutSpy.mock.calls.map((c) => c[1]);
+      // Each attempt creates a setTimeout for its escalating timeout (1x, 2x, 4x).
+      expect(timeoutValues).toContain(1000);
+      expect(timeoutValues).toContain(2000);
+      expect(timeoutValues).toContain(4000);
+      setTimeoutSpy.mockRestore();
+    });
+
+    it("gives up after exhausting retries and rejects with the last AbortError", async () => {
+      const fetchMock = jest.fn().mockRejectedValue(makeAbortError());
+      window.fetch = fetchMock;
+
+      await expect(
+        armRequest({
+          apiVersion: "2001-01-01",
+          host: "https://foo.com",
+          path: "foo",
+          method: "GET",
+          timeoutMs: 1000,
+        }),
+      ).rejects.toMatchObject({ name: "AbortError" });
+
+      // 3 attempts total (initial + 2 retries).
+      expect(fetchMock).toHaveBeenCalledTimes(3);
+    });
+
+    it("does not retry non-GET methods on timeout", async () => {
+      const fetchMock = jest.fn().mockRejectedValue(makeAbortError());
+      window.fetch = fetchMock;
+
+      for (const method of ["POST", "PUT", "PATCH", "DELETE", "HEAD"] as const) {
+        fetchMock.mockClear();
+        await expect(
+          armRequest({
+            apiVersion: "2001-01-01",
+            host: "https://foo.com",
+            path: "foo",
+            method,
+            timeoutMs: 1000,
+          }),
+        ).rejects.toBeTruthy();
+        expect(fetchMock).toHaveBeenCalledTimes(1);
+      }
+    });
+
+    it("does not retry GET on HTTP 500 (server error)", async () => {
+      const fetchMock = jest.fn().mockResolvedValue({
+        ok: false,
+        status: 500,
+        json: async () => ({ code: "InternalServerError", message: "boom" }),
+      });
+      window.fetch = fetchMock;
+
+      await expect(
+        armRequest({
+          apiVersion: "2001-01-01",
+          host: "https://foo.com",
+          path: "foo",
+          method: "GET",
+          timeoutMs: 1000,
+        }),
+      ).rejects.toThrow("boom");
+
+      expect(fetchMock).toHaveBeenCalledTimes(1);
+    });
+
+    it("stops retrying GET when the caller's signal is already aborted", async () => {
+      const controller = new AbortController();
+      const reason = new Error("user-cancelled");
+      controller.abort(reason);
+      const fetchMock = jest.fn().mockRejectedValue(makeAbortError());
+      window.fetch = fetchMock;
+
+      await expect(
+        armRequest({
+          apiVersion: "2001-01-01",
+          host: "https://foo.com",
+          path: "foo",
+          method: "GET",
+          timeoutMs: 1000,
+          signal: controller.signal,
+        }),
+      ).rejects.toBeTruthy();
+
+      // fetchWithTimeout throws synchronously on already-aborted signal, so no fetch call.
+      expect(fetchMock).not.toHaveBeenCalled();
+    });
+
+    it("combines caller signal with timeout: aborting the signal cancels in-flight fetch", async () => {
+      const controller = new AbortController();
+      const reason = new Error("user-cancelled");
+
+      let receivedSignal: AbortSignal | undefined;
+      window.fetch = jest.fn().mockImplementation((_url: string, init: RequestInit) => {
+        receivedSignal = init.signal ?? undefined;
+        return new Promise<Response>((_resolve, reject) => {
+          init.signal?.addEventListener("abort", () => reject(init.signal?.reason ?? new Error("aborted")));
+        });
+      });
+
+      const pending = armRequest({
+        apiVersion: "2001-01-01",
+        host: "https://foo.com",
+        path: "foo",
+        method: "POST",
+        timeoutMs: 60000,
+        signal: controller.signal,
+      });
+
+      // Allow fetch to wire up its abort listener.
+      await Promise.resolve();
+      controller.abort(reason);
+
+      await expect(pending).rejects.toBe(reason);
+      expect(receivedSignal?.aborted).toBe(true);
+    });
+  });
 });

src/Utils/arm/request.ts

@@ -5,6 +5,7 @@ Instead, generate ARM clients that consume this function with stricter typing.
 
 */
 
+import { stringifyError } from "Common/stringifyError";
 import promiseRetry, { AbortError } from "p-retry";
 import { HttpHeaders } from "../../Common/Constants";
 import { configContext } from "../../ConfigContext";
@@ -50,8 +51,13 @@ interface Options {
   contentType?: string;
   customHeaders?: Record<string, string>;
   signal?: AbortSignal;
+  timeoutMs?: number;
 }
 
+const DEFAULT_ARM_TIMEOUT_MS = 5000;
+
+const isAbortError = (error: unknown): boolean => error instanceof Error && error.name === "AbortError";
+
 export async function armRequestWithoutPolling<T>({
   host,
   path,
@@ -62,6 +68,7 @@ export async function armRequestWithoutPolling<T>({
   contentType,
   customHeaders,
   signal,
+  timeoutMs,
 }: Options): Promise<{ result: T; operationStatusUrl: string }> {
   const url = new URL(path, host);
   url.searchParams.append("api-version", configContext.armAPIVersion || apiVersion);
@@ -71,6 +78,9 @@ export async function armRequestWithoutPolling<T>({
   }
 
   if (!userContext?.authorizationToken && !customHeaders?.["Authorization"]) {
+    console.log(
+      "{{cdbp}} in armRequestWithoutPolling(): condition '!userContext?.authorizationToken && !customHeaders?.['Authorization']' met, throwing 'No authority token provided' error",
+    );
     throw new Error("No authority token provided");
   }
 
@@ -84,10 +94,14 @@ export async function armRequestWithoutPolling<T>({
     method,
     headers,
     body: requestBody ? JSON.stringify(requestBody) : undefined,
-    ...(signal ? { signal } : {}),
+    signal,
   };
 
-  const response = signal ? await window.fetch(url.href, fetchInit) : await fetchWithTimeout(url.href, fetchInit);
+  const effectiveTimeoutMs = timeoutMs ?? DEFAULT_ARM_TIMEOUT_MS;
+  console.log(
+    `{{cdbp}} in armRequestWithoutPolling(): calling fetchWithRetry (method=${method}, timeoutMs=${effectiveTimeoutMs}, hasSignal=${!!signal})`,
+  );
+  const response = await fetchWithRetry(url.href, fetchInit, method, effectiveTimeoutMs, signal);
 
   if (!response.ok) {
     let error: ARMError;
@@ -101,9 +115,11 @@ export async function armRequestWithoutPolling<T>({
         error.code = errorResponse.code;
       }
     } catch (error) {
+      console.log("{{cdbp}} in armRequestWithoutPolling(): ERROR: " + stringifyError(error));
       throw new Error(await response.text());
     }
 
+    console.log("{{cdbp}} in armRequestWithoutPolling(): ERROR: " + stringifyError(error));
     throw error;
   }
 
@@ -123,6 +139,7 @@ export async function armRequest<T>({
   contentType,
   customHeaders,
   signal,
+  timeoutMs,
 }: Options): Promise<T> {
   const armRequestResult = await armRequestWithoutPolling<T>({
     host,
@@ -134,6 +151,7 @@ export async function armRequest<T>({
     contentType,
     customHeaders,
     signal,
+    timeoutMs,
   });
   const operationStatusUrl = armRequestResult.operationStatusUrl;
   if (operationStatusUrl) {
@@ -142,6 +160,45 @@ export async function armRequest<T>({
   return armRequestResult.result;
 }
 
+/**
+ * Calls `fetchWithTimeout` once for non-idempotent methods. For idempotent GETs, retries
+ * up to {@link RETRY_TIMEOUT_MULTIPLIERS}.length attempts on timeout, escalating the timeout
+ * on each attempt. HTTP error responses (4xx/5xx) are NOT retried — they are surfaced by the
+ * caller's response.ok check. External `signal` cancellation aborts the retry loop immediately.
+ */
+async function fetchWithRetry(
+  url: string,
+  fetchInit: RequestInit,
+  method: Options["method"],
+  timeoutMs: number,
+  signal?: AbortSignal,
+): Promise<Response> {
+  if (method !== "GET") {
+    return fetchWithTimeout(url, fetchInit, timeoutMs);
+  }
+
+  const RETRY_TIMEOUT_MULTIPLIERS = [1, 2, 4];
+  const RETRY_BACKOFF_MS = 100;
+
+  return promiseRetry(
+    (attemptNumber: number) => {
+      const attemptTimeoutMs =
+        timeoutMs * RETRY_TIMEOUT_MULTIPLIERS[Math.min(attemptNumber - 1, RETRY_TIMEOUT_MULTIPLIERS.length - 1)];
+      console.log(`{{cdbp}} in fetchWithRetry(): calling fetchWithTimeout: attempt=${attemptNumber} url=${url}`);
+      return fetchWithTimeout(url, fetchInit, attemptTimeoutMs);
+    },
+    {
+      retries: RETRY_TIMEOUT_MULTIPLIERS.length - 1,
+      factor: 1,
+      minTimeout: RETRY_BACKOFF_MS,
+      maxTimeout: RETRY_BACKOFF_MS,
+      signal,
+      // Only retry on timeout aborts. Caller cancellation (external signal aborted) stops retries.
+      shouldRetry: (error) => isAbortError(error) && !signal?.aborted,
+    },
+  );
+}
+
 async function getOperationStatus(operationStatusUrl: string) {
   if (!userContext.authorizationToken) {
     throw new Error("No authority token provided");