Harden Copilot api-proxy startup: verify listener accept readiness and absorb first-request ECONNREFUSED

actions/setup/js/awf_reflect.cjs

@@ -19,6 +19,8 @@ require("./shim.cjs");
 
 const fs = require("fs");
 const path = require("path");
+const net = require("net");
+const tls = require("tls");
 const { withRetry, sleep } = require("./error_recovery.cjs");
 const { getErrorMessage } = require("./error_helpers.cjs");
 
@@ -33,6 +35,12 @@ const AWF_REFLECT_OUTPUT_PATH = "/tmp/gh-aw/sandbox/firewall/awf-reflect.json";
 const AWF_REFLECT_TIMEOUT_MS = 60000;
 // Milliseconds to wait for each models_url fallback fetch (shorter than the main reflect timeout).
 const AWF_MODELS_URL_TIMEOUT_MS = 3000;
+// Milliseconds to wait for an api-proxy provider listener to accept a real TCP connection.
+const AWF_PROVIDER_LISTENER_READY_TIMEOUT_MS = 15000;
+// Delay between provider-listener readiness probes.
+const AWF_PROVIDER_LISTENER_READY_RETRY_MS = 250;
+// Per-attempt connect timeout while probing provider listener readiness.
+const AWF_PROVIDER_LISTENER_READY_PROBE_TIMEOUT_MS = 2000;
 // Maximum attempts for models_url fallback fetches when the proxy is not yet ready.
 const AWF_MODELS_URL_MAX_ATTEMPTS = 5;
 // Base delay between models_url fallback retries. Uses exponential backoff.
@@ -366,6 +374,7 @@ async function fetchAWFReflect(options) {
         status: res.status,
       };
     }
+
     /** @type {any} */
     const reflectData = await res.json();
     // Attempt to fill in null models for configured providers by fetching directly
@@ -407,6 +416,111 @@ async function fetchAWFReflect(options) {
   }
 }
 
