diff --git a/doc/api/index.md b/doc/api/index.md index a30724c064e1..b3533dbd9f2e 100644 --- a/doc/api/index.md +++ b/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) diff --git a/doc/api/logger.md b/doc/api/logger.md new file mode 100644 index 000000000000..1c182edea305 --- /dev/null +++ b/doc/api/logger.md @@ -0,0 +1,409 @@ +# Logger + + + + + +> Stability: 1.1 - Active development + + + +The `node:logger` module provides a structured logging facade. A logger composes +log events and passes them to a provider. Providers control filtering, encoding, +buffering, and output. + +```mjs +import { create } from 'node:logger'; + +const logger = create({ name: 'example' }); +logger.info('server started', { port: 3000 }); +``` + +```cjs +const { create } = require('node:logger'); + +const logger = create({ name: 'example' }); +logger.info('server started', { port: 3000 }); +``` + +The module can only be imported using the `node:` scheme. + +## Log events + +Providers receive a log event with the following properties: + +* `timestamp` {number} Milliseconds since the Unix epoch. +* `level` {Object} + * `name` {string} The level name. + * `value` {number} The numeric level value. Larger values are more severe. +* `name` {string|undefined} The logger name. +* `message` {string} The log message. +* `bindings` {Object} Attributes associated with the logger and its parents. +* `attributes` {Object} Attributes supplied for this event. + +The event, level, bindings, and attributes objects are shallowly frozen. Nested +values are not cloned or frozen. Providers must treat the entire event as +read-only and must copy nested values before retaining or modifying them +asynchronously. + +If a direct value of `bindings` or `attributes` is an +[`AsyncLocalStorage`][] instance, the logger replaces it in the event with the +value returned by `asyncLocalStorage.getStore()`. Bound instances are evaluated +for every event, allowing a logger to include the store for the current async +context. Nested `AsyncLocalStorage` instances are not resolved. + +## `logger.create([provider][, options])` + + + +* `provider` {Object} The provider that receives log events. **Default:** A new + [`ConsoleProvider`][]. +* `options` {Object} + * `name` {string} The logger name. + * `bindings` {Object} Attributes included in every event from the logger. + **Default:** `{}`. +* Returns: {Logger} + +Creates a logger. If the first argument does not implement the provider +contract, it is treated as `options`. + +```cjs +const { create, ReadableProvider } = require('node:logger'); + +const defaultLogger = create(); + +const events = new ReadableProvider(); +const streamLogger = create(events, { + name: 'api', + bindings: { service: 'users' }, +}); +``` + +Each call without an explicit provider creates a distinct default provider. + +## Provider contract + +A provider is an object with a synchronous `log(event)` method. It may also +implement `isEnabled(level, context)` to prevent events from being composed: + +```cjs +class CustomProvider { + isEnabled(level, context) { + return level.value >= 30; + } + + log(event) { + // Handle the structured event. + } +} +``` + +The `level` passed to `isEnabled()` is an immutable level descriptor. `context` +contains the logger's `name` and `bindings`. Only an exact `false` return value +disables the event. A provider without `isEnabled()` receives every event. + +Provider methods run synchronously in the logging call. Exceptions propagate to +the caller. A provider that performs asynchronous work must enqueue or copy the +event synchronously. + +## Class: `Logger` + + + +### `new Logger([provider][, options])` + + + +* `provider` {Object} The provider that receives log events. **Default:** A new + [`ConsoleProvider`][]. +* `options` {Object} + * `name` {string} The logger name. + * `bindings` {Object} Attributes included in every event from the logger. + +Equivalent to [`logger.create()`][]. + +### `logger.provider` + + + +* {Object} + +The provider used by the logger. The property is read-only. + +### `logger.name` + + + +* {string|undefined} + +The logger name. + +### `logger.bindings` + + + +* {Object} + +The shallowly frozen bindings associated with the logger. + +### `logger.trace(message[, attributes])` + +### `logger.debug(message[, attributes])` + +### `logger.info(message[, attributes])` + +### `logger.warn(message[, attributes])` + +### `logger.error(message[, attributes])` + +### `logger.fatal(message[, attributes])` + + + +* `message` {string} The log message. +* `attributes` {Object} Attributes associated with this event. **Default:** `{}`. + +Creates a structured event at the corresponding level and passes it to the +provider if the provider enables that level. + +```cjs +logger.info('request completed', { + method: 'GET', + statusCode: 200, +}); +``` + +### `logger.log(level, message[, attributes])` + + + +* `level` {string|Object} A built-in level name or an object containing a + `name` {string} and integer `value` {number}. +* `message` {string} The log message. +* `attributes` {Object} Attributes associated with this event. **Default:** `{}`. + +Creates an event at a built-in or custom level. + +```cjs +logger.log({ name: 'notice', value: 35 }, 'configuration reloaded'); +``` + +### `logger.isEnabled(level)` + + + +* `level` {string|Object} A built-in level name or custom level descriptor. +* Returns: {boolean} + +Returns whether the provider enables the level for this logger. + +### `logger.child(bindings[, options])` + + + +* `bindings` {Object} Additional logger bindings. +* `options` {Object} + * `name` {string} A name for the child. **Default:** The parent logger's name. +* Returns: {Logger} + +Creates a logger that uses the same provider and adds to the parent's bindings. +Child bindings with the same key replace parent bindings. + +## Class: `ConsoleProvider` + + + +The `ConsoleProvider` serializes each event and writes it followed by a newline +using [`fs.Utf8Stream`][]. Events are serialized as JSON by default. + +### `new ConsoleProvider([options])` + + + +* `options` {Object} + * `destination` {string} Either `'stdout'` or `'stderr'`. **Default:** + `'stdout'`. + * `level` {string|Object} The minimum enabled level. **Default:** `'info'`. + * `maxLength` {number} The maximum internal buffer length. Writes that would + exceed this value are dropped. **Default:** `0`, for no limit. + * `minLength` {number} The minimum internal buffer length before an automatic + flush. **Default:** `0`. + * `periodicFlush` {number} The interval in milliseconds at which the stream + is flushed. **Default:** `0`, for no periodic flush. + * `pid` {boolean} Whether to add the process ID as a top-level `pid` property + to serialized records. **Default:** `false`. + * `serializer` {Function} A function that receives a log event and returns a + string. **Default:** [`JSON.stringify()`][]. + * `sync` {boolean} Whether writes are synchronous. **Default:** `false`. + +[`util.inspect()`][] can be used to serialize values that JSON does not support, +including circular references and `BigInt` values: + +```cjs +const { ConsoleProvider, create } = require('node:logger'); +const { inspect } = require('node:util'); + +const logger = create(new ConsoleProvider({ serializer: inspect })); +logger.info('started', { processId: 1n }); +``` + +### `consoleProvider.destination` + + + +* {string} + +The configured destination. + +### `consoleProvider.level` + + + +* {Object} + +The minimum level descriptor. + +### `consoleProvider.pid` + + + +* {boolean} + +Whether serialized records include the process ID. + +### `consoleProvider.serializer` + + + +* {Function} + +The configured serializer. + +### `consoleProvider.stream` + + + +* {fs.Utf8Stream} + +The underlying stream. Its `'drop'` event reports records dropped because of +`maxLength`. + +### `consoleProvider.flush([callback])` + + + +* `callback` {Function} Called when pending writes have completed. + +Flushes pending writes. + +### `consoleProvider.flushSync()` + + + +Synchronously flushes pending writes. + +## Class: `ReadableProvider` + + + +* Extends: {stream.Readable} + +An object-mode [`stream.Readable`][] that emits each enabled log event as a +chunk. + +### `new ReadableProvider([options])` + + + +* `options` {Object} + * `level` {string|Object} The minimum enabled level. **Default:** `'trace'`. + * `highWaterMark` {number} The readable stream high water mark. + +### `readableProvider.level` + + + +* {Object} + +The minimum level descriptor. + +### `readableProvider.close()` + + + +Ends the readable stream. Loggers using the provider stop composing events. + +## `logger.levels` + + + +* {Object} + +Immutable descriptors for the built-in levels: + +| Name | Value | +| ------- | ----: | +| `trace` | 10 | +| `debug` | 20 | +| `info` | 30 | +| `warn` | 40 | +| `error` | 50 | +| `fatal` | 60 | + +[`AsyncLocalStorage`]: async_context.md#class-asynclocalstorage +[`ConsoleProvider`]: #class-consoleprovider +[`JSON.stringify()`]: https://developer.mozilla.org/en-US/docs/Web/JavaScript/Reference/Global_Objects/JSON/stringify +[`fs.Utf8Stream`]: fs.md#class-fsutf8stream +[`logger.create()`]: #loggercreateprovider-options +[`stream.Readable`]: stream.md#class-streamreadable +[`util.inspect()`]: util.md#utilinspectobject-options diff --git a/lib/internal/bootstrap/realm.js b/lib/internal/bootstrap/realm.js index 81ac2a0e398e..2ab1714f6eac 100644 --- a/lib/internal/bootstrap/realm.js +++ b/lib/internal/bootstrap/realm.js @@ -128,6 +128,7 @@ const schemelessBlockList = new SafeSet([ 'bench/reporters', 'dtls', 'ffi', + 'logger', 'sea', 'sqlite', 'quic', diff --git a/lib/logger.js b/lib/logger.js new file mode 100644 index 000000000000..01b9110f8cb2 --- /dev/null +++ b/lib/logger.js @@ -0,0 +1,408 @@ +'use strict'; + +const { + DateNow, + FunctionPrototypeCall, + FunctionPrototypeSymbolHasInstance, + JSONStringify, + ObjectAssign, + ObjectFreeze, + ObjectKeys, + ReflectOwnKeys, +} = primordials; + +const { + codes: { + ERR_INVALID_ARG_TYPE, + ERR_INVALID_RETURN_VALUE, + }, +} = require('internal/errors'); +const { + validateBoolean, + validateFunction, + validateInteger, + validateObject, + validateOneOf, + validateString, +} = require('internal/validators'); +const { emitExperimentalWarning, kEmptyObject } = require('internal/util'); +const Utf8Stream = require('internal/streams/fast-utf8-stream'); +const Readable = require('internal/streams/readable'); +const { AsyncLocalStorage } = require('async_hooks'); + +const kDestinations = ['stdout', 'stderr']; +const kEmptyAttributes = ObjectFreeze({ __proto__: null }); +const kEmptyBindings = ObjectFreeze({ __proto__: null }); + +function createLevel(name, value) { + return ObjectFreeze({ __proto__: null, name, value }); +} + +const levels = ObjectFreeze({ + __proto__: null, + trace: createLevel('trace', 10), + debug: createLevel('debug', 20), + info: createLevel('info', 30), + warn: createLevel('warn', 40), + error: createLevel('error', 50), + fatal: createLevel('fatal', 60), +}); +const kLevelNames = ObjectKeys(levels); + +function normalizeLevel(level, name = 'level') { + if (typeof level === 'string') { + validateOneOf(level, name, kLevelNames); + return levels[level]; + } + + validateObject(level, name); + const { name: levelName, value } = level; + validateString(levelName, `${name}.name`); + validateInteger(value, `${name}.value`); + return createLevel(levelName, value); +} + +function isAsyncLocalStorage(value) { + return value !== null && typeof value === 'object' && + FunctionPrototypeSymbolHasInstance(AsyncLocalStorage, value); +} + +function copyObject(value, resolveStores = false) { + const copy = ObjectAssign({ __proto__: null }, value); + if (resolveStores) { + const keys = ReflectOwnKeys(copy); + for (let i = 0; i < keys.length; i++) { + const key = keys[i]; + const entry = copy[key]; + if (isAsyncLocalStorage(entry)) { + copy[key] = FunctionPrototypeCall(entry.getStore, entry); + } + } + } + return ObjectFreeze(copy); +} + +function hasAsyncLocalStorage(value) { + const keys = ReflectOwnKeys(value); + for (let i = 0; i < keys.length; i++) { + if (isAsyncLocalStorage(value[keys[i]])) { + return true; + } + } + return false; +} + +function isProvider(value) { + return value !== null && + (typeof value === 'object' || typeof value === 'function') && + typeof value.log === 'function'; +} + +function validateProvider(provider) { + if (provider === null || + (typeof provider !== 'object' && typeof provider !== 'function')) { + throw new ERR_INVALID_ARG_TYPE('provider', 'Provider', provider); + } + + validateFunction(provider.log, 'provider.log'); + if (provider.isEnabled !== undefined) { + validateFunction(provider.isEnabled, 'provider.isEnabled'); + } +} + +/** + * A provider that writes newline-delimited JSON to stdout or stderr. + */ +class ConsoleProvider { + #destination; + #level; + #pid; + #serializer; + #stream; + + constructor(options = kEmptyObject) { + validateObject(options, 'options'); + const { + destination = 'stdout', + level = 'info', + maxLength, + minLength, + periodicFlush, + pid = false, + serializer = JSONStringify, + sync, + } = options; + + validateOneOf(destination, 'options.destination', kDestinations); + validateBoolean(pid, 'options.pid'); + validateFunction(serializer, 'options.serializer'); + this.#destination = destination; + this.#level = normalizeLevel(level, 'options.level'); + this.#pid = pid; + this.#serializer = serializer; + this.#stream = new Utf8Stream({ + __proto__: null, + fd: destination === 'stdout' ? 1 : 2, + maxLength, + minLength, + periodicFlush, + sync, + }); + } + + get destination() { + return this.#destination; + } + + get level() { + return this.#level; + } + + get pid() { + return this.#pid; + } + + get serializer() { + return this.#serializer; + } + + get stream() { + return this.#stream; + } + + isEnabled(level) { + return level.value >= this.#level.value; + } + + log(event) { + if (this.isEnabled(event.level)) { + const record = this.#pid ? ObjectFreeze(ObjectAssign( + { __proto__: null }, + event, + { __proto__: null, pid: process.pid }, + )) : event; + const serialized = FunctionPrototypeCall( + this.#serializer, + undefined, + record, + ); + if (typeof serialized !== 'string') { + throw new ERR_INVALID_RETURN_VALUE( + 'a string', + 'serializer', + serialized, + ); + } + this.#stream.write(`${serialized}\n`); + } + } + + flush(callback) { + this.#stream.flush(callback); + } + + flushSync() { + this.#stream.flushSync(); + } +} + +/** + * An object-mode Readable that receives structured log events. + */ +class ReadableProvider extends Readable { + #closed = false; + #level; + + constructor(options = kEmptyObject) { + validateObject(options, 'options'); + const { + highWaterMark, + level = 'trace', + } = options; + const normalizedLevel = normalizeLevel(level, 'options.level'); + + super({ + __proto__: null, + highWaterMark, + objectMode: true, + }); + this.#level = normalizedLevel; + } + + get level() { + return this.#level; + } + + isEnabled(level) { + return !this.#closed && !this.destroyed && + level.value >= this.#level.value; + } + + log(event) { + if (this.isEnabled(event.level)) { + this.push(event); + } + } + + close() { + if (!this.#closed) { + this.#closed = true; + this.push(null); + } + } + + _read() {} +} + +class Logger { + #bindings; + #context; + #hasAsyncLocalStorage; + #name; + #provider; + + constructor(providerOrOptions, options) { + emitExperimentalWarning('Logger'); + + let provider = providerOrOptions; + if (provider === undefined || provider === null) { + provider = new ConsoleProvider(); + } else if (options === undefined && + typeof provider === 'object' && + !isProvider(provider)) { + options = provider; + provider = new ConsoleProvider(); + } + + options ??= kEmptyObject; + validateProvider(provider); + validateObject(options, 'options'); + + const { + bindings = kEmptyBindings, + name, + } = options; + validateObject(bindings, 'options.bindings'); + if (name !== undefined) { + validateString(name, 'options.name'); + } + + this.#provider = provider; + this.#name = name; + this.#bindings = copyObject(bindings); + this.#hasAsyncLocalStorage = hasAsyncLocalStorage(this.#bindings); + this.#context = ObjectFreeze({ + __proto__: null, + bindings: this.#bindings, + name: this.#name, + }); + } + + get provider() { + return this.#provider; + } + + get name() { + return this.#name; + } + + get bindings() { + return this.#bindings; + } + + isEnabled(level) { + return this.#isEnabled(normalizeLevel(level)); + } + + log(level, message, attributes = kEmptyAttributes) { + this.#log(normalizeLevel(level), message, attributes); + } + + trace(message, attributes = kEmptyAttributes) { + this.#log(levels.trace, message, attributes); + } + + debug(message, attributes = kEmptyAttributes) { + this.#log(levels.debug, message, attributes); + } + + info(message, attributes = kEmptyAttributes) { + this.#log(levels.info, message, attributes); + } + + warn(message, attributes = kEmptyAttributes) { + this.#log(levels.warn, message, attributes); + } + + error(message, attributes = kEmptyAttributes) { + this.#log(levels.error, message, attributes); + } + + fatal(message, attributes = kEmptyAttributes) { + this.#log(levels.fatal, message, attributes); + } + + child(bindings, options = kEmptyObject) { + validateObject(bindings, 'bindings'); + validateObject(options, 'options'); + + const { name = this.#name } = options; + if (name !== undefined) { + validateString(name, 'options.name'); + } + + return new Logger(this.#provider, { + __proto__: null, + bindings: ObjectAssign({ __proto__: null }, this.#bindings, bindings), + name, + }); + } + + #isEnabled(level) { + if (this.#provider.isEnabled === undefined) { + return true; + } + return FunctionPrototypeCall( + this.#provider.isEnabled, + this.#provider, + level, + this.#context, + ) !== false; + } + + #log(level, message, attributes) { + if (!this.#isEnabled(level)) { + return; + } + + validateString(message, 'message'); + validateObject(attributes, 'attributes'); + + const event = ObjectFreeze({ + __proto__: null, + attributes: attributes === kEmptyAttributes ? + attributes : copyObject(attributes, true), + bindings: this.#hasAsyncLocalStorage ? + copyObject(this.#bindings, true) : this.#bindings, + level, + message, + name: this.#name, + timestamp: DateNow(), + }); + + FunctionPrototypeCall(this.#provider.log, this.#provider, event); + } +} + +function create(provider, options) { + return new Logger(provider, options); +} + +module.exports = { + __proto__: null, + ConsoleProvider, + Logger, + ReadableProvider, + create, + levels, +}; diff --git a/test/module-hooks/test-module-hooks-builtin-require.js b/test/module-hooks/test-module-hooks-builtin-require.js index e1e137ce1169..3c973e53d641 100644 --- a/test/module-hooks/test-module-hooks-builtin-require.js +++ b/test/module-hooks/test-module-hooks-builtin-require.js @@ -13,6 +13,7 @@ const { registerHooks } = require('module'); const schemelessBlockList = new Set([ 'bench', 'bench/reporters', + 'logger', 'sea', 'test', 'test/reporters', diff --git a/test/module-hooks/test-module-hooks-load-builtin-require.js b/test/module-hooks/test-module-hooks-load-builtin-require.js index 946fc1e48766..00c5678afbe1 100644 --- a/test/module-hooks/test-module-hooks-load-builtin-require.js +++ b/test/module-hooks/test-module-hooks-load-builtin-require.js @@ -37,6 +37,7 @@ hook.deregister(); const schemelessBlockList = new Set([ 'bench', 'bench/reporters', + 'logger', 'sea', 'test', 'test/reporters', diff --git a/test/parallel/test-logger-console-provider.js b/test/parallel/test-logger-console-provider.js new file mode 100644 index 000000000000..65e166998961 --- /dev/null +++ b/test/parallel/test-logger-console-provider.js @@ -0,0 +1,140 @@ +'use strict'; + +require('../common'); +const assert = require('node:assert'); +const { spawnSync } = require('node:child_process'); +const { ConsoleProvider } = require('node:logger'); +const { inspect } = require('node:util'); + +function run(destination, level, statement) { + const script = ` + const { ConsoleProvider, create } = require('node:logger'); + const provider = new ConsoleProvider({ + destination: ${JSON.stringify(destination)}, + level: ${JSON.stringify(level)}, + sync: true, + }); + const logger = create(provider, { + name: 'example', + bindings: { service: 'api' }, + }); + ${statement} + provider.flushSync(); + `; + + return spawnSync(process.execPath, ['--no-warnings', '-e', script], { + encoding: 'utf8', + }); +} + +{ + const result = run( + 'stdout', + 'debug', + "logger.trace('filtered'); logger.info('started', { port: 3000 });", + ); + + assert.strictEqual(result.status, 0); + assert.strictEqual(result.stderr, ''); + const event = JSON.parse(result.stdout); + assert.strictEqual(event.message, 'started'); + assert.strictEqual(event.name, 'example'); + assert.deepStrictEqual(event.level, { name: 'info', value: 30 }); + assert.deepStrictEqual(event.bindings, { service: 'api' }); + assert.deepStrictEqual(event.attributes, { port: 3000 }); + assert.strictEqual(typeof event.timestamp, 'number'); + assert.strictEqual('pid' in event, false); +} + +{ + const script = ` + const { ConsoleProvider, create } = require('node:logger'); + const provider = new ConsoleProvider({ pid: true, sync: true }); + const logger = create(provider); + logger.info('with pid'); + provider.flushSync(); + `; + const result = spawnSync(process.execPath, [ + '--no-warnings', + '-e', + script, + ], { encoding: 'utf8' }); + + assert.strictEqual(result.status, 0); + assert.strictEqual(result.stderr, ''); + const event = JSON.parse(result.stdout); + assert.strictEqual(event.message, 'with pid'); + assert.ok(Number.isInteger(event.pid)); + assert.ok(event.pid > 0); +} + +{ + const result = run( + 'stderr', + 'error', + "logger.warn('filtered'); logger.error('failed');", + ); + + assert.strictEqual(result.status, 0); + assert.strictEqual(result.stdout, ''); + const event = JSON.parse(result.stderr); + assert.strictEqual(event.message, 'failed'); + assert.deepStrictEqual(event.level, { name: 'error', value: 50 }); +} + +{ + const result = run( + 'stdout', + 'trace', + "const value = {}; value.self = value; logger.info('cyclic', value);", + ); + + assert.notStrictEqual(result.status, 0); + assert.match(result.stderr, /circular structure/i); +} + +{ + const script = ` + const { ConsoleProvider, create } = require('node:logger'); + const { inspect } = require('node:util'); + const provider = new ConsoleProvider({ serializer: inspect, sync: true }); + const logger = create(provider); + const cyclic = { value: 1n }; + cyclic.self = cyclic; + logger.info('inspected', { cyclic }); + provider.flushSync(); + `; + const result = spawnSync(process.execPath, [ + '--no-warnings', + '-e', + script, + ], { encoding: 'utf8' }); + + assert.strictEqual(result.status, 0); + assert.strictEqual(result.stderr, ''); + assert.match(result.stdout, /message: 'inspected'/); + assert.match(result.stdout, /value: 1n/); + assert.match(result.stdout, /\[Circular \*\d+\]/); +} + +{ + const provider = new ConsoleProvider({ serializer: inspect }); + assert.strictEqual(provider.serializer, inspect); +} + +assert.throws( + () => new ConsoleProvider({ serializer: 'json' }), + { code: 'ERR_INVALID_ARG_TYPE' }, +); +assert.throws( + () => new ConsoleProvider({ pid: 1 }), + { code: 'ERR_INVALID_ARG_TYPE' }, +); + +{ + const provider = new ConsoleProvider({ serializer: () => null }); + assert.throws( + () => provider.log({ level: { value: 30 } }), + { code: 'ERR_INVALID_RETURN_VALUE' }, + ); +} diff --git a/test/parallel/test-logger.js b/test/parallel/test-logger.js new file mode 100644 index 000000000000..78588f2ab6bf --- /dev/null +++ b/test/parallel/test-logger.js @@ -0,0 +1,223 @@ +'use strict'; + +const common = require('../common'); +const assert = require('node:assert'); +const { AsyncLocalStorage } = require('node:async_hooks'); +const { isBuiltin } = require('node:module'); +const { Readable } = require('node:stream'); +const { + ConsoleProvider, + Logger, + ReadableProvider, + create, + levels, +} = require('node:logger'); + +common.expectWarning( + 'ExperimentalWarning', + 'Logger is an experimental feature and might change at any time', +); + +assert.strictEqual(isBuiltin('node:logger'), true); +assert.strictEqual(isBuiltin('logger'), false); + +{ + const first = create(); + const second = create(); + + assert.ok(first instanceof Logger); + assert.ok(first.provider instanceof ConsoleProvider); + assert.notStrictEqual(first.provider, second.provider); +} + +{ + const events = []; + const contexts = []; + const provider = { + isEnabled(level, context) { + contexts.push(context); + return level.value >= levels.debug.value; + }, + log: common.mustCall(function log(event) { + assert.strictEqual(this, provider); + events.push(event); + }, 2), + }; + const inputBindings = { service: 'api' }; + const logger = create(provider, { + name: 'root', + bindings: inputBindings, + }); + + inputBindings.service = 'changed'; + + assert.strictEqual(logger.provider, provider); + assert.strictEqual(logger.name, 'root'); + assert.deepStrictEqual(logger.bindings, { + __proto__: null, + service: 'api', + }); + assert.strictEqual(Object.isFrozen(logger.bindings), true); + assert.strictEqual(logger.isEnabled('trace'), false); + assert.strictEqual(logger.isEnabled('debug'), true); + + logger.trace('filtered'); + + const inputAttributes = { requestId: 1 }; + logger.info('request received', inputAttributes); + inputAttributes.requestId = 2; + + assert.strictEqual(events.length, 1); + const event = events[0]; + assert.strictEqual(event.message, 'request received'); + assert.strictEqual(event.name, 'root'); + assert.strictEqual(event.level, levels.info); + assert.strictEqual(typeof event.timestamp, 'number'); + assert.deepStrictEqual(event.bindings, { + __proto__: null, + service: 'api', + }); + assert.deepStrictEqual(event.attributes, { + __proto__: null, + requestId: 1, + }); + assert.strictEqual(Object.isFrozen(event), true); + assert.strictEqual(Object.isFrozen(event.attributes), true); + assert.strictEqual(contexts.at(-1).name, 'root'); + + const child = logger.child({ service: 'worker', workerId: 2 }); + assert.strictEqual(child.provider, provider); + assert.strictEqual(child.name, 'root'); + assert.deepStrictEqual(child.bindings, { + __proto__: null, + service: 'worker', + workerId: 2, + }); + + child.log({ name: 'notice', value: 35 }, 'custom level'); + assert.strictEqual(events.length, 2); + assert.deepStrictEqual(events[1].level, { + __proto__: null, + name: 'notice', + value: 35, + }); +} + +{ + const events = []; + const provider = { + log(event) { + events.push(event); + }, + }; + const logger = new Logger(provider); + + logger.fatal('fatal message'); + assert.strictEqual(events.length, 1); + assert.strictEqual(logger.isEnabled('trace'), true); +} + +{ + const bindingStorage = new AsyncLocalStorage(); + const attributeStorage = new AsyncLocalStorage(); + const events = []; + const logger = create({ + log(event) { + events.push(event); + }, + }, { + bindings: { request: bindingStorage }, + }); + + logger.info('outside', { operation: attributeStorage }); + bindingStorage.run({ requestId: 1 }, () => { + attributeStorage.run('create', () => { + logger.info('inside', { operation: attributeStorage }); + }); + }); + bindingStorage.run({ requestId: 2 }, () => { + logger.info('second request'); + }); + + assert.strictEqual(logger.bindings.request, bindingStorage); + assert.strictEqual(events[0].bindings.request, undefined); + assert.strictEqual(events[0].attributes.operation, undefined); + assert.deepStrictEqual(events[1].bindings.request, { requestId: 1 }); + assert.strictEqual(events[1].attributes.operation, 'create'); + assert.deepStrictEqual(events[2].bindings.request, { requestId: 2 }); +} + +{ + const logger = create({ name: 'options-only' }); + assert.strictEqual(logger.name, 'options-only'); + assert.ok(logger.provider instanceof ConsoleProvider); +} + +{ + const provider = new ReadableProvider({ + highWaterMark: 4, + level: 'debug', + }); + const logger = create(provider, { name: 'stream' }); + const events = []; + + assert.ok(provider instanceof Readable); + assert.strictEqual(provider.readableObjectMode, true); + assert.strictEqual(provider.readableHighWaterMark, 4); + + provider.on('data', common.mustCall((event) => { + events.push(event); + }, 2)); + provider.on('end', common.mustCall(() => { + assert.strictEqual(events.length, 2); + assert.strictEqual(events[0].level, levels.debug); + assert.strictEqual(events[1].level, levels.error); + })); + + logger.trace('filtered'); + logger.debug('debug message'); + logger.error('error message'); + provider.close(); + assert.strictEqual(logger.isEnabled('fatal'), false); +} + +assert.throws( + () => create(1), + { code: 'ERR_INVALID_ARG_TYPE' }, +); +assert.throws( + () => create({ log: 'not a function' }, {}), + { code: 'ERR_INVALID_ARG_TYPE' }, +); +assert.throws( + () => create({ log() {}, isEnabled: true }), + { code: 'ERR_INVALID_ARG_TYPE' }, +); +assert.throws( + () => create({ bindings: [] }), + { code: 'ERR_INVALID_ARG_TYPE' }, +); + +{ + const logger = create({ log() {} }); + + assert.throws( + () => logger.info(1), + { code: 'ERR_INVALID_ARG_TYPE' }, + ); + assert.throws( + () => logger.info('message', []), + { code: 'ERR_INVALID_ARG_TYPE' }, + ); + assert.throws( + () => logger.log('unknown', 'message'), + { code: 'ERR_INVALID_ARG_VALUE' }, + ); + assert.throws( + () => logger.log({ name: 'custom', value: 1.5 }, 'message'), + { code: 'ERR_OUT_OF_RANGE' }, + ); +} + +assert.strictEqual(Object.isFrozen(levels), true); +assert.strictEqual(Object.isFrozen(levels.info), true);