fix(logging): prevent verbose/debug logs from leaking to Application Insights

providers/logging/winstonConfig.ts

@@ -4,6 +4,8 @@
 import appInsights from 'applicationinsights'
 import config from 'painless-config'
 import winston from 'winston'
+import Transport from 'winston-transport'
+import type { InsightsClient } from '../../lib/mockInsights.ts'
 import { MockInsights } from '../../lib/mockInsights.ts'
 
 const SENSITIVE_HEADERS = ['x-api-key', 'authorization', 'proxy-authorization', 'cookie']
@@ -103,6 +105,47 @@ function buildProperties(info: Record<string, any>): Record<string, any> {
   )
 }
 
+class ApplicationInsightsTransport extends Transport {
+  private aiClient: InsightsClient | null
+
+  constructor(opts: { aiClient: InsightsClient | null; level?: string }) {
+    super({ level: opts.level })
+    this.aiClient = opts.aiClient
+  }
+
+  override log(info: any, callback: () => void): void {
+    setImmediate(() => this.emit('logged', info))
+
+    if (!this.aiClient || !info) {
+      callback()
+      return
+    }
+
+    const properties = buildProperties(info)
+    if (info.level === 'error') {
+      if (info.stack) {
+        const exception = info.cause ? new Error(info.message, { cause: info.cause }) : new Error(info.message)
+        exception.stack = info.stack
+        this.aiClient.trackException({ exception, properties })
+      } else {
+        this.aiClient.trackTrace({
+          message: info.message,
+          severity: appInsights.KnownSeverityLevel.Error,
+          properties
+        })
+      }
+    } else {
+      this.aiClient.trackTrace({
+        message: info.message,
+        severity: mapLevel(info.level),
+        properties
+      })
+    }
+
+    callback()
+  }
+}
+
 /**
  * Factory function to create a Winston logger instance.
  */
@@ -115,20 +158,12 @@ function factory(options?: WinstonLoggerOptions): winston.Logger {
   }
 
   MockInsights.setup(realOptions.connectionString || 'mock', realOptions.echo)
+  const aiClient = MockInsights.getClient()
 
-  const logFormat = winston.format.combine(
-    sanitizeMeta(),
-    winston.format.timestamp(),
-    winston.format.errors({ stack: true, cause: true }),
-    winston.format.printf(({ timestamp, level, message, ...meta }) => {
-      const metaKeys = Object.keys(meta)
-      const metaString = metaKeys.length ? `\n${JSON.stringify(meta, null, 2)}` : ''
-      return `${timestamp} [${level}]: ${message}${metaString}`
-    })
-  )
+  const logFormat = winston.format.combine(sanitizeMeta(), winston.format.errors({ stack: true, cause: true }))
 
   const consoleFormat = winston.format.combine(
-    sanitizeMeta(),
+    winston.format.timestamp(),
     winston.format.colorize(),
     winston.format.printf(({ timestamp, level, message, ...meta }) => {
       const metaKeys = Object.keys(meta)
@@ -144,32 +179,13 @@ function factory(options?: WinstonLoggerOptions): winston.Logger {
       new winston.transports.Console({
         format: consoleFormat,
         silent: !realOptions.echo
+      }),
+      new ApplicationInsightsTransport({
+        aiClient
       })
     ]
   })
 
-  const aiClient = MockInsights.getClient()
-
-  // Pipe Winston logs to Application Insights
-  logger.on('data', info => {
-    const properties = buildProperties(info)
-    if (info.level === 'error') {
-      if (info.stack) {
-        const exception = info.cause ? new Error(info.message, { cause: info.cause }) : new Error(info.message)
-        exception.stack = info.stack
-        aiClient.trackException({ exception, properties })
-      } else {
-        aiClient.trackTrace({
-          message: info.message,
-          severity: appInsights.KnownSeverityLevel.Error,
-          properties
-        })
-      }
-    } else {
-      aiClient.trackTrace({ message: info.message, severity: mapLevel(info.level), properties })
-    }
-  })
-
   return logger
 }
 

