lib: implement node:logger

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/fs.md

@@ -8563,12 +8563,13 @@ Close the stream gracefully, flushing the internal buffer before closing.
 * `callback` {Function}
   * `err` {Error|null} An error if the flush failed, otherwise `null`.
 
-Writes the current buffer to the file if a write was not in progress. Do
-nothing if `minLength` is zero or if it is already writing.
+Writes the current buffer to the file. The callback is invoked after pending
+writes complete.
 
 #### `utf8Stream.flushSync()`
 
-Flushes the buffered data synchronously. This is a costly operation.
+Flushes the buffered data synchronously. This is a costly operation. An
+`ERR_INVALID_STATE` error is thrown if the stream is currently writing.
 
 #### `utf8Stream.fsync`
 

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)