lib: implement node:logger

A simpler attempt to add a structured logging API.

Uses a provider model similar to VFS.

This implements two providers out of the box,
ConsoleProvider and ReadableProvider. ConsoleProvider
is the default and uses Utf8Stream to emit to either
stdout or stderr.

```js
const { create } = require('node:logger');
const logger = create(); // default logger to console
logger.info('foo');

// ...
const als = new AsyncLocalStorage();
const logger2 = create(new ConsoleProvider({ pid: true }), {
  name: 'foo',
  bindings: {
    'abc': 'included in every log line',
    'xyz': als,  // current als.getStore() included in
                 // every log line
  }
});
logger2.info('foo', { baz: 1 });
```

The `Logger` keeps things as simple as possible, leaving
actual handling of the log events to the providers, which
can be fully customized. Easy to adapt to other loggers
like pino or extend capabilities without directly touching
the facade.

Signed-off-by: James M Snell <jasnell@gmail.com>
Assisted-by: Opencode

Author: jasnell

benchmark/logger/console-provider.js

@@ -0,0 +1,45 @@
+'use strict';
+
+// End-to-end cost of logging through ConsoleProvider with the default JSON
+// serializer. The provider's stream write() is replaced to avoid I/O latency.
+
+const common = require('../common.js');
+
+const bench = common.createBenchmark(main, {
+  n: [5e5],
+  variant: ['json', 'flatten-pid', 'error'],
+}, {
+  flags: ['--experimental-logger', '--no-warnings'],
+});
+
+function main({ n, variant }) {
+  const { ConsoleProvider, create } = require('node:logger');
+
+  const provider = new ConsoleProvider({
+    flatten: variant === 'flatten-pid',
+    pid: variant === 'flatten-pid',
+  });
+  let bytes = 0;
+  provider.stream.write = (data) => {
+    bytes += data.length;
+    return true;
+  };
+  const logger = create(provider, {
+    name: 'bench',
+    bindings: { service: 'api' },
+  });
+
+  if (variant === 'error') {
+    const err = new Error('boom');
+    err.code = 'E_BOOM';
+    bench.start();
+    for (let i = 0; i < n; i++) logger.error('failed', { err });
+    bench.end(n);
+  } else {
+    bench.start();
+    for (let i = 0; i < n; i++) logger.info('hello', { i, user: 'x' });
+    bench.end(n);
+  }
+
+  if (bytes === 0) throw new Error('nothing was serialized');
+}

benchmark/logger/creation.js

@@ -0,0 +1,34 @@
+'use strict';
+
+// Cost of creating loggers and child loggers.
+
+const common = require('../common.js');
+
+const bench = common.createBenchmark(main, {
+  n: [1e6],
+  type: ['create', 'child'],
+}, {
+  flags: ['--experimental-logger', '--no-warnings'],
+});
+
+function main({ n, type }) {
+  const { ConsoleProvider, create } = require('node:logger');
+
+  const provider = new ConsoleProvider();
+  const parent = create(provider, { name: 'bench' });
+  const loggers = new Array(1024);
+
+  if (type === 'child') {
+    bench.start();
+    for (let i = 0; i < n; i++) {
+      loggers[i & 1023] = parent.child({ requestId: i });
+    }
+    bench.end(n);
+  } else {
+    bench.start();
+    for (let i = 0; i < n; i++) {
+      loggers[i & 1023] = create(provider, { name: 'bench' });
+    }
+    bench.end(n);
+  }
+}

benchmark/logger/disabled.js

@@ -0,0 +1,36 @@
+'use strict';
+
+// Calls to level methods for a level the provider has disabled.
+
+const common = require('../common.js');
+
+const bench = common.createBenchmark(main, {
+  n: [1e8],
+  provider: ['console', 'custom'],
+  attributes: ['none', 'object'],
+  child: [0, 1],
+}, {
+  flags: ['--experimental-logger', '--no-warnings'],
+});
+
+function main({ n, provider, attributes, child }) {
+  const { ConsoleProvider, create } = require('node:logger');
+
+  let logger = create(provider === 'console' ?
+    new ConsoleProvider({ level: 'info' }) :
+    {
+      isEnabled(level) { return level.value >= 30; },
+      log() {},
+    });
+  if (child) logger = logger.child({ requestId: 1 });
+
+  if (attributes === 'object') {
+    bench.start();
+    for (let i = 0; i < n; i++) logger.debug('hello', { i });
+    bench.end(n);
+  } else {
+    bench.start();
+    for (let i = 0; i < n; i++) logger.debug('hello');
+    bench.end(n);
+  }
+}

benchmark/logger/enabled.js

