diff --git a/lib/services/errorTracker.js b/lib/services/errorTracker.js index 84dcee421..5d0d801c6 100644 --- a/lib/services/errorTracker.js +++ b/lib/services/errorTracker.js @@ -52,6 +52,7 @@ const setupExpressErrorHandler = (app) => { ? String(req.user.id) : 'anonymous'; captureException(err, { distinctId, requestId: req.id }); + if (err && typeof err === 'object') err.posthogCaptured = true; next(err); }); }; diff --git a/lib/services/logger.js b/lib/services/logger.js index 817e54fa1..59fec26af 100644 --- a/lib/services/logger.js +++ b/lib/services/logger.js @@ -3,6 +3,7 @@ import chalk from 'chalk'; import fs from 'fs'; import winston from 'winston'; import config from '../../config/index.js'; +import { PostHogErrorTransport } from './logger.posthog.transport.js'; // list of valid formats for the logging const validFormats = ['combined', 'common', 'dev', 'short', 'tiny', 'custom']; @@ -38,6 +39,10 @@ const logger = new winston.createLogger({ exitOnError: false, }); +if (config?.analytics?.posthog?.errorTracking === true) { + logger.add(new PostHogErrorTransport()); +} + // A stream object with a write function that will call the built-in winston // logger.info() function. // Useful for integrating with stream-related mechanism like Morgan's stream diff --git a/lib/services/logger.posthog.transport.js b/lib/services/logger.posthog.transport.js new file mode 100644 index 000000000..b8c35f6a0 --- /dev/null +++ b/lib/services/logger.posthog.transport.js @@ -0,0 +1,58 @@ +import Transport from 'winston-transport'; +import errorTracker from './errorTracker.js'; + +/** + * Winston transport that forwards `error`-level (and above) logs to + * PostHog Error Tracking via the existing errorTracker service. + * + * 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. + * + * Safe-by-default: the transport's `log()` swallows any throw from + * the underlying capture call so application logging never breaks + * when PostHog is misconfigured or unreachable. + */ +export class PostHogErrorTransport extends Transport { + constructor(opts = {}) { + super({ ...opts, level: opts.level ?? 'error' }); + } + + log(info, callback) { + setImmediate(() => this.emit('logged', info)); + + const sourceErr = info instanceof Error + ? info + : info?.error instanceof Error + ? info.error + : null; + + if (sourceErr?.posthogCaptured) { + callback(); + return; + } + + const err = sourceErr ?? Object.assign( + new Error(info?.message ?? 'logger.error'), + info?.stack ? { stack: info.stack } : {}, + ); + + try { + errorTracker.captureException(err, { + distinctId: info?.distinctId, + requestId: info?.requestId, + properties: { + source: 'system', + logMessage: info?.message, + logLevel: info?.level, + }, + }); + if (sourceErr) sourceErr.posthogCaptured = true; + } catch (_) { /* logging must never break the caller */ } + + callback(); + } +} + +export default PostHogErrorTransport; diff --git a/lib/services/tests/errorTracker.unit.tests.js b/lib/services/tests/errorTracker.unit.tests.js index 83133d469..e7dfbc220 100644 --- a/lib/services/tests/errorTracker.unit.tests.js +++ b/lib/services/tests/errorTracker.unit.tests.js @@ -200,4 +200,29 @@ describe('errorTracker service unit tests:', () => { }); }); }); + + describe('setupExpressErrorHandler — dedup flag:', () => { + test('marks err.posthogCaptured = true after capture so Winston transport skips it', async () => { + jest.unstable_mockModule('../analytics.js', () => ({ + default: { captureException: jest.fn(), init: jest.fn().mockResolvedValue() }, + })); + jest.unstable_mockModule('../../../config/index.js', () => ({ + default: { analytics: { posthog: { enabled: true, key: 'phc_test', errorTracking: true } } }, + })); + const mod = await import('../errorTracker.js'); + const errorTracker = mod.default; + + const handlers = []; + const app = { use: (fn) => handlers.push(fn) }; + errorTracker.setupExpressErrorHandler(app); + + const middleware = handlers[handlers.length - 1]; + const err = new Error('boom'); + const next = jest.fn(); + middleware(err, { user: { _id: 'u1' }, id: 'r1' }, {}, next); + + expect(err.posthogCaptured).toBe(true); + expect(next).toHaveBeenCalledWith(err); + }); + }); }); diff --git a/lib/services/tests/logger.posthog.transport.integration.tests.js b/lib/services/tests/logger.posthog.transport.integration.tests.js new file mode 100644 index 000000000..eae23b888 --- /dev/null +++ b/lib/services/tests/logger.posthog.transport.integration.tests.js @@ -0,0 +1,62 @@ +import { jest, beforeEach, afterEach, describe, test, expect } from '@jest/globals'; + +describe('logger.error → PostHog $exception (integration):', () => { + let logger; + let mockPostHogInstance; + + beforeEach(async () => { + jest.resetModules(); + mockPostHogInstance = { + capture: jest.fn(), + identify: jest.fn(), + groupIdentify: jest.fn(), + getFeatureFlag: jest.fn().mockResolvedValue(undefined), + isFeatureEnabled: jest.fn().mockResolvedValue(undefined), + shutdown: jest.fn().mockResolvedValue(undefined), + }; + jest.unstable_mockModule('posthog-node', () => ({ + PostHog: jest.fn().mockImplementation(() => mockPostHogInstance), + })); + jest.unstable_mockModule('../../../config/index.js', () => ({ + default: { + analytics: { posthog: { enabled: true, key: 'phc_test', host: 'https://eu.i.posthog.com', errorTracking: true, appTag: 'devkit' } }, + logger: { level: 'info' }, + log: { level: 'info', fileLogger: {} }, + }, + })); + + const analyticsMod = await import('../analytics.js'); + await analyticsMod.default.init(); + const loggerMod = await import('../logger.js'); + logger = loggerMod.default ?? loggerMod.logger; + }); + + afterEach(() => { jest.restoreAllMocks(); }); + + test('logger.error(message, { error }) emits a single $exception event', () => { + const err = new Error('payment failed'); + logger.error('Charge failed for user', { error: err }); + expect(mockPostHogInstance.capture).toHaveBeenCalledWith(expect.objectContaining({ + event: '$exception', + properties: expect.objectContaining({ + $exception_message: 'payment failed', + $exception_type: 'Error', + logMessage: 'Charge failed for user', + logLevel: 'error', + source: 'system', + }), + })); + }); + + test('logger.error(err) directly emits a single $exception event', () => { + const err = new Error('boom'); + logger.error(err); + expect(mockPostHogInstance.capture).toHaveBeenCalledTimes(1); + }); + + test('error already marked posthogCaptured does NOT re-emit', () => { + const err = Object.assign(new Error('boom'), { posthogCaptured: true }); + logger.error('skipped', { error: err }); + expect(mockPostHogInstance.capture).not.toHaveBeenCalled(); + }); +}); diff --git a/lib/services/tests/logger.posthog.transport.unit.tests.js b/lib/services/tests/logger.posthog.transport.unit.tests.js new file mode 100644 index 000000000..5ec4aad81 --- /dev/null +++ b/lib/services/tests/logger.posthog.transport.unit.tests.js @@ -0,0 +1,87 @@ +import { jest, beforeEach, afterEach, describe, test, expect } from '@jest/globals'; + +describe('PostHogErrorTransport:', () => { + let PostHogErrorTransport; + let captureExceptionMock; + + beforeEach(async () => { + jest.resetModules(); + captureExceptionMock = jest.fn(); + jest.unstable_mockModule('../errorTracker.js', () => ({ + default: { captureException: captureExceptionMock }, + })); + const mod = await import('../logger.posthog.transport.js'); + PostHogErrorTransport = mod.PostHogErrorTransport; + }); + + afterEach(() => { jest.restoreAllMocks(); }); + + test('only listens at error level by default', () => { + const t = new PostHogErrorTransport(); + expect(t.level).toBe('error'); + }); + + test('forwards info-as-Error to errorTracker.captureException', () => { + const t = new PostHogErrorTransport(); + const err = new Error('boom'); + const cb = jest.fn(); + t.log(err, cb); + expect(captureExceptionMock).toHaveBeenCalledWith(err, expect.objectContaining({ + properties: expect.objectContaining({ source: 'system', logLevel: undefined }), + })); + expect(cb).toHaveBeenCalled(); + }); + + test('extracts info.error when info is a plain object', () => { + const t = new PostHogErrorTransport(); + const err = new Error('boom'); + const info = { level: 'error', message: 'something failed', error: err, requestId: 'r1' }; + const cb = jest.fn(); + t.log(info, cb); + expect(captureExceptionMock).toHaveBeenCalledWith(err, expect.objectContaining({ + requestId: 'r1', + properties: expect.objectContaining({ + source: 'system', + logMessage: 'something failed', + logLevel: 'error', + }), + })); + }); + + test('wraps string-only info into a synthetic Error', () => { + const t = new PostHogErrorTransport(); + const info = { level: 'error', message: 'no error object here' }; + 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('no error object here'); + }); + + test('skips when err.posthogCaptured is true (dedup with express middleware)', () => { + const t = new PostHogErrorTransport(); + const err = Object.assign(new Error('boom'), { posthogCaptured: true }); + const cb = jest.fn(); + t.log(err, cb); + expect(captureExceptionMock).not.toHaveBeenCalled(); + expect(cb).toHaveBeenCalled(); + }); + + test('sets posthogCaptured = true on the source Error after forwarding', () => { + const t = new PostHogErrorTransport(); + const err = new Error('boom'); + const cb = jest.fn(); + t.log(err, cb); + expect(err.posthogCaptured).toBe(true); + }); + + test('callback is always invoked even on captureException throw', () => { + captureExceptionMock.mockImplementation(() => { throw new Error('SDK down'); }); + const t = new PostHogErrorTransport(); + const err = new Error('boom'); + const cb = jest.fn(); + expect(() => t.log(err, cb)).not.toThrow(); + expect(cb).toHaveBeenCalled(); + }); +}); diff --git a/lib/services/tests/logger.posthog.transport.wiring.unit.tests.js b/lib/services/tests/logger.posthog.transport.wiring.unit.tests.js new file mode 100644 index 000000000..f38fe9113 --- /dev/null +++ b/lib/services/tests/logger.posthog.transport.wiring.unit.tests.js @@ -0,0 +1,25 @@ +import { jest, beforeEach, describe, test, expect } from '@jest/globals'; + +describe('logger.js — PostHogErrorTransport wiring:', () => { + beforeEach(() => { jest.resetModules(); }); + + test('PostHogErrorTransport is registered when analytics.posthog.errorTracking=true', async () => { + jest.unstable_mockModule('../../../config/index.js', () => ({ + default: { analytics: { posthog: { errorTracking: true, enabled: true, key: 'phc_test' } }, logger: { level: 'info' }, log: { level: 'info', fileLogger: {} } }, + })); + const mod = await import('../logger.js'); + const logger = mod.default ?? mod.logger; + const hasTransport = logger.transports.some((t) => t.constructor.name === 'PostHogErrorTransport'); + expect(hasTransport).toBe(true); + }); + + test('PostHogErrorTransport is NOT registered when errorTracking=false', async () => { + jest.unstable_mockModule('../../../config/index.js', () => ({ + default: { analytics: { posthog: { errorTracking: false } }, logger: { level: 'info' }, log: { level: 'info', fileLogger: {} } }, + })); + const mod = await import('../logger.js'); + const logger = mod.default ?? mod.logger; + const hasTransport = logger.transports.some((t) => t.constructor.name === 'PostHogErrorTransport'); + expect(hasTransport).toBe(false); + }); +});