Make Logger obey log level settings (#703)

With this change, log messages can be suppressed if they are at a lower
level than whatever the current log level setting is (i.e., if the
setting is `'error'`, a call to `log.debug(...)` will output nothing).

Currently the log level is set on on the console transport via an argument to `makeConsoleTransport()`.

For backwards compatibility until we decide otherwise, if unspecified
the level defaults to `'debug'`, i.e., always print all log messages.
However, now that we can obey the level setting, we should probably
consider changing the default. We probably should also consider adding
an `'off'` level that suppresses all log output, but for weird
complicated reasons having to do with conflation of the `console` API
with the level name strings that's tricky. (I'd argue that the default
level should either be `'error'` or `'off'`.)

Eventually we will probably also want to read the setting from an
environment variable, but that's an additional bundle of complication
that deserves its own issue.

Closes #679

Author: FUDCo

packages/kernel-agents/test/e2e/agents.test.ts

@@ -1,6 +1,6 @@
 import '@ocap/repo-tools/test-utils/mock-endoify';
 
-import { consoleTransport, Logger } from '@metamask/logger';
+import { makeConsoleTransport, Logger } from '@metamask/logger';
 import { OllamaNodejsService } from '@ocap/kernel-language-model-service/ollama/nodejs';
 import { fetchMock } from '@ocap/repo-tools/test-utils/fetch-mock';
 import {
@@ -25,7 +25,7 @@ import { filterTransports, randomLetter } from '../utils.ts';
 
 const logger = new Logger({
   tags: ['test'],
-  transports: [filterTransports(consoleTransport)],
+  transports: [filterTransports(makeConsoleTransport())],
 });
 
 const makeJsonAgentWithMathCapabilities = (args: MakeAgentArgs) =>

packages/kernel-browser-runtime/test/build-tests.ts

@@ -1,7 +1,6 @@
 import { runTests } from '@ocap/repo-tools/build-utils/test';
 import path from 'node:path';
 
-// eslint-disable-next-line n/no-unsupported-features/node-builtins
 const outDir = path.resolve(import.meta.dirname, '../dist/static');
 
 const untransformedFiles = [

packages/kernel-browser-runtime/vite.config.ts

@@ -29,8 +29,6 @@ const staticCopyTargets: readonly (string | Target)[] = [
   '../../kernel-shims/dist/endoify.js',
 ];
 
-// We will only run this where it's available, but ESLint doesn't know that
-// eslint-disable-next-line n/no-unsupported-features/node-builtins
 const sourceDir = path.resolve(import.meta.dirname, 'src');
 const buildDir = path.resolve(sourceDir, '../dist/static');
 

packages/kernel-test/src/utils.ts

@@ -3,7 +3,11 @@
 
 import type { KernelDatabase } from '@metamask/kernel-store';
 import { stringify, waitUntilQuiescent } from '@metamask/kernel-utils';
-import { Logger, makeArrayTransport, consoleTransport } from '@metamask/logger';
+import {
+  Logger,
+  makeArrayTransport,
+  makeConsoleTransport,
+} from '@metamask/logger';
 import type { LogEntry } from '@metamask/logger';
 import { Kernel, kunser } from '@metamask/ocap-kernel';
 import type { ClusterConfig, PlatformServices } from '@metamask/ocap-kernel';
@@ -193,7 +197,7 @@ export function logDatabase(
 export const makeTestLogger = (): { logger: Logger; entries: LogEntry[] } => {
   const entries: LogEntry[] = [];
   const logger = new Logger({
-    transports: [consoleTransport, makeArrayTransport(entries)],
+    transports: [makeConsoleTransport(), makeArrayTransport(entries)],
   });
   return { logger, entries };
 };

packages/logger/src/constants.ts

@@ -1,2 +1,8 @@
-export const logLevels = ['debug', 'info', 'log', 'warn', 'error'] as const;
+export const logLevels = {
+  debug: 1,
+  info: 2,
+  log: 3,
+  warn: 4,
+  error: 5,
+} as const;
 export const TOKEN_UNDEFINED = 'e790f877-6987-4b06-9ce2-5fc889d5b9ac';

packages/logger/src/index.test.ts

@@ -7,8 +7,8 @@ describe('index', () => {
     expect(Object.keys(indexModule).sort()).toStrictEqual(
       expect.arrayContaining([
         'Logger',
-        'consoleTransport',
         'makeArrayTransport',
+        'makeConsoleTransport',
         'makeStreamTransport',
         'splitLoggerStream',
       ]),

packages/logger/src/index.ts

@@ -1,6 +1,6 @@
 export { Logger } from './logger.ts';
 export {
-  consoleTransport,
+  makeConsoleTransport,
   makeArrayTransport,
   makeStreamTransport,
 } from './transports.ts';

packages/logger/src/logger.test.ts

@@ -2,20 +2,24 @@ import type { DuplexStream } from '@metamask/streams';
 import { delay } from '@ocap/repo-tools/test-utils';
 import { describe, it, expect, vi } from 'vitest';
 
+import { logLevels } from './constants.ts';
 import { Logger } from './logger.ts';
 import { lser } from './stream.ts';
 import type { LogMessage } from './stream.ts';
-import { consoleTransport } from './transports.ts';
+import { makeConsoleTransport } from './transports.ts';
 
 const consoleMethod = ['log', 'debug', 'info', 'warn', 'error'] as const;
-const transports = [consoleTransport];
+const transports = [makeConsoleTransport()];
 
 describe('Logger', () => {
   it.each([
     ['no arguments', undefined],
     ['an empty object', {}],
     ['a string tag', 'test'],
-    ['an options bag', { tags: ['test'], transports: [consoleTransport] }],
+    [
+      'an options bag',
+      { tags: ['test'], transports: [makeConsoleTransport()] },
+    ],
   ])('can be constructed with $description', (_description, options) => {
     const logger = new Logger(options);
     expect(logger).toBeInstanceOf(Logger);
@@ -113,6 +117,27 @@ describe('Logger', () => {
     });
   });
 
+  describe('logging level limits output', () => {
+    consoleMethod.forEach((level) => {
+      it(`logging at level ${level}`, () => {
+        const testLogger = new Logger({
+          transports: [makeConsoleTransport(level)],
+        });
+        consoleMethod.forEach((method) => {
+          const consoleSpy = vi.spyOn(console, method);
+          testLogger[method](`foo ${method}`);
+          if (logLevels[level] <= logLevels[method]) {
+            // eslint-disable-next-line vitest/no-conditional-expect
+            expect(consoleSpy).toHaveBeenCalledWith(`foo ${method}`);
+          } else {
+            // eslint-disable-next-line vitest/no-conditional-expect
+            expect(consoleSpy).not.toHaveBeenCalled();
+          }
+        });
+      });
+    });
+  });
+
   describe('injectStream', () => {
     it('calls drain on the provided stream', () => {
       const logger = new Logger();

packages/logger/src/logger.ts

@@ -89,8 +89,6 @@ export class Logger {
    *   logger's tag.
    * @param options.transports - The transports, which deliver the log messages
    *   to the appropriate destination.
-   * @param options.level - The log level for the logger, used as a default
-   *   argument for the transports.
    * @param options.tags - The tags for the logger, which are accumulated by
    *   sub-loggers and passed to the transports.
    */
@@ -99,16 +97,14 @@ export class Logger {
 
     // Create aliases for the log methods, allowing them to be used in a
     // manner similar to the console object.
-    const bind = (level: LogLevel): LogMethod =>
-      harden(
-        this.#dispatch.bind(this, {
-          ...this.#options,
-          level,
-        }),
+    const bind = (level: LogLevel): LogMethod => {
+      return harden(
+        this.#dispatch.bind(this, { ...this.#options }, level),
       ) as LogMethod;
-    this.log = bind('log');
+    };
     this.debug = bind('debug');
     this.info = bind('info');
+    this.log = bind('log');
     this.warn = bind('warn');
     this.error = bind('error');
   }
@@ -146,13 +142,13 @@ export class Logger {
         const { level, tags, message, data } = lunser(args);
         const logArgs: LogArgs =
           message === undefined ? [] : [message, ...(data ?? [])];
-        this.#dispatch({ level, tags }, ...logArgs);
+        this.#dispatch({ tags }, level, ...logArgs);
       })
       .catch((problem) => onError?.(problem));
   }
 
-  #dispatch(options: LoggerOptions, ...args: LogArgs): void {
-    const { transports, level, tags } = mergeOptions(this.#options, options);
+  #dispatch(options: LoggerOptions, level: LogLevel, ...args: LogArgs): void {
+    const { transports, tags } = mergeOptions(this.#options, options);
     const [message, ...data] = args;
     const entry: LogEntry = harden({ level, tags, message, data });
     transports.forEach((transport) => transport(entry));

packages/logger/src/options.test.ts

@@ -1,25 +1,29 @@
 import { describe, expect, it, vi } from 'vitest';
 
 import { DEFAULT_OPTIONS, mergeOptions, parseOptions } from './options.ts';
-import type { LoggerOptions, LogLevel, Transport } from './types.ts';
+import type { Transport } from './types.ts';
 
 const mocks = vi.hoisted(() => ({
-  consoleTransport: vi.fn(),
+  makeConsoleTransport: vi.fn(),
 }));
 
 vi.mock('./transports.ts', () => ({
-  consoleTransport: mocks.consoleTransport,
+  makeConsoleTransport: mocks.makeConsoleTransport,
 }));
 
 describe('parseOptions', () => {
   it('parses an undefined options bag', () => {
     const options = parseOptions(undefined);
-    expect(options).toStrictEqual({ transports: [mocks.consoleTransport] });
+    expect(options).toStrictEqual({
+      transports: [mocks.makeConsoleTransport()],
+    });
   });
 
   it('parses an empty options bag', () => {
     const options = parseOptions({});
-    expect(options).toStrictEqual({ transports: [mocks.consoleTransport] });
+    expect(options).toStrictEqual({
+      transports: [mocks.makeConsoleTransport()],
+    });
   });
 
   it('parses an options bag', () => {
@@ -38,7 +42,7 @@ describe('parseOptions', () => {
     const options = parseOptions('test');
     expect(options).toStrictEqual({
       tags: ['test'],
-      transports: [mocks.consoleTransport],
+      transports: [mocks.makeConsoleTransport()],
     });
   });
 
@@ -100,19 +104,4 @@ describe('mergeOptions', () => {
       ]);
     },
   );
-
-  it.each([
-    { left: { level: 'warn' }, right: { level: 'error' }, result: 'error' },
-    { left: { level: undefined }, right: { level: 'warn' }, result: 'warn' },
-    { left: { level: 'info' }, right: {}, result: 'info' },
-  ] as { left: LoggerOptions; right: LoggerOptions; result: LogLevel }[])(
-    'merges levels as expected: $left and $right',
-    ({ left, right, result }) => {
-      const options = mergeOptions(
-        { ...left, transports: [] },
-        { ...right, transports: [] },
-      );
-      expect(options.level).toBe(result);
-    },
-  );
 });