@@ -0,0 +1,50 @@
+'use strict';
+
+// Cost of composing an enabled log event, with a provider that does no work.
+
+const common = require('../common.js');
+
+const bench = common.createBenchmark(main, {
+  n: [1e6],
+  provider: ['minimal', 'custom'],
+  variant: ['no-attributes', 'attributes', 'function-binding'],
+}, {
+  flags: ['--experimental-logger', '--no-warnings'],
+});
+
+function main({ n, provider, variant }) {
+  const { create } = require('node:logger');
+  const { AsyncLocalStorage } = require('node:async_hooks');
+
+  let last;
+  const log = (event) => { last = event; };
+  const als = new AsyncLocalStorage();
+  const bindings = variant === 'function-binding' ?
+    { service: 'api', request: () => als.getStore() } :
+    { service: 'api' };
+  const logger = create(provider === 'minimal' ? { log } : {
+    isEnabled(level) { return level.value >= 30; },
+    log,
+  }, { name: 'bench', bindings });
+
+  switch (variant) {
+    case 'no-attributes':
+      bench.start();
+      for (let i = 0; i < n; i++) logger.info('hello');
+      bench.end(n);
+      break;
+    case 'attributes':
+      bench.start();
+      for (let i = 0; i < n; i++) logger.info('hello', { i, user: 'x' });
+      bench.end(n);
+      break;
+    case 'function-binding':
+      als.enterWith(1);
+      bench.start();
+      for (let i = 0; i < n; i++) logger.info('hello', { i });
+      bench.end(n);
+      break;
+  }
+
+  if (last === undefined) throw new Error('no event was logged');
+}

benchmark/logger/request.js

@@ -0,0 +1,43 @@
+'use strict';
+
+// A child logger per request, logging a few lines through ConsoleProvider.
+// The provider's stream write() is replaced to avoid I/O latency.
+
+const common = require('../common.js');
+
+const bench = common.createBenchmark(main, {
+  n: [5e5],
+  lines: [0, 1, 3],
+  level: ['info', 'debug'],
+}, {
+  flags: ['--experimental-logger', '--no-warnings'],
+});
+
+function main({ n, lines, level }) {
+  const { ConsoleProvider, create } = require('node:logger');
+
+  // With level 'debug' the lines are disabled (the provider is at 'info').
+  const provider = new ConsoleProvider({ level: 'info' });
+  let bytes = 0;
+  provider.stream.write = (data) => {
+    bytes += data.length;
+    return true;
+  };
+  const logger = create(provider, {
+    name: 'bench',
+    bindings: { service: 'api' },
+  });
+
+  bench.start();
+  for (let i = 0; i < n; i++) {
+    const child = logger.child({ requestId: i });
+    for (let j = 0; j < lines; j++) {
+      child[level]('handled', { step: j });
+    }
+  }
+  bench.end(n);
+
+  if (lines > 0 && level === 'info' && bytes === 0) {
+    throw new Error('nothing was serialized');
+  }
+}

doc/api/cli.md

@@ -1545,6 +1545,16 @@ Specify the `module` containing exported [asynchronous module customization hook
 
 This feature requires `--allow-worker` if used with the [Permission Model][].
 
+### `--experimental-logger`
+
+<!-- YAML
+added: REPLACEME
+-->
+
+> Stability: 1.1 - Active development
+
+Enable the experimental [`node:logger`][] module.
+
 ### `--experimental-network-inspection`
 
 <!-- YAML
@@ -4276,6 +4286,7 @@ one is included in the list below.
 * `--experimental-import-text`
 * `--experimental-json-modules`
 * `--experimental-loader`
+* `--experimental-logger`
 * `--experimental-modules`
 * `--experimental-package-map`
 * `--experimental-print-required-tla`
@@ -4961,6 +4972,7 @@ node --stack-trace-limit=12 -p -e "Error.stackTraceLimit" # prints 12
 [`inspector.open()`]: inspector.md#inspectoropenport-host-wait
 [`net.getDefaultAutoSelectFamilyAttemptTimeout()`]: net.md#netgetdefaultautoselectfamilyattempttimeout
 [`node:ffi`]: ffi.md
+[`node:logger`]: logger.md
 [`node:sqlite`]: sqlite.md
 [`node:stream/iter`]: stream_iter.md
 [`node:vfs`]: vfs.md

doc/api/index.md

@@ -36,6 +36,7 @@
 * [Inspector](inspector.md)
 * [Internationalization](intl.md)
 * [Iterable Streams API](stream_iter.md)
+* [Logger](logger.md)
 * [Modules: CommonJS modules](modules.md)
 * [Modules: ECMAScript modules](esm.md)
 * [Modules: `node:module` API](module.md)