test/providers/logging/winstonConfig.ts

@@ -442,4 +442,103 @@ describe('winstonFactory', () => {
     expect(exceptionTelemetry.exception.cause).to.equal(undefined)
     expect(exceptionTelemetry.exception.stack).to.include('no cause error')
   })
+
+  it('does not forward debug or verbose when logger level is info', async () => {
+    const aiClient = {
+      trackException: sinon.stub(),
+      trackTrace: sinon.stub()
+    }
+    sinon.stub(MockInsights, 'setup')
+    sinon.stub(MockInsights, 'getClient').returns(aiClient as any)
+
+    const logger = winstonFactory({
+      connectionString: 'mock',
+      echo: false,
+      level: 'info'
+    })
+
+    logger.debug('debug should not be sent')
+    logger.verbose('verbose should not be sent')
+    logger.info('info should be sent')
+
+    await new Promise(resolve => setImmediate(resolve))
+
+    expect(aiClient.trackException.called).to.be.false
+    expect(aiClient.trackTrace.callCount).to.equal(1)
+    expect(aiClient.trackTrace.firstCall.args[0].message).to.include('info should be sent')
+    expect(aiClient.trackTrace.firstCall.args[0].severity).to.equal('Information')
+  })
+
+  it('routes errors with stack to trackException', async () => {
+    const aiClient = {
+      trackException: sinon.stub(),
+      trackTrace: sinon.stub()
+    }
+    sinon.stub(MockInsights, 'setup')
+    sinon.stub(MockInsights, 'getClient').returns(aiClient as any)
+
+    const logger = winstonFactory({
+      connectionString: 'mock',
+      echo: false,
+      level: 'error'
+    })
+
+    const error = new Error('something broke')
+    logger.error(error)
+
+    await new Promise(resolve => setImmediate(resolve))
+
+    expect(aiClient.trackException.callCount).to.equal(1)
+    expect(aiClient.trackTrace.callCount).to.equal(0)
+    const telemetry = aiClient.trackException.firstCall.args[0]
+    expect(telemetry.exception.message).to.equal('something broke')
+    expect(telemetry.exception.stack).to.include('something broke')
+  })
+
+  it('routes errors without stack to trackTrace with Error severity', async () => {
+    const aiClient = {
+      trackException: sinon.stub(),
+      trackTrace: sinon.stub()
+    }
+    sinon.stub(MockInsights, 'setup')
+    sinon.stub(MockInsights, 'getClient').returns(aiClient as any)
+
+    const logger = winstonFactory({
+      connectionString: 'mock',
+      echo: false,
+      level: 'error'
+    })
+
+    logger.error('plain error message')
+
+    await new Promise(resolve => setImmediate(resolve))
+
+    expect(aiClient.trackException.callCount).to.equal(0)
+    expect(aiClient.trackTrace.callCount).to.equal(1)
+    const telemetry = aiClient.trackTrace.firstCall.args[0]
+    expect(telemetry.message).to.include('plain error message')
+    expect(telemetry.severity).to.equal('Error')
+  })
+
+  it('maps warn level to Warning severity', async () => {
+    const aiClient = {
+      trackException: sinon.stub(),
+      trackTrace: sinon.stub()
+    }
+    sinon.stub(MockInsights, 'setup')
+    sinon.stub(MockInsights, 'getClient').returns(aiClient as any)
+
+    const logger = winstonFactory({
+      connectionString: 'mock',
+      echo: false,
+      level: 'warn'
+    })
+
+    logger.warn('a warning')
+
+    await new Promise(resolve => setImmediate(resolve))
+
+    expect(aiClient.trackTrace.callCount).to.equal(1)
+    expect(aiClient.trackTrace.firstCall.args[0].severity).to.equal('Warning')
+  })
 })