+/**
+ * Wait until a provider listener (e.g. http://api-proxy:10002) accepts a real TCP
+ * connection, or time out.
+ *
+ * This guards against startup races where /reflect is available but a per-provider
+ * listener has not yet bound/started accepting connections.
+ *
+ * For "https:" baseUrls, the probe performs a full TLS handshake (via `tls.connect`) rather
+ * than a bare TCP connect, since a raw TCP accept can succeed well before the TLS listener
+ * is actually able to negotiate a secure session and serve requests.
+ *
+ * @param {{
+ *   baseUrl: string,
+ *   timeoutMs?: number,
+ *   retryDelayMs?: number,
+ *   perAttemptTimeoutMs?: number,
+ *   logger?: (msg: string) => void,
+ *   connectImpl?: (opts: { host: string, port: number }) => import("net").Socket,
+ * }} options - `connectImpl`, when provided, overrides the default connect implementation for
+ *   both http:// and https:// baseUrls (test-only hook). The readiness event awaited is still
+ *   derived from the baseUrl's protocol: for `https:` baseUrls the returned socket must emit
+ *   `"secureConnect"` (not `"connect"`) to be treated as ready, matching the real `tls.connect`
+ *   behavior; for `http:` baseUrls it must emit `"connect"`.
+ * @returns {Promise<{ ok: true } | { ok: false, reason: "invalid_base_url" | "timeout", error: string }>}
+ */
+async function waitForProviderListenerReady(options) {
+  const logger = options?.logger ?? DEFAULT_REFLECT_LOGGER;
+  const timeoutMs = options?.timeoutMs ?? AWF_PROVIDER_LISTENER_READY_TIMEOUT_MS;
+  const retryDelayMs = options?.retryDelayMs ?? AWF_PROVIDER_LISTENER_READY_RETRY_MS;
+  const perAttemptTimeoutMsRaw = options?.perAttemptTimeoutMs ?? AWF_PROVIDER_LISTENER_READY_PROBE_TIMEOUT_MS;
+  const perAttemptTimeoutMs = Number.isFinite(perAttemptTimeoutMsRaw) && perAttemptTimeoutMsRaw > 0 ? perAttemptTimeoutMsRaw : AWF_PROVIDER_LISTENER_READY_PROBE_TIMEOUT_MS;
+  const baseUrl = String(options?.baseUrl ?? "").trim();
+  if (!baseUrl) {
+    return { ok: false, reason: "invalid_base_url", error: "baseUrl is empty" };
+  }
+
+  let parsed;
+  try {
+    parsed = new URL(baseUrl);
+  } catch {
+    return { ok: false, reason: "invalid_base_url", error: `invalid baseUrl: ${baseUrl}` };
+  }
+  const host = parsed.hostname;
+  const port = parsed.port ? Number.parseInt(parsed.port, 10) : parsed.protocol === "https:" ? 443 : 80;
+  if (!host || !Number.isFinite(port) || port <= 0) {
+    return { ok: false, reason: "invalid_base_url", error: `baseUrl missing host/port: ${baseUrl}` };
+  }
+  // For https:// providers, a bare TCP accept does not prove the listener can complete a TLS
+  // handshake. Probe with tls.connect and wait for "secureConnect" so the readiness gate lines
+  // up with the actual failure mode (handshake/startup errors), not just an open port.
+  const isHttps = parsed.protocol === "https:";
+  const readyEvent = isHttps ? "secureConnect" : "connect";
+  const connectImpl = options?.connectImpl ?? (isHttps ? opts => tls.connect({ ...opts, servername: opts.host }) : opts => net.connect(opts));
+
+  logger(`awf-reflect: waiting for provider listener readiness at ${host}:${port} (timeout=${timeoutMs}ms)`);
+  const startedAt = Date.now();
+  let lastError = "connection not ready";
+  while (Date.now() - startedAt < timeoutMs) {
+    const remainingBudgetMs = timeoutMs - (Date.now() - startedAt);
+    const attemptTimeoutMs = Math.max(1, Math.min(perAttemptTimeoutMs, remainingBudgetMs));
+    const ready = await new Promise(resolve => {
+      const socket = connectImpl({ host, port });
+      let settled = false;
+      const settle = value => {
+        if (settled) return;
+        settled = true;
+        resolve(value);
+      };
+      const timer = setTimeout(() => {
+        clear();
+        lastError = `connect attempt timed out after ${attemptTimeoutMs}ms`;
+        socket.destroy();
+        settle(false);
+      }, attemptTimeoutMs);
+      const clear = () => clearTimeout(timer);
+      socket.once(readyEvent, () => {
+        clear();
+        // Remove the error listener before tearing down the socket: a successful handshake has
+        // already settled this probe as ready, and a late/trailing error (e.g. an abrupt RST)
+        // must not overwrite lastError or otherwise affect the already-settled result.
+        socket.removeAllListeners("error");
+        socket.destroy();
+        settle(true);
+      });
+      socket.once("error", err => {
+        clear();
+        lastError = getErrorMessage(err);
+        socket.destroy();
+        settle(false);
+      });
+    });
+    if (ready) {
+      logger(`awf-reflect: provider listener is accepting connections at ${host}:${port}`);
+      return { ok: true };
+    }
+    const remainingAfterAttemptMs = timeoutMs - (Date.now() - startedAt);
+    if (remainingAfterAttemptMs <= 0) {
+      break;
+    }
+    await sleep(Math.min(retryDelayMs, remainingAfterAttemptMs));
+  }
+  logger(`awf-reflect: provider listener readiness timed out for ${host}:${port} (${lastError})`);
+  return { ok: false, reason: "timeout", error: lastError };
+}
+
 /**
  * Returns true when the model name matches well-known Anthropic naming patterns:
  * "claude-*" prefix, or "-opus", "-haiku", or "-sonnet" as a segment or suffix.
@@ -836,12 +950,16 @@ if (typeof module !== "undefined" && module.exports) {
     AWF_MODELS_URL_MAX_ATTEMPTS,
     AWF_MODELS_URL_RETRY_BASE_MS,
     AWF_MODELS_URL_RETRY_MAX_MS,
+    AWF_PROVIDER_LISTENER_READY_TIMEOUT_MS,
+    AWF_PROVIDER_LISTENER_READY_RETRY_MS,
+    AWF_PROVIDER_LISTENER_READY_PROBE_TIMEOUT_MS,
     DEFAULT_API_PROXY_HOST_BRIDGE,
     GEMINI_MODEL_NAME_PREFIX,
     enrichReflectModels,
     extractModelIds,
     fetchAWFReflect,
     fetchModelsFromUrl,
+    waitForProviderListenerReady,
     getCatalogModelEntry,
     hasAPIProxyLocalhostAlias,
     inferProviderTypeForModel,

actions/setup/js/awf_reflect.test.cjs

@@ -13,12 +13,16 @@ const {
   AWF_MODELS_URL_MAX_ATTEMPTS,
   AWF_MODELS_URL_RETRY_BASE_MS,
   AWF_MODELS_URL_RETRY_MAX_MS,
+  AWF_PROVIDER_LISTENER_READY_TIMEOUT_MS,
+  AWF_PROVIDER_LISTENER_READY_RETRY_MS,
+  AWF_PROVIDER_LISTENER_READY_PROBE_TIMEOUT_MS,
   DEFAULT_API_PROXY_HOST_BRIDGE,
   GEMINI_MODEL_NAME_PREFIX,
   enrichReflectModels,
   extractModelIds,
   fetchAWFReflect,
   fetchModelsFromUrl,
+  waitForProviderListenerReady,
   getCatalogModelEntry,
   hasAPIProxyLocalhostAlias,
   inferProviderTypeForModel,
@@ -39,11 +43,196 @@ describe("awf_reflect.cjs", () => {
       expect(AWF_MODELS_URL_MAX_ATTEMPTS).toBe(5);
       expect(AWF_MODELS_URL_RETRY_BASE_MS).toBe(250);
       expect(AWF_MODELS_URL_RETRY_MAX_MS).toBe(2000);
+      expect(AWF_PROVIDER_LISTENER_READY_TIMEOUT_MS).toBe(15000);
+      expect(AWF_PROVIDER_LISTENER_READY_RETRY_MS).toBe(250);
+      expect(AWF_PROVIDER_LISTENER_READY_PROBE_TIMEOUT_MS).toBe(2000);
       expect(DEFAULT_API_PROXY_HOST_BRIDGE).toBe("host.docker.internal");
       expect(GEMINI_MODEL_NAME_PREFIX).toBe("models/");
     });
   });
 
+  describe("waitForProviderListenerReady", () => {
+    it("returns ok when listener accepts a connection", async () => {
+      const probingConnect = vi.fn().mockImplementation(() => {
+        const listeners = {};
+        queueMicrotask(() => listeners.connect && listeners.connect());
+        return {
+          once(event, cb) {
+            listeners[event] = cb;
+            return this;
+          },
+          removeAllListeners() {
+            return this;
+          },
+          end() {},
+          destroy() {},
+        };
+      });
+
+      const result = await waitForProviderListenerReady({
+        baseUrl: "http://api-proxy:10002",
+        timeoutMs: 500,
+        retryDelayMs: 1,
+        connectImpl: probingConnect,
+        logger: () => {},
+      });
+      expect(result).toEqual({ ok: true });
+      expect(probingConnect).toHaveBeenCalled();
+    });
+
+    it("returns timeout when listener keeps refusing connections", async () => {
+      const probingConnect = vi.fn().mockImplementation(() => {
+        const listeners = {};
+        queueMicrotask(() => listeners.error && listeners.error(new Error("connect ECONNREFUSED")));
+        return {
+          once(event, cb) {
+            listeners[event] = cb;
+            return this;
+          },
+          end() {},
+          destroy() {},
+        };
+      });
+
+      const result = await waitForProviderListenerReady({
+        baseUrl: "http://api-proxy:10002",
+        timeoutMs: 20,
+        retryDelayMs: 1,
+        connectImpl: probingConnect,
+        logger: () => {},
+      });
+      expect(result.ok).toBe(false);
+      expect(result.reason).toBe("timeout");
+      expect(result.error).toContain("ECONNREFUSED");
+    });
+
+    it("returns invalid_base_url for malformed baseUrl", async () => {
+      const result = await waitForProviderListenerReady({
+        baseUrl: "not a url",
+        logger: () => {},
+      });
+      expect(result.ok).toBe(false);
+      expect(result.reason).toBe("invalid_base_url");
+    });
+
+    it("returns timeout when the per-attempt timer fires (hung connect)", async () => {
+      const probingConnect = vi.fn().mockImplementation(() => {
+        // Never fire "connect" or "error" — simulates a hung connection attempt.
+        return {
+          once() {
+            return this;
+          },
+          end() {},
+          destroy() {},
+          removeAllListeners() {
+            return this;
+          },
+        };
+      });
+
+      const result = await waitForProviderListenerReady({
+        baseUrl: "http://api-proxy:10002",
+        timeoutMs: 50,
+        retryDelayMs: 1,
+        perAttemptTimeoutMs: 5,
+        connectImpl: probingConnect,
+        logger: () => {},
+      });
+      expect(result.ok).toBe(false);
+      expect(result.reason).toBe("timeout");
+      expect(result.error).toContain("timed out after");
+    });
+
+    it("uses a TLS secureConnect handshake for https:// baseUrls", async () => {
+      const probingConnect = vi.fn().mockImplementation(() => {
+        const listeners = {};
+        queueMicrotask(() => listeners.secureConnect && listeners.secureConnect());
+        return {
+          once(event, cb) {
+            listeners[event] = cb;
+            return this;
+          },
+          removeAllListeners() {
+            return this;
+          },
+          end() {},
+          destroy() {},
+        };
+      });
+
+      const result = await waitForProviderListenerReady({
+        baseUrl: "https://api-proxy:10443",
+        timeoutMs: 500,
+        retryDelayMs: 1,
+        connectImpl: probingConnect,
+        logger: () => {},
+      });
+      expect(result).toEqual({ ok: true });
+    });
+
+    it("does not report ready on a bare TCP connect for https:// baseUrls", async () => {
+      const probingConnect = vi.fn().mockImplementation(() => {
+        const listeners = {};
+        // Only fires "connect" (bare TCP), never "secureConnect" (TLS handshake complete).
+        queueMicrotask(() => listeners.connect && listeners.connect());
+        return {
+          once(event, cb) {
+            listeners[event] = cb;
+            return this;
+          },
+          removeAllListeners() {
+            return this;
+          },
+          end() {},
+          destroy() {},
+        };
+      });
+
+      const result = await waitForProviderListenerReady({
+        baseUrl: "https://api-proxy:10443",
+        timeoutMs: 20,
+        retryDelayMs: 1,
+        perAttemptTimeoutMs: 5,
+        connectImpl: probingConnect,
+        logger: () => {},
+      });
+      expect(result.ok).toBe(false);
+      expect(result.reason).toBe("timeout");
+    });
+
+    it("clears a late error after a successful connect without affecting the result", async () => {
+      const probingConnect = vi.fn().mockImplementation(() => {
+        const listeners = {};
+        queueMicrotask(() => listeners.connect && listeners.connect());
+        return {
+          once(event, cb) {
+            listeners[event] = cb;
+            return this;
+          },
+          removeAllListeners(event) {
+            delete listeners[event];
+            return this;
+          },
+          end() {},
+          destroy() {
+            // Simulate a trailing error emitted after destroy(); it must be a no-op
+            // since the "error" listener was removed on successful connect.
+            if (listeners.error) listeners.error(new Error("late ECONNRESET"));
+          },
+        };
+      });
+
+      const result = await waitForProviderListenerReady({
+        baseUrl: "http://api-proxy:10002",
+        timeoutMs: 500,
+        retryDelayMs: 1,
+        connectImpl: probingConnect,
+        logger: () => {},
+      });
+      expect(result).toEqual({ ok: true });
+    });
+  });
+
   describe("rewriteAPIProxyURLForHostBridge", () => {
     it("does not rewrite api-proxy URLs without a localhost HOSTALIASES mapping", () => {
       const env = { HOSTALIASES: "/tmp/aliases" };