diff --git a/memory-bank/change-log.md b/memory-bank/change-log.md index 50b7b973..c584470b 100644 --- a/memory-bank/change-log.md +++ b/memory-bank/change-log.md @@ -1107,3 +1107,44 @@ Validation: Follow-ups: - Batch 12 completes the previously listed remaining P2-S2 relay GET candidates. + +--- + +### CL-030: TASK22236 P2-S3 relay forwarding hardening (timeouts, retries, structured redacted logs) + +date: 2026-03-24 +author: Cline +scope: `pages/api/middleware/relayForwarding.js`, `tests/phase21/relay-forwarding-hardening.test.cjs` +type: change +rationale: Begin P2-S3 by hardening shared relay forwarding behavior with bounded timeout/retry controls and structured redacted operational logging, reducing transient failure impact while preserving endpoint contracts. +impact: Improves resilience/observability for relay GET traffic; endpoint success/error contracts remain unchanged because caller handlers still manage response envelopes. +status: completed + +Summary: + +- Hardened `forwardGetData` in `relayForwarding.js` with: + - configurable timeout (`RELAY_TIMEOUT_MS`, default 8000ms) + - bounded retries (`RELAY_RETRY_MAX`, default 2) + - exponential backoff with cap (`RELAY_RETRY_BASE_DELAY_MS`, `RELAY_RETRY_MAX_DELAY_MS`) + - retry eligibility for transient statuses/codes (`408/429/5xx`, selected network timeout/reset codes) +- Added structured, redacted operational relay logs: + - `relay_request_retrying` + - `relay_request_failed` +- Preserved compatibility behaviors: + - existing token/header/hash handling + - optional `appendHash` and custom `requestOptionsBuilder` + - endpoint-level `relayGet` error response semantics +- Added focused Phase 21 hardening tests: + - retries on retryable status and succeeds + - does not retry non-retryable status + - applies timeout and respects `appendHash=false` + +Validation: + +- `node tests/phase21/relay-forwarding-hardening.test.cjs` -> pass (3/3) +- `node tests/phase21/endpoint-handler-contract.test.cjs` -> pass (152/152) +- `npm run lint` -> warnings only (pre-existing `react-hooks/exhaustive-deps`; no new lint errors) + +Follow-ups: + +- Optional next hardening increment: introduce endpoint-specific retry overrides for write paths (if future non-GET use is introduced) to keep retry policy conservative by operation type. diff --git a/pages/api/middleware/relayForwarding.js b/pages/api/middleware/relayForwarding.js index f5b4c16c..8d9118e6 100644 --- a/pages/api/middleware/relayForwarding.js +++ b/pages/api/middleware/relayForwarding.js @@ -1,6 +1,6 @@ import axios from "axios"; import { azureHeaders } from "../../../actions/core/headers"; -import { consoleLogger } from "../../../actions/core/logger"; +import { consoleLogger, redactSensitive } from "../../../actions/core/logger"; import { getToken } from "../../../actions/core/token"; import { hashAPIPath } from "../../../actions/core/hash"; import { respondError, respondSuccess } from "./apiResponse"; @@ -9,6 +9,69 @@ const WEBAPI_URL = process.env.RELAY_ROOT || "https://dev-pedw-ns.servicebus.windows.net/dev-pedw-hc/"; +const DEFAULT_TIMEOUT_MS = 8000; +const DEFAULT_MAX_RETRIES = 2; +const DEFAULT_RETRY_BASE_DELAY_MS = 200; +const DEFAULT_RETRY_MAX_DELAY_MS = 1200; + +const RETRYABLE_STATUS_CODES = new Set([408, 429, 500, 502, 503, 504]); +const RETRYABLE_ERROR_CODES = new Set([ + "ECONNABORTED", + "ECONNRESET", + "ETIMEDOUT", + "ENOTFOUND", + "EAI_AGAIN", + "EPIPE" +]); + +const parsePositiveInt = (value, fallback) => { + const parsed = Number.parseInt(value, 10); + return Number.isFinite(parsed) && parsed >= 0 ? parsed : fallback; +}; + +const getRelayConfig = () => { + return { + timeoutMs: parsePositiveInt( + process.env.RELAY_TIMEOUT_MS, + DEFAULT_TIMEOUT_MS + ), + maxRetries: parsePositiveInt( + process.env.RELAY_RETRY_MAX, + DEFAULT_MAX_RETRIES + ), + retryBaseDelayMs: parsePositiveInt( + process.env.RELAY_RETRY_BASE_DELAY_MS, + DEFAULT_RETRY_BASE_DELAY_MS + ), + retryMaxDelayMs: parsePositiveInt( + process.env.RELAY_RETRY_MAX_DELAY_MS, + DEFAULT_RETRY_MAX_DELAY_MS + ) + }; +}; + +const backoffDelayMs = ({ attempt, retryBaseDelayMs, retryMaxDelayMs }) => { + return Math.min(retryMaxDelayMs, retryBaseDelayMs * 2 ** attempt); +}; + +const wait = async (delayMs) => { + await new Promise((resolve) => setTimeout(resolve, delayMs)); +}; + +const structuredRelayLog = (event, payload) => { + console.info(event, redactSensitive(payload)); +}; + +const shouldRetryRelayError = ({ error, attempt, maxRetries }) => { + if (attempt >= maxRetries) return false; + + const status = error?.response?.status; + if (RETRYABLE_STATUS_CODES.has(status)) return true; + + const code = error?.code; + return RETRYABLE_ERROR_CODES.has(code); +}; + export const relayGet = async ({ queryUrl, res, @@ -51,8 +114,34 @@ export const forwardGetData = async ({ queryUrl, requestOptionsBuilder, accessToken, - appendHash = true + appendHash = true, + timeoutMs, + maxRetries, + retryBaseDelayMs, + retryMaxDelayMs }) => { + const relayConfig = getRelayConfig(); + + const resolvedTimeoutMs = + typeof timeoutMs === "number" && timeoutMs >= 0 + ? timeoutMs + : relayConfig.timeoutMs; + + const resolvedMaxRetries = + typeof maxRetries === "number" && maxRetries >= 0 + ? maxRetries + : relayConfig.maxRetries; + + const resolvedRetryBaseDelayMs = + typeof retryBaseDelayMs === "number" && retryBaseDelayMs >= 0 + ? retryBaseDelayMs + : relayConfig.retryBaseDelayMs; + + const resolvedRetryMaxDelayMs = + typeof retryMaxDelayMs === "number" && retryMaxDelayMs >= 0 + ? retryMaxDelayMs + : relayConfig.retryMaxDelayMs; + const tokenAccessToken = typeof accessToken === "string" && accessToken.length > 0 ? accessToken @@ -62,15 +151,71 @@ export const forwardGetData = async ({ const finalUrl = resolvedBaseUrl + queryUrl + (appendHash ? hashAPIPath(queryUrl) : ""); - const { data } = await axios.get( - finalUrl, + const requestOptions = typeof requestOptionsBuilder === "function" ? requestOptionsBuilder(tokenAccessToken) - : azureHeaders(tokenAccessToken) - ); + : azureHeaders(tokenAccessToken); - return { - data, - accessToken: tokenAccessToken + const axiosOptions = { + ...(requestOptions || {}), + timeout: + requestOptions?.timeout != null + ? requestOptions.timeout + : resolvedTimeoutMs }; + + let lastError; + + for (let attempt = 0; attempt <= resolvedMaxRetries; attempt += 1) { + try { + const { data } = await axios.get(finalUrl, axiosOptions); + + return { + data, + accessToken: tokenAccessToken + }; + } catch (error) { + lastError = error; + + const retryEligible = shouldRetryRelayError({ + error, + attempt, + maxRetries: resolvedMaxRetries + }); + + if (!retryEligible) { + structuredRelayLog("relay_request_failed", { + queryUrl, + baseUrl: resolvedBaseUrl, + attempt: attempt + 1, + maxAttempts: resolvedMaxRetries + 1, + status: error?.response?.status, + code: error?.code, + message: error?.message + }); + throw error; + } + + const delayMs = backoffDelayMs({ + attempt, + retryBaseDelayMs: resolvedRetryBaseDelayMs, + retryMaxDelayMs: resolvedRetryMaxDelayMs + }); + + structuredRelayLog("relay_request_retrying", { + queryUrl, + baseUrl: resolvedBaseUrl, + attempt: attempt + 1, + maxAttempts: resolvedMaxRetries + 1, + delayMs, + status: error?.response?.status, + code: error?.code, + message: error?.message + }); + + await wait(delayMs); + } + } + + throw lastError; }; diff --git a/tests/phase21/relay-forwarding-hardening.test.cjs b/tests/phase21/relay-forwarding-hardening.test.cjs new file mode 100644 index 00000000..cd94e20b --- /dev/null +++ b/tests/phase21/relay-forwarding-hardening.test.cjs @@ -0,0 +1,167 @@ +const assert = require("assert"); +const fs = require("fs"); +const path = require("path"); +const vm = require("vm"); + +const rootDir = path.resolve(__dirname, "..", ".."); + +const loadRelayForwardingModule = (injected = {}) => { + const filePath = path.join( + rootDir, + "pages/api/middleware/relayForwarding.js" + ); + let source = fs.readFileSync(filePath, "utf8"); + + source = source.replace(/import[\s\S]*?from\s+"[^"]+";\n?/g, ""); + source = source.replace(/export const\s+/g, "const "); + + source += + "\nmodule.exports = { relayGet, relayGetData, forwardGetData };\n"; + + const context = { + module: { exports: {} }, + exports: {}, + require, + process, + setTimeout, + clearTimeout, + console: { + log: () => {}, + info: () => {}, + warn: () => {}, + error: () => {} + }, + ...injected + }; + + vm.runInNewContext(source, context, { filename: filePath }); + return context.module.exports; +}; + +const tests = []; +const test = (name, fn) => tests.push({ name, fn }); + +test("forwardGetData retries retryable HTTP status and then succeeds", async () => { + let callCount = 0; + + const mod = loadRelayForwardingModule({ + axios: { + get: async () => { + callCount += 1; + if (callCount === 1) { + const error = new Error("temporary outage"); + error.response = { status: 503 }; + throw error; + } + + return { data: { ok: true } }; + } + }, + getToken: async () => ({ access_token: "token" }), + hashAPIPath: () => "&hash=abc", + azureHeaders: () => ({ headers: { Authorization: "Bearer token" } }), + redactSensitive: (value) => value, + consoleLogger: () => {} + }); + + const result = await mod.forwardGetData({ + queryUrl: "incidents?$top=1", + maxRetries: 1, + retryBaseDelayMs: 0, + retryMaxDelayMs: 0 + }); + + assert.strictEqual(callCount, 2); + assert.deepStrictEqual(result.data, { ok: true }); + assert.strictEqual(result.accessToken, "token"); +}); + +test("forwardGetData does not retry non-retryable HTTP status", async () => { + let callCount = 0; + + const mod = loadRelayForwardingModule({ + axios: { + get: async () => { + callCount += 1; + const error = new Error("bad request"); + error.response = { status: 400 }; + throw error; + } + }, + getToken: async () => ({ access_token: "token" }), + hashAPIPath: () => "&hash=abc", + azureHeaders: () => ({ headers: {} }), + redactSensitive: (value) => value, + consoleLogger: () => {} + }); + + let thrown = null; + try { + await mod.forwardGetData({ + queryUrl: "incidents?$top=1", + maxRetries: 3, + retryBaseDelayMs: 0, + retryMaxDelayMs: 0 + }); + } catch (error) { + thrown = error; + } + + assert.ok(thrown); + assert.strictEqual(callCount, 1); +}); + +test("forwardGetData applies timeout and appendHash=false behavior", async () => { + let capturedUrl = null; + let capturedOptions = null; + + const mod = loadRelayForwardingModule({ + axios: { + get: async (url, options) => { + capturedUrl = url; + capturedOptions = options; + return { data: { ok: true } }; + } + }, + getToken: async () => ({ access_token: "token" }), + hashAPIPath: () => "&hash=abc", + azureHeaders: () => ({ headers: { Accept: "application/json" } }), + redactSensitive: (value) => value, + consoleLogger: () => {} + }); + + await mod.forwardGetData({ + baseUrl: "http://localhost:3000", + queryUrl: "/api/endpoint/example", + appendHash: false, + timeoutMs: 1234, + maxRetries: 0 + }); + + assert.strictEqual( + capturedUrl, + "http://localhost:3000/api/endpoint/example" + ); + assert.strictEqual(capturedOptions.timeout, 1234); + assert.strictEqual(capturedOptions.headers.Accept, "application/json"); +}); + +const run = async () => { + let passed = 0; + for (const currentTest of tests) { + await currentTest.fn(); + passed += 1; + } + console.log( + `Phase 21 relay-forwarding hardening tests passed (${passed}/${tests.length}).` + ); +}; + +module.exports = run; + +if (require.main === module) { + run().catch((error) => { + console.error(error); + process.exit(1); + }); +}