diff --git a/MIGRATIONS.md b/MIGRATIONS.md index 78184fde0..1847fec96 100644 --- a/MIGRATIONS.md +++ b/MIGRATIONS.md @@ -4,6 +4,14 @@ Breaking changes and upgrade notes for downstream projects. --- +## errorTracker: 4xx no longer captured; exceptions carry request context (2026-10-30) + +#4241: the Express error middleware (`setupExpressErrorHandler`) now captures only server errors (`err.status || 500` >= 500) — expected 4xx outcomes disappear from PostHog Error Tracking. Each captured exception carries `method`, `endpoint` (route pattern, or the path with secret segments redacted) and `statusCode`, the same names as the `api_request` event. An error with an empty message is captured as an `Error` named ` `. + +No action needed. A dashboard or alert that relied on 4xx exceptions should read `api_request` events instead (`analytics.posthog.autoCapture: true`). + +--- + ## mailer: the 15 shared `config/templates/*.html` mails are now body fragments on the default layout (2026-10-04) #4133: `billing-*`, `org-*`, `referral-reward-earned`, `reset-password-*`, `signup-invite`, `verify-email` and `welcome` are no longer full HTML documents — each is now a body fragment rendered inside the default layout (`_layout/layout.html` + its header/footer/button partials, #4132/#4166), the same mechanism #4164–#4171 already added for a downstream's own templates. diff --git a/lib/helpers/redactUrl.js b/lib/helpers/redactUrl.js index fdb6055cc..e22439f89 100644 --- a/lib/helpers/redactUrl.js +++ b/lib/helpers/redactUrl.js @@ -76,6 +76,9 @@ const SENSITIVE_QUERY_KEYS = [...new Set([...DEFAULT_SENSITIVE_QUERY_KEYS, ...sa */ const SENSITIVE_PATH_MARKERS = [...new Set([...DEFAULT_SENSITIVE_PATH_MARKERS, ...sanitizeConfigList(config?.log?.sensitivePathMarkers, 'log.sensitivePathMarkers')])]; +/** Lowercased lookup for `redactPathSecrets`: both sides compare case-insensitively (Express routes are). */ +const SENSITIVE_PATH_MARKERS_LC = new Set(SENSITIVE_PATH_MARKERS.map((m) => String(m).toLowerCase())); + /** * @desc Redact single-use secrets embedded as PATH parameters. Any segment that * immediately follows a sensitive marker (see `SENSITIVE_PATH_MARKERS`) is @@ -90,13 +93,27 @@ const redactPathSecrets = (path) => { const segments = path.split('/'); for (let i = 0; i < segments.length - 1; i += 1) { - if (SENSITIVE_PATH_MARKERS.includes(segments[i]) && segments[i + 1]) { + if (SENSITIVE_PATH_MARKERS_LC.has(segments[i].toLowerCase()) && segments[i + 1]) { segments[i + 1] = 'REDACTED'; } } return segments.join('/'); }; +/** + * @desc Log-safe endpoint for an Express request. Prefers the matched route + * pattern (`req.baseUrl` + `req.route.path`) so path params collapse to their + * placeholder; falls back to the concrete path (no query string) with secret + * segments redacted (unmatched routes / 404s). A raw `/api/auth/reset/` + * must never reach an analytics or error-tracking store. + * @param {import('express').Request} req - the request + * @returns {String} the route pattern, or the redacted concrete path + */ +const redactRequestPath = (req) => { + if (typeof req?.route?.path === 'string') return `${redactPathSecrets(req.baseUrl || '')}${req.route.path}`; + return redactPathSecrets((req?.originalUrl || req?.url || '').split('?')[0] || '/'); +}; + /** * @desc Redact single-use secrets from a request URL for logging: sensitive * PATH segments (see `redactPathSecrets`) AND sensitive query-string @@ -129,4 +146,4 @@ const redactUrl = (url) => { }; export default redactUrl; -export { SENSITIVE_QUERY_KEYS, SENSITIVE_PATH_MARKERS, redactPathSecrets }; +export { SENSITIVE_QUERY_KEYS, SENSITIVE_PATH_MARKERS, redactPathSecrets, redactRequestPath }; diff --git a/lib/helpers/tests/redactUrl.unit.tests.js b/lib/helpers/tests/redactUrl.unit.tests.js index c3f448392..7e6639dca 100644 --- a/lib/helpers/tests/redactUrl.unit.tests.js +++ b/lib/helpers/tests/redactUrl.unit.tests.js @@ -1,5 +1,5 @@ import { jest, describe, test, expect } from '@jest/globals'; -import redactUrl, { SENSITIVE_QUERY_KEYS, SENSITIVE_PATH_MARKERS, redactPathSecrets } from '../redactUrl.js'; +import redactUrl, { SENSITIVE_QUERY_KEYS, SENSITIVE_PATH_MARKERS, redactPathSecrets, redactRequestPath } from '../redactUrl.js'; import developmentConfig from '../../../config/defaults/development.config.js'; describe('redactUrl', () => { @@ -138,6 +138,31 @@ describe('redactPathSecrets', () => { }); }); +describe('redactRequestPath', () => { + test('prefers the matched route pattern, prefixed with baseUrl', () => { + expect(redactRequestPath({ baseUrl: '/api/auth', route: { path: '/reset/:token' }, originalUrl: '/api/auth/reset/SECRET' })).toBe('/api/auth/reset/:token'); + expect(redactRequestPath({ route: { path: '/api/things/:id' }, originalUrl: '/api/things/42' })).toBe('/api/things/:id'); + }); + + test('redacts a secret carried by a mounted baseUrl', () => { + expect(redactRequestPath({ baseUrl: '/api/auth/reset/SECRET', route: { path: '/' } })).toBe('/api/auth/reset/REDACTED/'); + }); + + test('matches sensitive markers case-insensitively', () => { + expect(redactRequestPath({ originalUrl: '/api/auth/RESET/SECRET' })).toBe('/api/auth/RESET/REDACTED'); + }); + + test('falls back to the redacted concrete path without the query string', () => { + expect(redactRequestPath({ originalUrl: '/api/auth/reset/SECRET?x=1' })).toBe('/api/auth/reset/REDACTED'); + expect(redactRequestPath({ url: '/api/things?page=2' })).toBe('/api/things'); + }); + + test('returns / when the request carries no path', () => { + expect(redactRequestPath({})).toBe('/'); + expect(redactRequestPath(undefined)).toBe('/'); + }); +}); + /** * `SENSITIVE_QUERY_KEYS` / `SENSITIVE_PATH_MARKERS` are read from * `config.log.*` once, at module-evaluation time (#3953), and UNIONED with @@ -177,6 +202,12 @@ describe('redactUrl config sourcing (#3953)', () => { expect(mod.redactPathSecrets('/api/newsletter/promo-opt-out/SECRETTOKEN')).toBe('/api/newsletter/promo-opt-out/REDACTED'); }); + test('a mixed-case config marker redacts regardless of segment case', async () => { + const mod = await loadWithConfig({ log: { sensitivePathMarkers: ['promoOptOut'] } }); + expect(mod.redactPathSecrets('/api/x/promoOptOut/SECRET')).toBe('/api/x/promoOptOut/REDACTED'); + expect(mod.redactPathSecrets('/api/x/promooptout/SECRET')).toBe('/api/x/promooptout/REDACTED'); + }); + test('unions a module-extended query key from config with the built-in defaults', async () => { const mod = await loadWithConfig({ log: { sensitiveQueryKeys: ['magicToken'] }, diff --git a/lib/middlewares/analytics.js b/lib/middlewares/analytics.js index e13d8c366..4976edfb8 100644 --- a/lib/middlewares/analytics.js +++ b/lib/middlewares/analytics.js @@ -3,7 +3,7 @@ */ import AnalyticsService from '../services/analytics.js'; import logger from '../services/logger.js'; -import { redactPathSecrets } from '../helpers/redactUrl.js'; +import { redactRequestPath } from '../helpers/redactUrl.js'; /** * Default route prefixes to skip when auto-capturing API request events. @@ -48,15 +48,10 @@ const createAnalyticsMiddleware = (options = {}) => { const groups = req.organization?._id ? { company: String(req.organization._id) } : undefined; // Never let a single-use secret carried as a PATH parameter (e.g. - // /api/auth/reset/:token) reach the analytics store. Prefer the matched - // route pattern (resolved by the time `finish` fires) so path params - // collapse to their placeholder; fall back to redacting known secret - // segments from the concrete path (unmatched routes / 404s). - const routePath = typeof req.route?.path === 'string' ? req.route.path : null; - const safeEndpoint = routePath ? `${req.baseUrl || ''}${routePath}` : redactPathSecrets(endpoint); - + // /api/auth/reset/:token) reach the analytics store: the matched route + // pattern is resolved by the time `finish` fires (see redactRequestPath). AnalyticsService.track(distinctId, 'api_request', { - endpoint: safeEndpoint, + endpoint: redactRequestPath(req), method: req.method, statusCode: res.statusCode, responseTime: Date.now() - start, diff --git a/lib/services/errorTracker.js b/lib/services/errorTracker.js index 5d0d801c6..589aa0214 100644 --- a/lib/services/errorTracker.js +++ b/lib/services/errorTracker.js @@ -3,6 +3,7 @@ */ import config from '../../config/index.js'; import analyticsService from './analytics.js'; +import { redactRequestPath } from '../helpers/redactUrl.js'; /** * Capture an exception in PostHog. @@ -16,6 +17,7 @@ import analyticsService from './analytics.js'; * @param {Object} [ctx] - Optional context attached to the event * @param {string} [ctx.distinctId] - User identifier for PostHog * @param {string} [ctx.requestId] - Request trace ID + * @param {Object} [ctx.properties] - Additional properties merged into the event * @returns {void} */ const captureException = (err, ctx = {}) => { @@ -38,20 +40,46 @@ const init = async () => { * Set up Express error handling for PostHog Error Tracking. * * Must be called after all routes are mounted. - * Mounts a 4-arg error middleware that captures the exception - * to PostHog and passes it down to the next handler. + * Mounts a 4-arg error middleware that captures server errors (status >= 500) + * to PostHog with the request context (`method`, redacted `endpoint`, + * `statusCode`) and passes the error down to the next handler. Expected 4xx + * outcomes are not captured. An error with no message + * is captured as an `Error` named ` ` so its group + * is readable; the original error is never mutated beyond the dedup flag. + * + * Every error object (4xx included) is flagged `posthogCaptured` so the Winston + * PostHog transport does not capture it again when it is logged downstream. + * A thrown primitive (e.g. a string) cannot carry the flag, so the transport + * may capture it a second time. * * @param {import('express').Express} app - Express application instance */ const setupExpressErrorHandler = (app) => { // `_res` is required for Express to recognise this as a 4-arg error handler app.use((err, req, _res, next) => { - const distinctId = req.user?._id - ? String(req.user._id) - : req.user?.id - ? String(req.user.id) - : 'anonymous'; - captureException(err, { distinctId, requestId: req.id }); + // Same status rule as initErrorRoutes (lib/services/express.js) — + // res.statusCode is not set yet at this point. + const status = err?.status || 500; + if (status >= 500) { + const distinctId = req.user?._id + ? String(req.user._id) + : req.user?.id + ? String(req.user.id) + : 'anonymous'; + const endpoint = redactRequestPath(req); + const target = err?.message + ? err + : Object.assign( + new Error(`${req.method} ${endpoint} ${status}`), + err?.name ? { name: err.name } : {}, + err?.stack ? { stack: err.stack } : {}, + ); + captureException(target, { + distinctId, + requestId: req.id, + properties: { method: req.method, endpoint, statusCode: status }, + }); + } if (err && typeof err === 'object') err.posthogCaptured = true; next(err); }); diff --git a/lib/services/logger.posthog.transport.js b/lib/services/logger.posthog.transport.js index b8c35f6a0..bdecb60b2 100644 --- a/lib/services/logger.posthog.transport.js +++ b/lib/services/logger.posthog.transport.js @@ -7,8 +7,8 @@ import errorTracker from './errorTracker.js'; * * Dedup with the Express 4-arg error middleware: errors that have * already been captured (marked `err.posthogCaptured = true` by - * `errorTracker.setupExpressErrorHandler`) are skipped so the same - * exception doesn't land twice in PostHog. + * `errorTracker.setupExpressErrorHandler`, on Error and non-Error values + * alike) are skipped so the same exception doesn't land twice in PostHog. * * Safe-by-default: the transport's `log()` swallows any throw from * the underlying capture call so application logging never breaks @@ -28,7 +28,7 @@ export class PostHogErrorTransport extends Transport { ? info.error : null; - if (sourceErr?.posthogCaptured) { + if ((sourceErr ?? info?.error)?.posthogCaptured) { callback(); return; } diff --git a/lib/services/tests/errorTracker.unit.tests.js b/lib/services/tests/errorTracker.unit.tests.js index e7dfbc220..523fbda8a 100644 --- a/lib/services/tests/errorTracker.unit.tests.js +++ b/lib/services/tests/errorTracker.unit.tests.js @@ -144,7 +144,7 @@ describe('errorTracker service unit tests:', () => { // Invoke the middleware and verify PostHog is called const err = new Error('express error'); - const req = { user: { _id: 'user-5' }, id: 'req-5' }; + const req = { user: { _id: 'user-5' }, id: 'req-5', method: 'GET', originalUrl: '/api/things?page=2' }; const res = {}; const next = jest.fn(); middleware(err, req, res, next); @@ -152,6 +152,7 @@ describe('errorTracker service unit tests:', () => { expect(mockAnalyticsCapture).toHaveBeenCalledWith(err, { distinctId: 'user-5', requestId: 'req-5', + properties: { method: 'GET', endpoint: '/api/things', statusCode: 500 }, }); expect(next).toHaveBeenCalledWith(err); }); @@ -169,12 +170,13 @@ describe('errorTracker service unit tests:', () => { const middleware = mockApp.use.mock.calls[0][0]; const err = new Error('fallback id test'); - const req = { user: { id: 'user-6' }, id: 'req-6' }; + const req = { user: { id: 'user-6' }, id: 'req-6', method: 'PUT', originalUrl: '/api/things/42' }; middleware(err, req, {}, jest.fn()); expect(mockAnalyticsCapture).toHaveBeenCalledWith(err, { distinctId: 'user-6', requestId: 'req-6', + properties: { method: 'PUT', endpoint: '/api/things/42', statusCode: 500 }, }); }); @@ -191,16 +193,127 @@ describe('errorTracker service unit tests:', () => { const middleware = mockApp.use.mock.calls[0][0]; const err = new Error('anonymous test'); - const req = { user: null, id: 'req-7' }; + const req = { user: null, id: 'req-7', method: 'POST', originalUrl: '/api/things' }; middleware(err, req, {}, jest.fn()); expect(mockAnalyticsCapture).toHaveBeenCalledWith(err, { distinctId: 'anonymous', requestId: 'req-7', + properties: { method: 'POST', endpoint: '/api/things', statusCode: 500 }, }); }); }); + describe('setupExpressErrorHandler — request context:', () => { + /** + * Mount the error middleware with error tracking enabled and return it. + * @returns {Promise} the 4-arg error middleware + */ + const mountMiddleware = async () => { + jest.unstable_mockModule('../../../config/index.js', () => ({ + default: { + analytics: { posthog: { key: 'ph_test_key', errorTracking: true } }, + }, + })); + const { default: errorTracker } = await import('../errorTracker.js'); + const mockApp = { use: jest.fn() }; + errorTracker.setupExpressErrorHandler(mockApp); + return mockApp.use.mock.calls[0][0]; + }; + + test('keeps the original name of an empty-message error', async () => { + const middleware = await mountMiddleware(); + const err = new Error(''); + err.name = 'MongoServerError'; + const req = { user: null, id: 'req-9', method: 'GET', baseUrl: '', route: { path: '/api/things' }, originalUrl: '/api/things' }; + middleware(err, req, {}, jest.fn()); + + const [captured] = mockAnalyticsCapture.mock.calls[0]; + expect(captured).toBeInstanceOf(Error); + expect(captured.name).toBe('MongoServerError'); + expect(captured.message).toBe('GET /api/things 500'); + }); + + test('names an empty-message error after the request and keeps its stack', async () => { + const middleware = await mountMiddleware(); + const err = new Error(''); + const req = { user: null, id: 'req-8', method: 'POST', baseUrl: '', route: { path: '/api/things/:thingId' }, originalUrl: '/api/things/42' }; + const next = jest.fn(); + middleware(err, req, {}, next); + + expect(mockAnalyticsCapture).toHaveBeenCalledTimes(1); + const [captured, ctx] = mockAnalyticsCapture.mock.calls[0]; + expect(captured).not.toBe(err); + expect(captured).toBeInstanceOf(Error); + expect(captured.message).toBe('POST /api/things/:thingId 500'); + expect(captured.stack).toBe(err.stack); + expect(ctx).toEqual({ + distinctId: 'anonymous', + requestId: 'req-8', + properties: { method: 'POST', endpoint: '/api/things/:thingId', statusCode: 500 }, + }); + expect(err.message).toBe(''); + expect(err.posthogCaptured).toBe(true); + expect(next).toHaveBeenCalledWith(err); + }); + + test('captures a non-Error value as a named Error', async () => { + const middleware = await mountMiddleware(); + const err = { status: 502 }; + const req = { id: 'req-9', method: 'GET', originalUrl: '/api/upstream' }; + const next = jest.fn(); + middleware(err, req, {}, next); + + const [captured, ctx] = mockAnalyticsCapture.mock.calls[0]; + expect(captured).not.toBe(err); + expect(captured).toBeInstanceOf(Error); + expect(captured.message).toBe('GET /api/upstream 502'); + expect(ctx.properties).toEqual({ method: 'GET', endpoint: '/api/upstream', statusCode: 502 }); + expect(err.posthogCaptured).toBe(true); + expect(next).toHaveBeenCalledWith(err); + }); + + test('does not capture a 4xx but still flags it and passes it on', async () => { + const middleware = await mountMiddleware(); + const err = Object.assign(new Error('Not Found'), { status: 404 }); + const next = jest.fn(); + middleware(err, { id: 'req-10', method: 'GET', originalUrl: '/api/things/42' }, {}, next); + + expect(mockAnalyticsCapture).not.toHaveBeenCalled(); + expect(err.posthogCaptured).toBe(true); + expect(next).toHaveBeenCalledWith(err); + }); + + test('reports the matched route pattern, not the concrete path', async () => { + const middleware = await mountMiddleware(); + const err = new Error('boom'); + const req = { + id: 'req-11', + method: 'GET', + baseUrl: '/api/auth', + route: { path: '/reset/:token' }, + originalUrl: '/api/auth/reset/SECRETTOKEN', + }; + middleware(err, req, {}, jest.fn()); + + const { endpoint } = mockAnalyticsCapture.mock.calls[0][1].properties; + expect(endpoint).toBe('/api/auth/reset/:token'); + expect(endpoint).not.toContain('SECRETTOKEN'); + }); + + test('redacts a secret path segment when no route matched', async () => { + const middleware = await mountMiddleware(); + const err = new Error(''); + const req = { id: 'req-12', method: 'GET', originalUrl: '/api/auth/reset/SECRETTOKEN?x=1' }; + middleware(err, req, {}, jest.fn()); + + const [captured, ctx] = mockAnalyticsCapture.mock.calls[0]; + expect(ctx.properties.endpoint).toBe('/api/auth/reset/REDACTED'); + expect(captured.message).toBe('GET /api/auth/reset/REDACTED 500'); + expect(captured.message).not.toContain('SECRETTOKEN'); + }); + }); + describe('setupExpressErrorHandler — dedup flag:', () => { test('marks err.posthogCaptured = true after capture so Winston transport skips it', async () => { jest.unstable_mockModule('../analytics.js', () => ({ diff --git a/lib/services/tests/logger.posthog.transport.integration.tests.js b/lib/services/tests/logger.posthog.transport.integration.tests.js index cb203b1d5..27389da42 100644 --- a/lib/services/tests/logger.posthog.transport.integration.tests.js +++ b/lib/services/tests/logger.posthog.transport.integration.tests.js @@ -60,4 +60,9 @@ describe('logger.error → PostHog $exception (integration):', () => { logger.error('skipped', { error: err }); expect(mockPostHogInstance.captureException).not.toHaveBeenCalled(); }); + + test('non-Error error object marked posthogCaptured (e.g. next({ status: 404 })) does NOT re-emit', () => { + logger.error('Unhandled express error', { error: { status: 404, posthogCaptured: true } }); + expect(mockPostHogInstance.captureException).not.toHaveBeenCalled(); + }); }); diff --git a/lib/services/tests/logger.posthog.transport.unit.tests.js b/lib/services/tests/logger.posthog.transport.unit.tests.js index 231e817ce..db6596db1 100644 --- a/lib/services/tests/logger.posthog.transport.unit.tests.js +++ b/lib/services/tests/logger.posthog.transport.unit.tests.js @@ -78,6 +78,27 @@ describe('PostHogErrorTransport:', () => { expect(cb).toHaveBeenCalled(); }); + test('skips when a non-Error info.error carries posthogCaptured (e.g. next({ status: 404 }) already flagged by express middleware)', () => { + const t = new PostHogErrorTransport(); + const info = { level: 'error', message: 'Unhandled express error', error: { status: 404, posthogCaptured: true } }; + const cb = jest.fn(); + t.log(info, cb); + expect(captureExceptionMock).not.toHaveBeenCalled(); + expect(cb).toHaveBeenCalled(); + }); + + test('still captures a non-Error info.error without posthogCaptured as a synthetic Error', () => { + const t = new PostHogErrorTransport(); + const info = { level: 'error', message: 'Unhandled express error', error: { status: 502 } }; + const cb = jest.fn(); + t.log(info, cb); + expect(captureExceptionMock).toHaveBeenCalledTimes(1); + const [err] = captureExceptionMock.mock.calls[0]; + expect(err).toBeInstanceOf(Error); + expect(err.message).toBe('Unhandled express error'); + expect(cb).toHaveBeenCalled(); + }); + test('sets posthogCaptured = true on the source Error after forwarding', () => { const t = new PostHogErrorTransport(); const err = new Error('boom');