fix(logger): avoid recursive error handling (#71)

* avoid using log to broadcast its own errors
* move log format into a helper

Author: cdcabrera

src/__tests__/__snapshots__/logger.test.ts.snap

@@ -33,6 +33,16 @@ exports[`createLogger should attempt to subscribe and unsubscribe from a channel
 }
 `;
 
+exports[`formatLogEvent should return a formatted log event, all available fields 1`] = `"[INFO]: lorem ipsum, debug	:1 2 3"`;
+
+exports[`formatLogEvent should return a formatted log event, default 1`] = `"[DEBUG]: lorem ipsum, debug"`;
+
+exports[`formatLogEvent should return a formatted log event, null 1`] = `"[INFO]:"`;
+
+exports[`formatLogEvent should return a formatted log event, partial 1`] = `"[DEBUG]:"`;
+
+exports[`formatLogEvent should return a formatted log event, undefined 1`] = `"[INFO]:"`;
+
 exports[`formatUnknownError should attempt to return a formatted error on non-errors, bigint 1`] = `"9007199254740991n"`;
 
 exports[`formatUnknownError should attempt to return a formatted error on non-errors, boolean 1`] = `"Non-Error thrown: true"`;

src/__tests__/logger.test.ts

@@ -1,6 +1,6 @@
 import diagnostics_channel from 'node:diagnostics_channel';
 import { setOptions, getLoggerOptions } from '../options.context';
-import { logSeverity, truncate, formatUnknownError, publish, subscribeToChannel, registerStderrSubscriber, createLogger } from '../logger';
+import { logSeverity, truncate, formatUnknownError, formatLogEvent, publish, subscribeToChannel, registerStderrSubscriber, createLogger } from '../logger';
 
 describe('logSeverity', () => {
   it.each([
@@ -113,6 +113,47 @@ describe('formatUnknownError', () => {
   });
 });
 
+describe('formatLogEvent', () => {
+  it.each([
+    {
+      description: 'default',
+      event: {
+        level: 'debug',
+        timestamp: new Date('2025-11-01T00:00:00Z'),
+        msg: 'lorem ipsum, debug'
+      }
+    },
+    {
+      description: 'all available fields',
+      event: {
+        level: 'info',
+        timestamp: new Date('2025-11-01T00:00:00.000Z'),
+        msg: 'lorem ipsum, debug',
+        fields: { lorem: 'ipsum dolor sit amet' },
+        source: 'loremIpsum',
+        args: [1, 2, 3],
+        transport: 'dolorSit'
+      }
+    },
+    {
+      description: 'undefined',
+      event: undefined
+    },
+    {
+      description: 'null',
+      event: null
+    },
+    {
+      description: 'partial',
+      event: {
+        level: 'debug'
+      }
+    }
+  ])('should return a formatted log event, $description', ({ event }) => {
+    expect(formatLogEvent(event as any)).toMatchSnapshot();
+  });
+});
+
 describe('publish', () => {
   let channelSpy: jest.SpyInstance;
   const mockPublish = jest.fn();

src/logger.ts

@@ -114,6 +114,29 @@ const formatUnknownError = (value: unknown): string => {
   }
 };
 
+/**
+ * Format a structured log event for output to stderr.
+ *
+ * @param event - Log event to format
+ */
+const formatLogEvent = (event: LogEvent) => {
+  const level = event?.level?.toUpperCase() || 'INFO';
+  const eventLevel = `[${level}]`;
+  const message = event?.msg || '';
+
+  const rest = event?.args?.map(arg => {
+    try {
+      return typeof arg === 'string' ? arg : JSON.stringify(arg);
+    } catch {
+      return String(arg);
+    }
+  }).join(' ') || '';
+
+  const separator = rest ? '\t:' : '';
+
+  return `${eventLevel}: ${message}${separator}${rest}`.trim();
+};
+
 /**
  * Publish a structured log event to the diagnostics channel.
  *
@@ -207,7 +230,7 @@ const subscribeToChannel = (
     try {
       handler.call(null, event);
     } catch (error) {
-      log.debug('Error invoking logging subscriber', event, error);
+      process.stderr.write(`Error invoking logging subscriber: ${formatUnknownError(error)}\n`);
     }
   };
 
@@ -227,28 +250,14 @@ const subscribeToChannel = (
  * @param [formatter] - Optional custom formatter for log events. Default prints: `[LEVEL] msg ...args`
  * @returns Unsubscribe function to remove the subscriber
  */
-const registerStderrSubscriber = (options: LoggingSession, formatter?: (e: LogEvent) => string): Unsubscribe => {
-  const format = formatter || ((event: LogEvent) => {
-    const eventLevel = `[${event.level.toUpperCase()}]`;
-    const message = event.msg || '';
-    const rest = event?.args?.map(arg => {
-      try {
-        return typeof arg === 'string' ? arg : JSON.stringify(arg);
-      } catch {
-        return String(arg);
-      }
-    }).join(' ') || '';
-    const separator = rest ? '\t:' : '';
-
-    return `${eventLevel}: ${message}${separator}${rest}`.trim();
-  });
-
-  return subscribeToChannel((event: LogEvent) => {
-    if (logSeverity(event.level) >= logSeverity(options.level)) {
-      process.stderr.write(`${format(event)}\n`);
-    }
-  });
-};
+const registerStderrSubscriber = (
+  options: LoggingSession,
+  formatter: (e: LogEvent) => string = formatLogEvent
+): Unsubscribe => subscribeToChannel((event: LogEvent) => {
+  if (logSeverity(event.level) >= logSeverity(options.level)) {
+    process.stderr.write(`${formatter(event)}\n`);
+  }
+});
 
 /**
  * Creates a logger initialization function and supports registering logging subscribers.
@@ -268,7 +277,7 @@ const createLogger = (options: LoggingSession = getLoggerOptions()): Unsubscribe
       try {
         unsubscribe();
       } catch (error) {
-        log.debug('Error unsubscribing from diagnostics channel', error);
+        process.stderr.write(`Error unsubscribing from diagnostics channel: ${formatUnknownError(error)}\n`);
       }
     });
 
@@ -279,6 +288,7 @@ const createLogger = (options: LoggingSession = getLoggerOptions()): Unsubscribe
 export {
   LOG_LEVELS,
   createLogger,
+  formatLogEvent,
   formatUnknownError,
   log,
   logSeverity,