diff --git a/package-lock.json b/package-lock.json index c3767fc..62504e4 100644 --- a/package-lock.json +++ b/package-lock.json @@ -4275,7 +4275,7 @@ "version": "7.6.13", "resolved": "https://registry.npmjs.org/@types/better-sqlite3/-/better-sqlite3-7.6.13.tgz", "integrity": "sha512-NMv9ASNARoKksWtsq/SHakpYAYnhBrQgGD8zkLYk/jaK8jUGn08CfEdTRgYhMypUQAfzSP8W6gNLe0q19/t4VA==", - "dev": true, + "devOptional": true, "license": "MIT", "dependencies": { "@types/node": "*" @@ -4476,7 +4476,7 @@ "version": "8.20.0", "resolved": "https://registry.npmjs.org/@types/pg/-/pg-8.20.0.tgz", "integrity": "sha512-bEPFOaMAHTEP1EzpvHTbmwR8UsFyHSKsRisLIHVMXnpNefSbGA1bD6CVy+qKjGSqmZqNqBDV2azOBo8TgkcVow==", - "dev": true, + "devOptional": true, "license": "MIT", "dependencies": { "@types/node": "*", @@ -4498,6 +4498,16 @@ "dev": true, "license": "MIT" }, + "node_modules/@types/react": { + "version": "19.2.17", + "resolved": "https://registry.npmjs.org/@types/react/-/react-19.2.17.tgz", + "integrity": "sha512-MXfmqaVPEVgkBT/aY0aGCkRWWtByiYQXo3xdQ8r5RzuFrPiRn8Gar2tQdXSUQ2GKV3bkXckek89V8wQBY2Q/Aw==", + "license": "MIT", + "peer": true, + "dependencies": { + "csstype": "^3.2.2" + } + }, "node_modules/@types/send": { "version": "1.2.1", "resolved": "https://registry.npmjs.org/@types/send/-/send-1.2.1.tgz", @@ -5892,6 +5902,13 @@ "node": ">= 8" } }, + "node_modules/csstype": { + "version": "3.2.3", + "resolved": "https://registry.npmjs.org/csstype/-/csstype-3.2.3.tgz", + "integrity": "sha512-z1HGKcYy2xA8AGQfwrn0PAy+PB7X/GSj3UVJW9qKyn43xWa+gl5nXmU4qqLMRzWVLFC8KusUX8T/0kCiOYpAIQ==", + "license": "MIT", + "peer": true + }, "node_modules/d": { "version": "1.0.2", "resolved": "https://registry.npmjs.org/d/-/d-1.0.2.tgz", @@ -13037,6 +13054,29 @@ "destr": "^2.0.3" } }, + "node_modules/react": { + "version": "19.2.7", + "resolved": "https://registry.npmjs.org/react/-/react-19.2.7.tgz", + "integrity": "sha512-HNe9WslTbXmFK8o8cmwgAeJFSBvt1bPdHCVKtaaV+WlAN36mpT4hcRpwbf3fY56ar2oIXzsBpOAiIRHAdY0OlQ==", + "license": "MIT", + "peer": true, + "engines": { + "node": ">=0.10.0" + } + }, + "node_modules/react-dom": { + "version": "19.2.7", + "resolved": "https://registry.npmjs.org/react-dom/-/react-dom-19.2.7.tgz", + "integrity": "sha512-t0BRVXvbiE/o20Hfw669rLbMCDWtYZLvmJigy2f0MxsXF+71pxhR3xOkspmsO8h3ZlNzyibAmtCa3l4lYKk6gQ==", + "license": "MIT", + "peer": true, + "dependencies": { + "scheduler": "^0.27.0" + }, + "peerDependencies": { + "react": "^19.2.7" + } + }, "node_modules/react-is": { "version": "18.3.1", "resolved": "https://registry.npmjs.org/react-is/-/react-is-18.3.1.tgz", @@ -13224,6 +13264,13 @@ "integrity": "sha512-YZo3K82SD7Riyi0E1EQPojLz7kpepnSQI9IyPbHHg1XXXevb5dJI7tpyN2ADxGcQbHG7vcyRHk0cbwqcQriUtg==", "license": "MIT" }, + "node_modules/scheduler": { + "version": "0.27.0", + "resolved": "https://registry.npmjs.org/scheduler/-/scheduler-0.27.0.tgz", + "integrity": "sha512-eNv+WrVbKu1f3vbYJT/xtiF5syA5HPIMtf9IgY/nKg0sWqzAUEvqY/xm7OcZc/qafLx/iO9FgOmeSAp4v5ti/Q==", + "license": "MIT", + "peer": true + }, "node_modules/semver": { "version": "7.7.4", "resolved": "https://registry.npmjs.org/semver/-/semver-7.7.4.tgz", @@ -14629,7 +14676,7 @@ "version": "5.9.3", "resolved": "https://registry.npmjs.org/typescript/-/typescript-5.9.3.tgz", "integrity": "sha512-jl1vZzPDinLr9eUt3J/t7V6FgNEw9QjvBPdysz9KfQDD41fQrC2Y4vKQdiaUpFT4bXlb1RHhLpp8wtm6M5TgSw==", - "dev": true, + "devOptional": true, "license": "Apache-2.0", "bin": { "tsc": "bin/tsc", diff --git a/src/app.ts b/src/app.ts index b07ae5f..46fed95 100644 --- a/src/app.ts +++ b/src/app.ts @@ -39,6 +39,7 @@ import { DepositController } from './controllers/depositController.js'; import { VaultController } from './controllers/vaultController.js'; import { TransactionBuilderService } from './services/transactionBuilder.js'; import { requestIdMiddleware } from './middleware/requestId.js'; +import { createMemoryAccountingMiddleware } from './middleware/memoryAccounting.js'; import { validate } from './middleware/validate.js'; import { requestLogger } from './middleware/logging.js'; import { auditEnrichMiddleware } from './middleware/auditEnrich.js'; @@ -146,6 +147,8 @@ export const createApp = (dependencies?: Partial) => { })); app.use(requestIdMiddleware); + const memoryAccountingMiddleware = createMemoryAccountingMiddleware(config.memoryAccounting); + app.use(memoryAccountingMiddleware); app.use(metricsMiddleware); app.use(requestLogger); diff --git a/src/config/env.ts b/src/config/env.ts index 6ff35bb..19f7e3b 100644 --- a/src/config/env.ts +++ b/src/config/env.ts @@ -165,6 +165,13 @@ export const envSchema = z .string() .transform((v) => v === "true") .default(false), + + // Memory accounting + MEMORY_ACCOUNTING_ENABLED: z + .string() + .transform((v) => v === "true") + .default(false), + MEMORY_ACCOUNTING_THRESHOLD_MB: z.coerce.number().nonnegative().default(50), // Test-only chaos harness SOROBAN_CHAOS: z .string() diff --git a/src/config/index.ts b/src/config/index.ts index 90fb885..1d7ba7d 100644 --- a/src/config/index.ts +++ b/src/config/index.ts @@ -209,4 +209,9 @@ export const config = { warmupTimeoutMs: env.LISTINGS_CACHE_WARMUP_TIMEOUT_MS, }, bulkEndpointLimit: env.BULK_ENDPOINT_LIMIT, + + memoryAccounting: { + enabled: env.MEMORY_ACCOUNTING_ENABLED, + thresholdMb: env.MEMORY_ACCOUNTING_THRESHOLD_MB, + }, } as const; diff --git a/src/middleware/memoryAccounting.test.ts b/src/middleware/memoryAccounting.test.ts new file mode 100644 index 0000000..83e3c30 --- /dev/null +++ b/src/middleware/memoryAccounting.test.ts @@ -0,0 +1,228 @@ +import type { Request, Response, NextFunction } from 'express'; +import { EventEmitter } from 'events'; +import { logger } from './logging.js'; +import { createMemoryAccountingMiddleware } from './memoryAccounting.js'; + +describe('createMemoryAccountingMiddleware', () => { + let warnSpy: jest.SpyInstance; + let memoryUsageSpy: jest.SpyInstance; + + beforeEach(() => { + warnSpy = jest.spyOn(logger, 'warn').mockImplementation(() => {}); + memoryUsageSpy = jest.spyOn(process, 'memoryUsage').mockImplementation(() => ({ + heapUsed: 50 * 1024 * 1024, + heapTotal: 100 * 1024 * 1024, + rss: 150 * 1024 * 1024, + arrayBuffers: 0, + external: 0, + })); + }); + + afterEach(() => { + warnSpy.mockRestore(); + memoryUsageSpy.mockRestore(); + }); + + function makeReq(overrides?: Partial): Request { + return { + id: 'test-req-id', + method: 'GET', + path: '/test', + header: jest.fn(), + ...overrides, + } as unknown as Request; + } + + function makeRes(): Response { + const res = new EventEmitter() as unknown as Response; + res.statusCode = 200; + res.setHeader = jest.fn(); + res.getHeader = jest.fn(); + res.headersSent = false; + return res; + } + + describe('when disabled', () => { + test('calls next immediately without attaching finish listener', () => { + const middleware = createMemoryAccountingMiddleware({ enabled: false, thresholdMb: 50 }); + const req = makeReq(); + const res = makeRes(); + const next = jest.fn() as NextFunction; + + const listenerCountBefore = res.listenerCount('finish'); + middleware(req, res, next); + const listenerCountAfter = res.listenerCount('finish'); + + expect(next).toHaveBeenCalledTimes(1); + expect(listenerCountAfter).toBe(listenerCountBefore); + expect(warnSpy).not.toHaveBeenCalled(); + }); + + test('does not sample heap when disabled', () => { + const middleware = createMemoryAccountingMiddleware({ enabled: false, thresholdMb: 50 }); + middleware(makeReq(), makeRes(), jest.fn() as NextFunction); + expect(memoryUsageSpy).not.toHaveBeenCalled(); + }); + }); + + describe('when enabled', () => { + test('calls next and registers finish listener', () => { + const middleware = createMemoryAccountingMiddleware({ enabled: true, thresholdMb: 50 }); + const req = makeReq(); + const res = makeRes(); + const next = jest.fn() as NextFunction; + + middleware(req, res, next); + + expect(next).toHaveBeenCalledTimes(1); + expect(res.listenerCount('finish')).toBe(1); + }); + + test('logs warning when heap delta exceeds threshold', () => { + const middleware = createMemoryAccountingMiddleware({ enabled: true, thresholdMb: 10 }); + const req = makeReq(); + const res = makeRes(); + const next = jest.fn() as NextFunction; + + memoryUsageSpy + .mockReturnValueOnce({ heapUsed: 10 * 1024 * 1024, heapTotal: 50 * 1024 * 1024, rss: 100 * 1024 * 1024, arrayBuffers: 0, external: 0 }) + .mockReturnValueOnce({ heapUsed: 30 * 1024 * 1024, heapTotal: 50 * 1024 * 1024, rss: 100 * 1024 * 1024, arrayBuffers: 0, external: 0 }); + + middleware(req, res, next); + res.emit('finish'); + + expect(warnSpy).toHaveBeenCalledTimes(1); + expect(warnSpy).toHaveBeenCalledWith( + expect.objectContaining({ + requestId: 'test-req-id', + method: 'GET', + path: '/test', + heapDeltaBytes: 20 * 1024 * 1024, + thresholdMb: 10, + }), + 'memory threshold exceeded' + ); + }); + + test('does not log when heap delta is within threshold', () => { + const middleware = createMemoryAccountingMiddleware({ enabled: true, thresholdMb: 50 }); + const req = makeReq(); + const res = makeRes(); + const next = jest.fn() as NextFunction; + + memoryUsageSpy + .mockReturnValueOnce({ heapUsed: 10 * 1024 * 1024, heapTotal: 50 * 1024 * 1024, rss: 100 * 1024 * 1024, arrayBuffers: 0, external: 0 }) + .mockReturnValueOnce({ heapUsed: 20 * 1024 * 1024, heapTotal: 50 * 1024 * 1024, rss: 100 * 1024 * 1024, arrayBuffers: 0, external: 0 }); + + middleware(req, res, next); + res.emit('finish'); + + expect(warnSpy).not.toHaveBeenCalled(); + }); + + test('does not log when heap delta is zero', () => { + const middleware = createMemoryAccountingMiddleware({ enabled: true, thresholdMb: 1 }); + const req = makeReq(); + const res = makeRes(); + const next = jest.fn() as NextFunction; + + memoryUsageSpy + .mockReturnValueOnce({ heapUsed: 25 * 1024 * 1024, heapTotal: 50 * 1024 * 1024, rss: 100 * 1024 * 1024, arrayBuffers: 0, external: 0 }) + .mockReturnValueOnce({ heapUsed: 25 * 1024 * 1024, heapTotal: 50 * 1024 * 1024, rss: 100 * 1024 * 1024, arrayBuffers: 0, external: 0 }); + + middleware(req, res, next); + res.emit('finish'); + + expect(warnSpy).not.toHaveBeenCalled(); + }); + + test('does not log when heap delta is negative (GC reclaimed memory)', () => { + const middleware = createMemoryAccountingMiddleware({ enabled: true, thresholdMb: 1 }); + const req = makeReq(); + const res = makeRes(); + const next = jest.fn() as NextFunction; + + memoryUsageSpy + .mockReturnValueOnce({ heapUsed: 30 * 1024 * 1024, heapTotal: 50 * 1024 * 1024, rss: 100 * 1024 * 1024, arrayBuffers: 0, external: 0 }) + .mockReturnValueOnce({ heapUsed: 10 * 1024 * 1024, heapTotal: 50 * 1024 * 1024, rss: 100 * 1024 * 1024, arrayBuffers: 0, external: 0 }); + + middleware(req, res, next); + res.emit('finish'); + + expect(warnSpy).not.toHaveBeenCalled(); + }); + + test('uses fallback requestId when req.id is not set', () => { + const middleware = createMemoryAccountingMiddleware({ enabled: true, thresholdMb: 0 }); + const req = makeReq({ id: undefined as unknown as string }); + const res = makeRes(); + const next = jest.fn() as NextFunction; + + memoryUsageSpy + .mockReturnValueOnce({ heapUsed: 0, heapTotal: 50 * 1024 * 1024, rss: 100 * 1024 * 1024, arrayBuffers: 0, external: 0 }) + .mockReturnValueOnce({ heapUsed: 10 * 1024 * 1024, heapTotal: 50 * 1024 * 1024, rss: 100 * 1024 * 1024, arrayBuffers: 0, external: 0 }); + + middleware(req, res, next); + res.emit('finish'); + + expect(warnSpy).toHaveBeenCalledWith( + expect.objectContaining({ + requestId: undefined, + heapDeltaBytes: 10 * 1024 * 1024, + }), + 'memory threshold exceeded' + ); + }); + + test('uses req.id as requestId when set', () => { + const middleware = createMemoryAccountingMiddleware({ enabled: true, thresholdMb: 0 }); + const req = makeReq({ id: 'explicit-id' }); + const res = makeRes(); + const next = jest.fn() as NextFunction; + + memoryUsageSpy + .mockReturnValueOnce({ heapUsed: 0, heapTotal: 50 * 1024 * 1024, rss: 100 * 1024 * 1024, arrayBuffers: 0, external: 0 }) + .mockReturnValueOnce({ heapUsed: 5 * 1024 * 1024, heapTotal: 50 * 1024 * 1024, rss: 100 * 1024 * 1024, arrayBuffers: 0, external: 0 }); + + middleware(req, res, next); + res.emit('finish'); + + expect(warnSpy).toHaveBeenCalledWith( + expect.objectContaining({ requestId: 'explicit-id' }), + 'memory threshold exceeded' + ); + }); + + test('warns with threshold of 0 on any positive delta', () => { + const middleware = createMemoryAccountingMiddleware({ enabled: true, thresholdMb: 0 }); + const req = makeReq(); + const res = makeRes(); + const next = jest.fn() as NextFunction; + + memoryUsageSpy + .mockReturnValueOnce({ heapUsed: 10 * 1024 * 1024, heapTotal: 50 * 1024 * 1024, rss: 100 * 1024 * 1024, arrayBuffers: 0, external: 0 }) + .mockReturnValueOnce({ heapUsed: 10 * 1024 * 1024 + 1, heapTotal: 50 * 1024 * 1024, rss: 100 * 1024 * 1024, arrayBuffers: 0, external: 0 }); + + middleware(req, res, next); + res.emit('finish'); + + expect(warnSpy).toHaveBeenCalledTimes(1); + }); + + test('samples heap at start and end of request', () => { + const middleware = createMemoryAccountingMiddleware({ enabled: true, thresholdMb: 50 }); + const req = makeReq(); + const res = makeRes(); + const next = jest.fn() as NextFunction; + + memoryUsageSpy + .mockReturnValueOnce({ heapUsed: 5 * 1024 * 1024, heapTotal: 50 * 1024 * 1024, rss: 100 * 1024 * 1024, arrayBuffers: 0, external: 0 }) + .mockReturnValueOnce({ heapUsed: 10 * 1024 * 1024, heapTotal: 50 * 1024 * 1024, rss: 100 * 1024 * 1024, arrayBuffers: 0, external: 0 }); + + middleware(req, res, next); + res.emit('finish'); + + expect(memoryUsageSpy).toHaveBeenCalledTimes(2); + }); + }); +}); diff --git a/src/middleware/memoryAccounting.ts b/src/middleware/memoryAccounting.ts new file mode 100644 index 0000000..2360830 --- /dev/null +++ b/src/middleware/memoryAccounting.ts @@ -0,0 +1,45 @@ +import type { Request, Response, NextFunction } from 'express'; +import { logger } from './logging.js'; + +export interface MemoryAccountingOptions { + enabled: boolean; + thresholdMb: number; +} + +export function createMemoryAccountingMiddleware(options: MemoryAccountingOptions) { + const { enabled, thresholdMb } = options; + const thresholdBytes = thresholdMb * 1024 * 1024; + + if (!enabled) { + return (_req: Request, _res: Response, next: NextFunction): void => { + next(); + }; + } + + return (req: Request, res: Response, next: NextFunction): void => { + const startHeap = process.memoryUsage().heapUsed; + const requestId = req.id; + + res.on('finish', () => { + const endHeap = process.memoryUsage().heapUsed; + const deltaBytes = endHeap - startHeap; + + if (deltaBytes > thresholdBytes) { + const deltaMb = deltaBytes / (1024 * 1024); + logger.warn( + { + requestId, + method: req.method, + path: req.path, + heapDeltaBytes: deltaBytes, + heapDeltaMb: Number(deltaMb.toFixed(3)), + thresholdMb, + }, + 'memory threshold exceeded' + ); + } + }); + + next(); + }; +}