Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
26 changes: 14 additions & 12 deletions src/middleware/requestLogger.js
Original file line number Diff line number Diff line change
@@ -1,4 +1,4 @@
'use strict';
"use strict";

/**
* Structured logging for every HTTP request/response cycle (issue #148).
Expand All @@ -10,30 +10,32 @@
* attached to every log line automatically by `logger.js`'s AsyncLocalStorage
* context (see requestId.js), so it isn't repeated here explicitly.
*
* Uses `req.path` (not `req.originalUrl`) so query strings — which can carry
* an API key on some endpoints — are never logged, consistent with
* logger.js's redaction of sensitive fields elsewhere.
* Uses the mount path plus `req.path` (not `req.originalUrl`) so mounted
* routers are logged accurately without exposing query strings, which can
* carry API keys on some endpoints.
*
* Also emits a distinct "Slow request detected" warn-level line for any
* request over SLOW_REQUEST_THRESHOLD_MS (default 1s, issue #244), so slow
* requests are greppable/alertable on their own rather than mixed in with
* every other normal-speed request at 'info' level.
*/

const logger = require('../logger');
const config = require('../config');
const logger = require("../logger");
const config = require("../config");

function requestLoggerMiddleware(req, res, next) {
const startedAt = process.hrtime.bigint();
const requestPath = req.baseUrl + req.path;

res.on('finish', () => {
res.on("finish", () => {
const durationMs = Number(process.hrtime.bigint() - startedAt) / 1e6;
const roundedDurationMs = Math.round(durationMs * 100) / 100;
const level = res.statusCode >= 500 ? 'error' : res.statusCode >= 400 ? 'warn' : 'info';
const level =
res.statusCode >= 500 ? "error" : res.statusCode >= 400 ? "warn" : "info";

logger[level]('HTTP request', {
logger[level]("HTTP request", {
method: req.method,
path: req.path,
path: requestPath,
statusCode: res.statusCode,
durationMs: roundedDurationMs,
});
Expand All @@ -43,9 +45,9 @@ function requestLoggerMiddleware(req, res, next) {
// (2xx) request would otherwise only ever appear at 'info' level mixed
// in with every other normal request.
if (durationMs > config.slowRequestThresholdMs) {
logger.warn('Slow request detected', {
logger.warn("Slow request detected", {
method: req.method,
path: req.path,
path: requestPath,
statusCode: res.statusCode,
durationMs: roundedDurationMs,
thresholdMs: config.slowRequestThresholdMs,
Expand Down
17 changes: 9 additions & 8 deletions src/middleware/validate.js
Original file line number Diff line number Diff line change
@@ -1,30 +1,31 @@
'use strict';
"use strict";

const AppError = require('../errors/AppError');
const AppError = require("../errors/AppError");

function flattenZodIssues(error) {
return error.issues.reduce((fields, issue) => {
const path = issue.path.length > 0 ? issue.path.join('.') : '_root';
const path = issue.path.length > 0 ? issue.path.join(".") : "_root";
fields[path] = fields[path] || [];
fields[path].push(issue.message);
return fields;
}, {});
}

function validate(schema, source = 'body') {
function validate(schema, source = "body") {
return (req, _res, next) => {
const result = schema.safeParse(req[source] ?? {});
if (!result.success) {
return next(new AppError('VALIDATION_ERROR', 'Validation failed', 400, {
fields: flattenZodIssues(result.error),
}));
return next(
new AppError("VALIDATION_ERROR", "Validation failed", 400, {
fields: flattenZodIssues(result.error),
}),
);
}

req.validated = {
...(req.validated || {}),
[source]: result.data,
};
req[source] = result.data;
return next();
};
}
Expand Down
43 changes: 26 additions & 17 deletions src/services/dbHealth.js
Original file line number Diff line number Diff line change
@@ -1,25 +1,34 @@
'use strict';
"use strict";

/**
* Lightweight database configuration check.
*
* The database (added for api_key_audit_logs, see migrations) is not yet on
* any live request path — nothing in the app queries it at runtime. So
* `/health` only reports whether a connection string is *configured*
* (via the same resolved config the migration CLI uses, including its
* dev/test defaults) rather than actually opening a connection: attempting
* a real ping here would make `/health` depend on a dependency the app
* doesn't actually use yet, and could flap the endpoint on a DB blip that
* doesn't affect anything real.
*/
const knexFactory = require("knex");
const config = require("../config");

const config = require('../config');
let db = null;

function checkDatabase() {
async function checkDatabase() {
if (!config.databaseUrl) {
return { configured: false, checked: false, status: 'unavailable' };
return { configured: false, checked: false, status: "unavailable" };
}

try {
if (!db) {
db = knexFactory({
client: "pg",
connection: {
connectionString: config.databaseUrl,
connectionTimeoutMillis: 1000,
query_timeout: 1000,
},
acquireConnectionTimeout: 1000,
pool: { min: 0, max: 1 },
});
}

await db.raw("SELECT 1");
return { configured: true, checked: true, status: "ok" };
} catch (_err) {
return { configured: true, checked: true, status: "error" };
}
return { configured: true, checked: false, status: 'unused' };
}

module.exports = { checkDatabase };
57 changes: 23 additions & 34 deletions src/utils/circuitBreaker.js
Original file line number Diff line number Diff line change
@@ -1,11 +1,11 @@
'use strict';
"use strict";

const logger = require('../logger');
const logger = require("../logger");

const STATES = Object.freeze({
CLOSED: 'closed',
OPEN: 'open',
HALF_OPEN: 'half-open',
CLOSED: "closed",
OPEN: "open",
HALF_OPEN: "half-open",
});

class CircuitBreaker {
Expand Down Expand Up @@ -34,36 +34,29 @@ class CircuitBreaker {
}

/**
* Wraps a call in the breaker's failure accounting. `fn` returning
* `null`/`undefined` is treated exactly like a thrown error — it counts
* as a failure and can trip the breaker OPEN.
*
* Contract for callers: only pass `fn` here for a call the wrapped source
* is actually expected to be able to answer. If a source can never serve
* a given request (e.g. an asset it doesn't track at all), that's a
* permanent, per-request condition, not a signal about the source's
* health — decide that *before* calling `call()`, and skip it entirely
* rather than letting a "not supported" response reach here as a `null`.
* priceOracle.js's `fetchFromAllSources` does this via each source's
* `isSupported(assetCode, issuer)` (see #130); any future caller wrapping
* a new per-item resource in a shared breaker should do the same.
* Wraps a call in the breaker's failure accounting. Any resolved value,
* including `null` or `undefined`, is a successful call; only thrown
* errors count as failures.
*/
async call(fn) {
this._moveToHalfOpenIfReady();

if (this.state === STATES.OPEN) {
this._logger.info('Circuit breaker open, skipping source call', {
this._logger.info("Circuit breaker open, skipping source call", {
source: this.name,
state: this.state,
});
return null;
}

if (this.state === STATES.HALF_OPEN && this.halfOpenInFlight) {
this._logger.info('Circuit breaker half-open probe already in flight, skipping source call', {
source: this.name,
state: this.state,
});
this._logger.info(
"Circuit breaker half-open probe already in flight, skipping source call",
{
source: this.name,
state: this.state,
},
);
return null;
}

Expand All @@ -74,11 +67,7 @@ class CircuitBreaker {

try {
const result = await fn();
if (result === null || result === undefined) {
this.recordFailure();
} else {
this.recordSuccess();
}
this.recordSuccess();
return result ?? null;
} catch (err) {
this.recordFailure();
Expand All @@ -94,7 +83,7 @@ class CircuitBreaker {
if (this.state === STATES.HALF_OPEN) {
this.successCount += 1;
if (this.successCount >= this.successThreshold) {
this._transitionTo(STATES.CLOSED, { reason: 'success-threshold' });
this._transitionTo(STATES.CLOSED, { reason: "success-threshold" });
}
return;
}
Expand All @@ -106,20 +95,20 @@ class CircuitBreaker {

recordFailure() {
if (this.state === STATES.HALF_OPEN) {
this._transitionTo(STATES.OPEN, { reason: 'half-open-failure' });
this._transitionTo(STATES.OPEN, { reason: "half-open-failure" });
return;
}

if (this.state === STATES.CLOSED) {
this.failureCount += 1;
if (this.failureCount >= this.failureThreshold) {
this._transitionTo(STATES.OPEN, { reason: 'failure-threshold' });
this._transitionTo(STATES.OPEN, { reason: "failure-threshold" });
}
}
}

reset() {
this._transitionTo(STATES.CLOSED, { reason: 'manual-reset' });
this._transitionTo(STATES.CLOSED, { reason: "manual-reset" });
}

_moveToHalfOpenIfReady() {
Expand All @@ -128,7 +117,7 @@ class CircuitBreaker {
}

if (this._now() - this.openedAt >= this.timeoutMs) {
this._transitionTo(STATES.HALF_OPEN, { reason: 'cooldown-elapsed' });
this._transitionTo(STATES.HALF_OPEN, { reason: "cooldown-elapsed" });
}
}

Expand All @@ -151,7 +140,7 @@ class CircuitBreaker {
this.successCount = 0;
this.openedAt = nextState === STATES.OPEN ? this._now() : null;

this._logger.info('Circuit breaker state changed', {
this._logger.info("Circuit breaker state changed", {
source: this.name,
from: previousState,
to: nextState,
Expand Down
Loading