refactor(api): harden relay forwarding with timeout, retries and redacted logs
This commit is contained in:
@@ -1107,3 +1107,44 @@ Validation:
|
|||||||
Follow-ups:
|
Follow-ups:
|
||||||
|
|
||||||
- Batch 12 completes the previously listed remaining P2-S2 relay GET candidates.
|
- 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.
|
||||||
|
|||||||
@@ -1,6 +1,6 @@
|
|||||||
import axios from "axios";
|
import axios from "axios";
|
||||||
import { azureHeaders } from "../../../actions/core/headers";
|
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 { getToken } from "../../../actions/core/token";
|
||||||
import { hashAPIPath } from "../../../actions/core/hash";
|
import { hashAPIPath } from "../../../actions/core/hash";
|
||||||
import { respondError, respondSuccess } from "./apiResponse";
|
import { respondError, respondSuccess } from "./apiResponse";
|
||||||
@@ -9,6 +9,69 @@ const WEBAPI_URL =
|
|||||||
process.env.RELAY_ROOT ||
|
process.env.RELAY_ROOT ||
|
||||||
"https://dev-pedw-ns.servicebus.windows.net/dev-pedw-hc/";
|
"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 ({
|
export const relayGet = async ({
|
||||||
queryUrl,
|
queryUrl,
|
||||||
res,
|
res,
|
||||||
@@ -51,8 +114,34 @@ export const forwardGetData = async ({
|
|||||||
queryUrl,
|
queryUrl,
|
||||||
requestOptionsBuilder,
|
requestOptionsBuilder,
|
||||||
accessToken,
|
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 =
|
const tokenAccessToken =
|
||||||
typeof accessToken === "string" && accessToken.length > 0
|
typeof accessToken === "string" && accessToken.length > 0
|
||||||
? accessToken
|
? accessToken
|
||||||
@@ -62,15 +151,71 @@ export const forwardGetData = async ({
|
|||||||
const finalUrl =
|
const finalUrl =
|
||||||
resolvedBaseUrl + queryUrl + (appendHash ? hashAPIPath(queryUrl) : "");
|
resolvedBaseUrl + queryUrl + (appendHash ? hashAPIPath(queryUrl) : "");
|
||||||
|
|
||||||
const { data } = await axios.get(
|
const requestOptions =
|
||||||
finalUrl,
|
|
||||||
typeof requestOptionsBuilder === "function"
|
typeof requestOptionsBuilder === "function"
|
||||||
? requestOptionsBuilder(tokenAccessToken)
|
? requestOptionsBuilder(tokenAccessToken)
|
||||||
: azureHeaders(tokenAccessToken)
|
: azureHeaders(tokenAccessToken);
|
||||||
);
|
|
||||||
|
|
||||||
return {
|
const axiosOptions = {
|
||||||
data,
|
...(requestOptions || {}),
|
||||||
accessToken: tokenAccessToken
|
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;
|
||||||
};
|
};
|
||||||
|
|||||||
@@ -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);
|
||||||
|
});
|
||||||
|
}
|
||||||
Reference in New Issue
Block a user