diff --git a/README.md b/README.md index 40025a2..3e7f526 100644 --- a/README.md +++ b/README.md @@ -22,7 +22,7 @@ See [Migrating from v1](#migrating-from-v1) at the bottom for breaking changes a Formats are applied in two layers: -- **Logger-level** (applied to all transports, in order): `serializeErrorFormat` → `mapAuditLevelForOtel` (if enabled) → `omitFormat` (if `omitPaths`) → `redactFormat` (if `redactPaths`) → `loggerOptions.format` (if supplied) → `jsonStringifyValuesFormat` (if `flatten`; always last so it captures every prior transformation). +- **Logger-level** (applied to all transports, in order): `serializeErrorFormat` → `mapAuditLevelForOtel` (if enabled) → `omitFormat` (if `omitPaths`) → `redactFormat` (if `redactPaths`) → `loggerOptions.format` (if supplied) → `otelAttributesFormat` (if `flatten: 'otel'`) or `jsonStringifyValuesFormat` (if `flatten: true`); always last so it captures every prior transformation. - **Console transport** (applied to Console output only): `omitNilFormat` → any `consoleFormats` → either `prettyConsoleFormat` (when `consoleFormat: 'pretty'`) or `timestamp` + `json` (when `consoleFormat: 'json'`). ### Options @@ -36,8 +36,8 @@ Formats are applied in two layers: | `omitPaths` | `string[]` | Dot-notation paths to remove from every log entry. Applied at the logger level, so affects all transports. | | `redactPaths` | `string[]` | Dot-notation paths whose values are replaced with `redactedValue`. Applied at the logger level, so affects all transports. | | `redactedValue` | `string` | Replacement value used by `redactPaths`. Defaults to `''`. | -| `flatten` | `boolean` | When `true`, serialises every top-level value on the log info to a JSON string, producing a flat `{ key: string }` shape for transports that expect scalar values. See [OpenTelemetry](#opentelemetry). | -| `flattenReplacer` | `(key, value) => any` | Optional `JSON.stringify` replacer used when `flatten` serialises each top-level value. | +| `flatten` | `boolean \| 'otel'` | Flattens every record as the last logger-level format. `'otel'` produces the attribute shape `@opentelemetry/winston-transport` 0.29 and later needs; `true` serialises every object value to a JSON string, for a transport before 0.29. See [OpenTelemetry](#opentelemetry). | +| `flattenReplacer` | `(key, value) => any` | Optional `JSON.stringify` replacer used by either `flatten` mode for every value it serialises. | | `errorSerializer` | `ErrorSerializer` | Custom serializer applied to every `Error` instance at the logger level (via `serializeErrorFormat`) and as the Console transport's `format.json` replacer. Defaults to the library's `serializeError`, which captures `name`/`message`/`stack`/`code`/`cause`/`errors` even when non-enumerable, walks own enumerable properties, and is safe against circular references. | | `mapAuditLevelForOtel` | `boolean` | When `true`, rewrites the triple-beam `LEVEL` from `audit` to `info` and copies the original onto `logLevel` for OTEL compatibility. See [Shipping the audit level via OpenTelemetry](#shipping-the-audit-level-via-opentelemetry). | | `loggerOptions` | `LoggerOptions` | Winston logger options (e.g. `level`, `defaultMeta`). A `format` supplied here is appended after the library's logger-level formats but still runs before `flatten` when enabled. | @@ -226,23 +226,60 @@ In-flight dispatches are tracked internally and drained via `Promise.allSettled` ## OpenTelemetry -When shipping logs via OpenTelemetry, install [`@opentelemetry/instrumentation-winston`](https://www.npmjs.com/package/@opentelemetry/instrumentation-winston) — it auto-installs [`@opentelemetry/winston-transport`](https://www.npmjs.com/package/@opentelemetry/winston-transport), which forwards each winston record through the OpenTelemetry Logs SDK. Two `createLogger` options shape that pipeline: `flatten: true` is recommended for any OTEL setup, and `mapAuditLevelForOtel: true` when using the default level set (which includes `audit`). +[`@opentelemetry/winston-transport`](https://www.npmjs.com/package/@opentelemetry/winston-transport) forwards each winston record through the OpenTelemetry Logs SDK. Add it yourself, or let [`@opentelemetry/instrumentation-winston`](https://www.npmjs.com/package/@opentelemetry/instrumentation-winston) add it to every logger. Two `createLogger` options shape the records it receives: `flatten`, chosen by transport line below, and `mapAuditLevelForOtel: true` when using the default level set (which includes `audit`). -### Flattening nested metadata +### Flattening for OpenTelemetry -OTEL's log attribute model has historically been flat — the JS API only accepts strings, numbers, booleans, and homogeneous arrays of those as attribute values, so nested objects in winston metadata aren't valid attributes. `@opentelemetry/winston-transport` copies them onto the attribute bag as-is, and downstream handling varies by exporter and backend (some stringify, some drop, some partially walk). +Most backends — Azure Log Analytics included — index only scalar attributes, so a nested value needs to arrive as a JSON string to be queryable. What else the record needs depends on the transport line: -Complex attribute types are landing in the spec ([announced for OTLP 1.9](https://opentelemetry.io/blog/2025/complex-attribute-types/) in 2025) but support is still rolling out across SDKs, and the official guidance is to prefer flat attributes anyway since most backends — Azure Log Analytics included — don't index or query nested values. +| `@opentelemetry/winston-transport` | Matching SDK line | What the transport does | Use | +| ---------------------------------- | ----------------- | ------------------------------------------------------------------------------------------ | ----------------------------------------------- | +| before 0.29 | ≤ 0.218 | Passes every value through as it is | `flatten: true`, or `jsonStringifyValuesFormat` | +| 0.29 – 0.31 | 0.219 – 0.221 | Records an `err`/`error` value as the record's exception; passes every other value through | `flatten: 'otel'`, or `otelAttributesFormat` | +| 0.32 and later | 0.222 and later | As 0.29, and normalises object values into nested map attributes | `flatten: 'otel'`, or `otelAttributesFormat` | -Set `flatten: true` to serialise every top-level value on the log info to a JSON string, producing a flat `{ key: string }` shape that survives the OTEL pipeline cleanly: +From 0.29 the transport gives the logs SDK an `err`/`error` value as the exception, and the SDK keeps only `name`, `message`, `stack` and a cause's message: they become `exception.type`, `exception.message`, `exception.stacktrace` and `error.cause.*`, and every other field of the error is dropped. Two things go wrong without help: + +- **`flatten: true`** turns the error into a JSON string first, and the SDK records the whole string as `exception.message`, with no `exception.type` or stack trace. +- **No flattening** records the exception, but loses the rest of the error — an HTTP status, a provider's error body, the cause chain — and other object values arrive as nested maps. + +`flatten: 'otel'` keeps the error an object with only the fields the SDK reads, moves the rest of it to `errorDetail` as JSON, and serialises every other object value to a JSON string. Scalars are left alone, and a `Date` becomes its ISO string. A provider error logged as `logger.error('Chat failed', { error, request: { route: '/chat' } })` is exported as: ```ts +{ + 'exception.type': 'ProviderError', + 'exception.message': 'Request too large', + 'exception.stacktrace': 'ProviderError: Request too large\n at …', + 'error.cause.type': 'Error', + 'error.cause.message': 'body exceeds limit', + errorDetail: '{"statusCode":413,"data":{"error":{"code":"request_too_large"}},"cause":{…}}', + request: '{"route":"/chat"}', +} +``` + +The SDK takes a truthy `code` over `name` as `exception.type`, so `code` goes to `errorDetail` unless the error has no `name`. + +#### Where to apply it + +`flatten` is a logger-level format, so it changes what every transport receives — the console included. When you construct the OpenTelemetry transport yourself, put the format on that transport instead and the console keeps its nested JSON: + +```ts +import { OpenTelemetryTransportV3 } from '@opentelemetry/winston-transport' +import { createLogger, otelAttributesFormat } from '@makerx/node-winston' + const logger = createLogger({ - flatten: true, + mapAuditLevelForOtel: true, + transports: [new OpenTelemetryTransportV3({ format: otelAttributesFormat() })], }) ``` -Pair with `flattenReplacer` to customise the per-value `JSON.stringify` replacer. +`@opentelemetry/instrumentation-winston` constructs its transport without a format, so with it the logger-level option is the only place to apply one: + +```ts +const logger = createLogger({ flatten: 'otel', mapAuditLevelForOtel: true }) +``` + +Pair either `flatten` mode with `flattenReplacer` to customise the `JSON.stringify` replacer for every value it serialises. ### Shipping the audit level via OpenTelemetry @@ -264,15 +301,16 @@ The format rewrites the triple-beam `LEVEL` symbol from `audit` to `info` (so OT Every format used by `createLogger` is also exported for direct use with your own winston setup. -| Format | Purpose | -| --------------------------- | --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | -| `serializeErrorFormat` | Walks the log info (including nested objects and arrays) and replaces `Error` instances with plain objects that include the normally non-enumerable `message`/`stack`. A record that is itself an error, or holds one under `message`, is nested under `error`. | -| `omitFormat` | Removes fields by dot-notation path via [es-toolkit's compat `omit`](https://es-toolkit.dev/reference/compat/object/omit.html) (lodash-compatible). | -| `omitNilFormat` | Removes top-level `null` or `undefined` values. | -| `redactFormat` | Recursively replaces values at the given paths with `redactedValue` (default `''`). | -| `jsonStringifyValuesFormat` | Serialises every top-level value to a JSON string, producing a flat `{ key: string }` shape. Accepts an optional `replacer`. | -| `prettyConsoleFormat` | Applies `colorize` and `timestamp`, then renders logs as coloured YAML using [`yamlify-object`](https://www.npmjs.com/package/yamlify-object). | -| `mapAuditLevelForOtel` | Rewrites the triple-beam `LEVEL` symbol from `audit` to `info` and copies the original onto `logLevel` so custom levels survive OTEL's severity enumeration. | +| Format | Purpose | +| --------------------------- | ----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | +| `serializeErrorFormat` | Walks the log info (including nested objects and arrays) and replaces `Error` instances with plain objects that include the normally non-enumerable `message`/`stack`. A record that is itself an error, or holds one under `message`, is nested under `error`. | +| `omitFormat` | Removes fields by dot-notation path via [es-toolkit's compat `omit`](https://es-toolkit.dev/reference/compat/object/omit.html) (lodash-compatible). | +| `omitNilFormat` | Removes top-level `null` or `undefined` values. | +| `redactFormat` | Recursively replaces values at the given paths with `redactedValue` (default `''`). | +| `otelAttributesFormat` | Shapes a record into OpenTelemetry log attributes for `@opentelemetry/winston-transport` 0.29 and later: the error stays an object the transport records as the exception, the rest of it goes to `errorDetail`, and every other object value becomes a JSON string. Accepts an optional `replacer`. See [OpenTelemetry](#opentelemetry). | +| `jsonStringifyValuesFormat` | Serialises every top-level value to a JSON string, producing a flat `{ key: string }` shape. Accepts an optional `replacer`. | +| `prettyConsoleFormat` | Applies `colorize` and `timestamp`, then renders logs as coloured YAML using [`yamlify-object`](https://www.npmjs.com/package/yamlify-object). | +| `mapAuditLevelForOtel` | Rewrites the triple-beam `LEVEL` symbol from `audit` to `info` and copies the original onto `logLevel` so custom levels survive OTEL's severity enumeration. | `redactFormat` paths accept plain keys (`email`, matched at every level), dot-notation paths (`user.email`), and `[*]` array wildcards to iterate every element of an array segment — for example `files[*].name`, `users[*].addresses[*].zip`, or `tags[*]` to redact each element of a primitive array. diff --git a/package-lock.json b/package-lock.json index 7710b9e..2fe4e6c 100644 --- a/package-lock.json +++ b/package-lock.json @@ -1,12 +1,12 @@ { "name": "@makerx/node-winston", - "version": "2.2.1", + "version": "2.3.0", "lockfileVersion": 3, "requires": true, "packages": { "": { "name": "@makerx/node-winston", - "version": "2.2.1", + "version": "2.3.0", "license": "MIT", "dependencies": { "@colors/colors": "^1.6.0", @@ -21,6 +21,10 @@ "@makerx/node-common": "^1.5.0", "@makerx/prettier-config": "2.0.1", "@makerx/ts-toolkit": "^5.0.0-beta.0", + "@opentelemetry/api": "^1.9.1", + "@opentelemetry/api-logs": "^0.223.0", + "@opentelemetry/sdk-logs": "^0.223.0", + "@opentelemetry/winston-transport": "^0.34.0", "@rollup/plugin-commonjs": "29.0.2", "@rollup/plugin-typescript": "^12.3.0", "@tsconfig/node20": "20.1.9", @@ -36,6 +40,8 @@ "eslint-plugin-node": "^11.1.0", "eslint-plugin-prettier": "^5.5.5", "npm-run-all": "^4.1.5", + "otel-winston-transport-0.27": "npm:@opentelemetry/winston-transport@^0.27.0", + "otel-winston-transport-0.31": "npm:@opentelemetry/winston-transport@^0.31.0", "rimraf": "^6.1.3", "rollup": "4.60.2", "tslib": "^2.8.1", @@ -958,6 +964,106 @@ "node": ">=20.0" } }, + "node_modules/@opentelemetry/api": { + "version": "1.9.1", + "resolved": "https://registry.npmjs.org/@opentelemetry/api/-/api-1.9.1.tgz", + "integrity": "sha512-gLyJlPHPZYdAk1JENA9LeHejZe1Ti77/pTeFm/nMXmQH/HFZlcS/O2XJB+L8fkbrNSqhdtlvjBVjxwUYanNH5Q==", + "dev": true, + "license": "Apache-2.0", + "engines": { + "node": ">=8.0.0" + } + }, + "node_modules/@opentelemetry/api-logs": { + "version": "0.223.0", + "resolved": "https://registry.npmjs.org/@opentelemetry/api-logs/-/api-logs-0.223.0.tgz", + "integrity": "sha512-Oepm6etVPFCn0VWB1t833iOTgz1eYBDUPxcrOR/XvwzD1+Ag9VzSPSrrKAFNJ/haatj+8CXbG47pZXvdNQKDJw==", + "dev": true, + "license": "Apache-2.0", + "dependencies": { + "@opentelemetry/api": "^1.3.0" + }, + "engines": { + "node": ">=8.0.0" + } + }, + "node_modules/@opentelemetry/core": { + "version": "2.12.0", + "resolved": "https://registry.npmjs.org/@opentelemetry/core/-/core-2.12.0.tgz", + "integrity": "sha512-1HsSAuvT4/my0QrXWsyXFdWjKaPeCHsismKZgEEIb8NK13LP6DrMRlsUbvD/0F9mDWK3xDom9AMv3IscxgOnOQ==", + "dev": true, + "license": "Apache-2.0", + "dependencies": { + "@opentelemetry/semantic-conventions": "^1.29.0" + }, + "engines": { + "node": "^18.19.0 || >=20.6.0" + }, + "peerDependencies": { + "@opentelemetry/api": ">=1.0.0 <1.10.0" + } + }, + "node_modules/@opentelemetry/resources": { + "version": "2.12.0", + "resolved": "https://registry.npmjs.org/@opentelemetry/resources/-/resources-2.12.0.tgz", + "integrity": "sha512-+rSRoOdln6NhXTVcBdHSlZxJDNzwxadeweK2ltZO3tVtfp6aklABc06xclDk6ovRR+EiGgIcSbh/6NgjFhnb3A==", + "dev": true, + "license": "Apache-2.0", + "dependencies": { + "@opentelemetry/core": "2.12.0", + "@opentelemetry/semantic-conventions": "^1.29.0" + }, + "engines": { + "node": "^18.19.0 || >=20.6.0" + }, + "peerDependencies": { + "@opentelemetry/api": ">=1.3.0 <1.10.0" + } + }, + "node_modules/@opentelemetry/sdk-logs": { + "version": "0.223.0", + "resolved": "https://registry.npmjs.org/@opentelemetry/sdk-logs/-/sdk-logs-0.223.0.tgz", + "integrity": "sha512-ApiAfUiUh6fmJt1GbsBuoeDn8D8IL42UvGyPUr8o1Z89ZeIiOCE1rZ78KkIUjEX3OV8Oorl9ez5Qjo43ZynDyw==", + "dev": true, + "license": "Apache-2.0", + "dependencies": { + "@opentelemetry/api-logs": "0.223.0", + "@opentelemetry/core": "2.12.0", + "@opentelemetry/resources": "2.12.0", + "@opentelemetry/semantic-conventions": "^1.29.0" + }, + "engines": { + "node": "^18.19.0 || >=20.6.0" + }, + "peerDependencies": { + "@opentelemetry/api": ">=1.4.0 <1.10.0" + } + }, + "node_modules/@opentelemetry/semantic-conventions": { + "version": "1.43.0", + "resolved": "https://registry.npmjs.org/@opentelemetry/semantic-conventions/-/semantic-conventions-1.43.0.tgz", + "integrity": "sha512-eSYWTm620tTk45EKSedaUL8MFYI8hW164hIXsgIHyxu3VobUB3fFCu5t0hQby6OoWRPsG1KkKUG2M5UadiLiVg==", + "dev": true, + "license": "Apache-2.0", + "engines": { + "node": ">=14" + } + }, + "node_modules/@opentelemetry/winston-transport": { + "version": "0.34.0", + "resolved": "https://registry.npmjs.org/@opentelemetry/winston-transport/-/winston-transport-0.34.0.tgz", + "integrity": "sha512-0bfxiBP9KhPd1rKT4hf2ANrEqNW2QaN9N87rDBUzDJB14kztugWNT+1q0seix04PlbzqxAc0jJpOBmoyoY4E/Q==", + "dev": true, + "license": "Apache-2.0", + "dependencies": { + "@opentelemetry/api-logs": "^0.223.0", + "@opentelemetry/semantic-conventions": "^1.41.1", + "winston-transport": "4.*" + }, + "engines": { + "node": "^18.19.0 || >=20.6.0" + } + }, "node_modules/@oxc-project/types": { "version": "0.154.0", "resolved": "https://registry.npmjs.org/@oxc-project/types/-/types-0.154.0.tgz", @@ -1899,8 +2005,7 @@ "version": "1.3.5", "resolved": "https://registry.npmjs.org/@types/triple-beam/-/triple-beam-1.3.5.tgz", "integrity": "sha512-6WaYesThRMCl19iryMYP7/x2OVgCtbIVflDGFpWnb9irXI3UjYE4AzmYuiUKY1AJstGijoY+MgUszMgRxIYTYw==", - "license": "MIT", - "peer": true + "license": "MIT" }, "node_modules/@typescript-eslint/eslint-plugin": { "version": "8.58.1", @@ -3875,8 +3980,7 @@ "version": "4.2.3", "resolved": "https://registry.npmjs.org/fecha/-/fecha-4.2.3.tgz", "integrity": "sha512-OP2IUU6HeYKJi3i0z4A19kHMQoLVs4Hc+DPqqxI2h/DPZHTm/vjsfC6P0b4jCMy14XizLBqvndQ+UilD7707Jw==", - "license": "MIT", - "peer": true + "license": "MIT" }, "node_modules/fflate": { "version": "0.8.3", @@ -5302,7 +5406,6 @@ "resolved": "https://registry.npmjs.org/logform/-/logform-2.7.0.tgz", "integrity": "sha512-TFYA4jnP7PVbmlBIfhlSe+WKxs9dklXMTEGcBCIvLhE/Tn3H6Gk1norupVW7m5Cnd4bLcr08AytbyV/xj7f/kQ==", "license": "MIT", - "peer": true, "dependencies": { "@colors/colors": "1.6.0", "@types/triple-beam": "^1.3.2", @@ -5897,6 +6000,63 @@ "node": ">= 0.8.0" } }, + "node_modules/otel-winston-transport-0.27": { + "name": "@opentelemetry/winston-transport", + "version": "0.27.0", + "resolved": "https://registry.npmjs.org/@opentelemetry/winston-transport/-/winston-transport-0.27.0.tgz", + "integrity": "sha512-Imeoqm9CqxSJRo6INwtOn1Kx2XXYZzkyrH6q2teIDJ7ZypKx7DRf23l5ylQZ3vYibkcCLIANbzpeMqCNPp4CEw==", + "dev": true, + "license": "Apache-2.0", + "dependencies": { + "@opentelemetry/api-logs": "^0.217.0", + "winston-transport": "4.*" + }, + "engines": { + "node": "^18.19.0 || >=20.6.0" + } + }, + "node_modules/otel-winston-transport-0.27/node_modules/@opentelemetry/api-logs": { + "version": "0.217.0", + "resolved": "https://registry.npmjs.org/@opentelemetry/api-logs/-/api-logs-0.217.0.tgz", + "integrity": "sha512-Cdq0jW2lknrNfrAm92MyEAvpe2cRsKjdnQLHUL6xRA4IVUnsWx6P65E7NcUO0Y+L4w1Aee5iV8FvjSwd+lrs9A==", + "dev": true, + "license": "Apache-2.0", + "dependencies": { + "@opentelemetry/api": "^1.3.0" + }, + "engines": { + "node": ">=8.0.0" + } + }, + "node_modules/otel-winston-transport-0.31": { + "name": "@opentelemetry/winston-transport", + "version": "0.31.0", + "resolved": "https://registry.npmjs.org/@opentelemetry/winston-transport/-/winston-transport-0.31.0.tgz", + "integrity": "sha512-higyMoGHbDTNlCX5ue1dJjDQuYSWwC0L4k6x57RKLG0uXdCIdyIu/OQYnjciL+7Kv2XmPMy4VQloeh36NTJTuQ==", + "dev": true, + "license": "Apache-2.0", + "dependencies": { + "@opentelemetry/api-logs": "^0.221.0", + "@opentelemetry/semantic-conventions": "^1.41.1", + "winston-transport": "4.*" + }, + "engines": { + "node": "^18.19.0 || >=20.6.0" + } + }, + "node_modules/otel-winston-transport-0.31/node_modules/@opentelemetry/api-logs": { + "version": "0.221.0", + "resolved": "https://registry.npmjs.org/@opentelemetry/api-logs/-/api-logs-0.221.0.tgz", + "integrity": "sha512-OlanaW1vv7ufTqQ3/fPLI4arGt5ZoM+P8abOMki6uEYnpRazepSWDwDnnw+la7kE26SHVC18//SMccrDvLKOXQ==", + "dev": true, + "license": "Apache-2.0", + "dependencies": { + "@opentelemetry/api": "^1.3.0" + }, + "engines": { + "node": ">=8.0.0" + } + }, "node_modules/own-keys": { "version": "1.0.1", "resolved": "https://registry.npmjs.org/own-keys/-/own-keys-1.0.1.tgz", @@ -6597,7 +6757,6 @@ "resolved": "https://registry.npmjs.org/safe-stable-stringify/-/safe-stable-stringify-2.5.0.tgz", "integrity": "sha512-b3rppTKm9T+PsVCBEOUR46GWI7fdOs00VKZ1+9c1EWDaDMvjQc6tUwuFyIprgGgTcWoVHSKrU8H31ZHA2e0RHA==", "license": "MIT", - "peer": true, "engines": { "node": ">=10" } @@ -7270,7 +7429,6 @@ "resolved": "https://registry.npmjs.org/triple-beam/-/triple-beam-1.4.1.tgz", "integrity": "sha512-aZbgViZrg1QNcG+LULa7nhZpJTZSLm/mXnHXnbAbjmN5aSa0y7V+wvv6+4WaBtpISJzThKy+PIPxc1Nq1EJ9mg==", "license": "MIT", - "peer": true, "engines": { "node": ">= 14.0.0" } @@ -7833,7 +7991,6 @@ "resolved": "https://registry.npmjs.org/winston-transport/-/winston-transport-4.9.0.tgz", "integrity": "sha512-8drMJ4rkgaPo1Me4zD/3WLfI/zPdA9o2IipKODunnGDcuqbHwjsbB79ylv04LCGGzU0xQ6vTznOMpQGaLhhm6A==", "license": "MIT", - "peer": true, "dependencies": { "logform": "^2.7.0", "readable-stream": "^3.6.2", @@ -7848,7 +8005,6 @@ "resolved": "https://registry.npmjs.org/readable-stream/-/readable-stream-3.6.2.tgz", "integrity": "sha512-9u/sniCrY3D5WdsERHzHE4G2YCXqoG5FTHUiCC4SIbr6XcLZBY05ya9EKjYek9O5xOAwjGq+1JdGBAS7Q9ScoA==", "license": "MIT", - "peer": true, "dependencies": { "inherits": "^2.0.3", "string_decoder": "^1.1.1", @@ -7876,15 +8032,13 @@ "url": "https://feross.org/support" } ], - "license": "MIT", - "peer": true + "license": "MIT" }, "node_modules/winston-transport/node_modules/string_decoder": { "version": "1.3.0", "resolved": "https://registry.npmjs.org/string_decoder/-/string_decoder-1.3.0.tgz", "integrity": "sha512-hkRX8U1WjJFd8LsDJ2yQ/wWWxaopEsABU1XfkM8A+j0+85JAGppt16cr1Whg6KIbb4okU6Mql6BOj+uup/wKeA==", "license": "MIT", - "peer": true, "dependencies": { "safe-buffer": "~5.2.0" } diff --git a/package.json b/package.json index 2ecb322..94c5111 100644 --- a/package.json +++ b/package.json @@ -1,6 +1,6 @@ { "name": "@makerx/node-winston", - "version": "2.2.1", + "version": "2.3.0", "private": false, "description": "A set of winston formats, console transport and logger creation functions", "author": "MakerX", @@ -47,6 +47,10 @@ "@makerx/node-common": "^1.5.0", "@makerx/prettier-config": "2.0.1", "@makerx/ts-toolkit": "^5.0.0-beta.0", + "@opentelemetry/api": "^1.9.1", + "@opentelemetry/api-logs": "^0.223.0", + "@opentelemetry/sdk-logs": "^0.223.0", + "@opentelemetry/winston-transport": "^0.34.0", "@rollup/plugin-commonjs": "29.0.2", "@rollup/plugin-typescript": "^12.3.0", "@tsconfig/node20": "20.1.9", @@ -62,6 +66,8 @@ "eslint-plugin-node": "^11.1.0", "eslint-plugin-prettier": "^5.5.5", "npm-run-all": "^4.1.5", + "otel-winston-transport-0.27": "npm:@opentelemetry/winston-transport@^0.27.0", + "otel-winston-transport-0.31": "npm:@opentelemetry/winston-transport@^0.31.0", "rimraf": "^6.1.3", "rollup": "4.60.2", "tslib": "^2.8.1", diff --git a/src/index.ts b/src/index.ts index 730aee8..38a92df 100644 --- a/src/index.ts +++ b/src/index.ts @@ -9,6 +9,7 @@ import { } from 'winston' import * as Transport from 'winston-transport' import { jsonStringifyValuesFormat } from './json-stringify-values-format' +import { otelAttributesFormat } from './otel-attributes-format' import { omitFormat } from './omit-format' import { omitNilFormat } from './omit-nil-format' import { prettyConsoleFormat } from './pretty-console-format' @@ -36,6 +37,7 @@ export * from './redact-values' export * from './serialize-error' export * from './serialize-error-format' export * from './map-audit-level-for-otel' +export * from './otel-attributes-format' export * from './utils' // winstonjs' default levels have debug and verbose reversed, which is confusing and causes filtering issues with Seq, @@ -153,16 +155,24 @@ export interface CreateLoggerOptions { redactedValue?: string /** - * When `true`, appends `jsonStringifyValuesFormat` as the final logger-level format — applied after every - * other logger-level format (including any `loggerOptions.format`) — serialising every top-level value on - * the log info to a JSON string. Produces a flat `{ key: string }` shape suitable for transports/aggregators - * that expect scalar values (e.g. OTEL + Azure Log Analytics). + * Appends a flattening format as the final logger-level format — applied after every other + * logger-level format (including any `loggerOptions.format`), so it affects every transport. + * + * - `'otel'` appends {@link otelAttributesFormat}: the shape `@opentelemetry/winston-transport` 0.29 + * and later needs. An `err`/`error` value stays an object holding `name`, `message` and `stack`, + * which the transport records as the exception, the rest of the error goes to `Detail` as + * JSON, and every other object value becomes a JSON string. + * - `true` appends `jsonStringifyValuesFormat`, serialising every top-level object value — errors + * included — to a JSON string. For a transport before 0.29; from 0.29 the transport records a + * stringified error as one `exception.message` holding the whole JSON. + * + * To flatten only what one transport receives, put the format on that transport instead. */ - flatten?: boolean + flatten?: boolean | 'otel' /** - * Optional `JSON.stringify` replacer forwarded to `flatten` when serialising each top-level value. - * Only applied when `flatten` is `true`. + * Optional `JSON.stringify` replacer forwarded to `flatten` when serialising each value. + * Applied in both `flatten` modes. */ // eslint-disable-next-line @typescript-eslint/no-explicit-any flattenReplacer?: (this: any, key: string, value: any) => any @@ -279,7 +289,8 @@ export function createLogger(options: CreateLoggerOptions): any { if (redactPaths) loggerFormats.push(redactFormat({ paths: redactPaths, redactedValue, errorSerializer })) if (options.loggerOptions?.format) loggerFormats.push(options.loggerOptions.format) // flatten is applied last so all prior transformations are captured in the stringified values - if (flatten) loggerFormats.push(jsonStringifyValuesFormat({ replacer: flattenReplacer })) + if (flatten === 'otel') loggerFormats.push(otelAttributesFormat({ replacer: flattenReplacer })) + else if (flatten) loggerFormats.push(jsonStringifyValuesFormat({ replacer: flattenReplacer })) // create logger options using supplied options + transports; loggerOptions.levels (if any) overrides defaultLevels const loggerOptions: LoggerOptions = { diff --git a/src/otel-attributes-format.spec.ts b/src/otel-attributes-format.spec.ts new file mode 100644 index 0000000..456efe4 --- /dev/null +++ b/src/otel-attributes-format.spec.ts @@ -0,0 +1,103 @@ +import { TransformableInfo } from 'logform' +import { LEVEL } from 'triple-beam' +import { describe, expect, it } from 'vitest' +import { otelAttributesFormat, OtelAttributesFormatOptions } from './otel-attributes-format' + +const run = (info: Record, opts?: OtelAttributesFormatOptions) => { + const input = { [LEVEL]: 'error', level: 'error', message: 'failed', ...info } as TransformableInfo + const fmt = otelAttributesFormat(opts) + return fmt.transform(input, fmt.options) as unknown as Record +} + +const serialized = (fields: Record = {}) => ({ name: 'Error', message: 'boom', stack: 'Error: boom\n at x', ...fields }) + +describe('otelAttributesFormat — the error', () => { + it('keeps name, message and stack on `error` for the transport to record as the exception', () => { + expect(run({ error: serialized() }).error).toEqual(serialized()) + }) + + it('moves every other field of the error to errorDetail as JSON', () => { + const result = run({ error: serialized({ statusCode: 413, data: { code: 'too_large' } }) }) + expect(result.error).toEqual(serialized()) + expect(JSON.parse(result.errorDetail as string)).toEqual({ statusCode: 413, data: { code: 'too_large' } }) + }) + + it('writes no errorDetail when the error has nothing beyond name, message and stack', () => { + expect(run({ error: serialized() })).not.toHaveProperty('errorDetail') + }) + + it('moves `code` to errorDetail so the SDK takes `name`, not `code`, as exception.type', () => { + const result = run({ error: serialized({ code: 'ECONNREFUSED' }) }) + expect(result.error).not.toHaveProperty('code') + expect(JSON.parse(result.errorDetail as string)).toEqual({ code: 'ECONNREFUSED' }) + }) + + it('keeps `code` on an error with no name, where it is the only type there is', () => { + expect(run({ error: { code: 'ECONNRESET', message: 'socket hang up' } }).error).toEqual({ + code: 'ECONNRESET', + message: 'socket hang up', + }) + }) + + it('keeps a cause with a message on the error, and the whole cause chain under errorDetail', () => { + const cause = { name: 'Error', message: 'middle', cause: { name: 'Error', message: 'inner' } } + const result = run({ error: serialized({ cause }) }) + expect(result.error).toEqual(serialized({ cause })) + expect(JSON.parse(result.errorDetail as string)).toEqual({ cause }) + }) + + it('leaves a cause with nothing to describe off the error, where the transport would write [object Object]', () => { + const cause = { type: 'error', sequence_number: 3 } + const result = run({ error: serialized({ cause }) }) + expect(result.error).toEqual(serialized()) + expect(JSON.parse(result.errorDetail as string)).toEqual({ cause }) + }) + + it('serializes a raw Error first when used without serializeErrorFormat', () => { + const result = run({ error: Object.assign(new Error('raw'), { statusCode: 500 }) }) + expect(result.error).toMatchObject({ name: 'Error', message: 'raw' }) + expect(JSON.parse(result.errorDetail as string)).toEqual({ statusCode: 500 }) + }) + + it('treats `err` as the exception when both are present, as the transport does, and stringifies `error`', () => { + const result = run({ err: serialized({ statusCode: 1 }), error: serialized() }) + expect(result.err).toEqual(serialized()) + expect(JSON.parse(result.errDetail as string)).toEqual({ statusCode: 1 }) + expect(typeof result.error).toBe('string') + }) + + it('leaves a string error alone, which the transport records as exception.message', () => { + expect(run({ error: 'timed out' }).error).toBe('timed out') + }) +}) + +describe('otelAttributesFormat — other values', () => { + it('stringifies objects and arrays and leaves scalars alone', () => { + const result = run({ obj: { a: 1 }, arr: [1, 2], count: 3, flag: true, text: 'literal', none: null }) + expect(result).toMatchObject({ obj: '{"a":1}', arr: '[1,2]', count: 3, flag: true, text: 'literal', none: null }) + }) + + it('writes a Date as its ISO string, unquoted', () => { + expect(run({ at: new Date('2026-01-02T03:04:05.000Z') }).at).toBe('2026-01-02T03:04:05.000Z') + }) + + it('serializes an error nested inside another value rather than writing {}', () => { + const result = run({ ctx: { failure: new Error('deep') } }) + expect(JSON.parse(result.ctx as string)).toMatchObject({ failure: { name: 'Error', message: 'deep' } }) + }) + + it('writes a BigInt as n rather than throwing out of the log call', () => { + expect(run({ ids: [10n] }).ids).toBe('["10n"]') + }) + + it('applies the replacer to stringified values and to errorDetail', () => { + const replacer = (key: string, value: unknown) => (key === 'secret' ? '' : value) + const result = run({ data: { secret: 'a', other: 'b' }, error: serialized({ secret: 'c' }) }, { replacer }) + expect(JSON.parse(result.data as string)).toEqual({ secret: '', other: 'b' }) + expect(JSON.parse(result.errorDetail as string)).toEqual({ secret: '' }) + }) + + it('keeps the routing symbols, so the record still reaches its transports', () => { + expect(run({ obj: { a: 1 } })[LEVEL]).toBe('error') + }) +}) diff --git a/src/otel-attributes-format.ts b/src/otel-attributes-format.ts new file mode 100644 index 0000000..5b7f311 --- /dev/null +++ b/src/otel-attributes-format.ts @@ -0,0 +1,118 @@ +import { format } from 'winston' +import { serializeError } from './serialize-error' +import { serializesItself } from './serializes-itself' + +// eslint-disable-next-line @typescript-eslint/no-explicit-any +type Replacer = (this: any, key: string, value: any) => any + +export interface OtelAttributesFormatOptions { + /** `JSON.stringify` replacer applied to every value this format stringifies, `errorDetail` included. */ + replacer?: Replacer +} + +/** The keys `@opentelemetry/winston-transport` reads an exception from, in the order it tries them. */ +const EXCEPTION_KEYS = ['err', 'error'] as const + +/** What the logs SDK reads from an exception: `name`, `message` and `stack` become `exception.type/message/stacktrace`. */ +const EXCEPTION_FIELDS = new Set(['name', 'message', 'stack']) + +const isObject = (value: unknown): value is Record => typeof value === 'object' && value !== null + +/** The transport's own test, so the key chosen here is the one it lifts. */ +const isExceptionCandidate = (value: unknown): boolean => + typeof value === 'string' || + typeof value === 'number' || + (isObject(value) && (value.code != null || value.name != null || value.message != null || value.stack != null)) + +/** A cause the transport turns into `.cause.*` attributes; any other object it writes as `'[object Object]'`. */ +const isDescribableCause = (cause: unknown): boolean => + typeof cause === 'string' || + typeof cause === 'number' || + (isObject(cause) && + (typeof cause.message === 'string' || + typeof cause.name === 'string' || + typeof cause.stack === 'string' || + typeof cause.code === 'string' || + typeof cause.code === 'number')) + +/** Plain JSON for any value: errors serialized, BigInts written as `n`, and never a throw out of the log call. */ +const stringify = (value: unknown, replacer: Replacer | undefined): string => { + const plain = function (this: unknown, key: string, entry: unknown): unknown { + const converted = entry instanceof Error ? serializeError(entry) : typeof entry === 'bigint' ? `${entry}n` : entry + return replacer ? (replacer.call(this, key, converted) as unknown) : converted + } + try { + return JSON.stringify(value, plain) ?? String(value) + } catch { + return '[Unserializable]' + } +} + +/** A value that writes itself as a primitive (a `Date`'s ISO string) is kept unquoted, so a query reads it as it is. */ +const flatValue = (value: object, replacer: Replacer | undefined): unknown => { + if (!replacer && serializesItself(value)) { + try { + const json: unknown = (value as { toJSON: () => unknown }).toJSON() + if (json === null || typeof json === 'string' || typeof json === 'number' || typeof json === 'boolean') return json + } catch { + // fall through to the JSON of the value itself + } + } + return stringify(value, replacer) +} + +/** + * Leaves the exception what the logs SDK reads — `name`, `message`, `stack`, and a cause it can + * describe — and moves the rest of the error to `Detail` as JSON. The SDK takes a truthy `code` + * over `name` for `exception.type`, so `code` moves too, unless there is no `name` to take its place. + */ +const splitException = (record: Record, key: string, error: Record, replacer: Replacer | undefined) => { + const exception: Record = {} + const detail: Record = {} + for (const [field, value] of Object.entries(error)) { + if (EXCEPTION_FIELDS.has(field)) exception[field] = value + else detail[field] = value + } + if (isDescribableCause(error.cause)) exception.cause = error.cause + if (exception.name == null && error.code != null) { + exception.code = error.code + delete detail.code + } + record[key] = exception + if (Object.keys(detail).length > 0) record[`${key}Detail`] = stringify(detail, replacer) +} + +/** + * Shapes a log record into OpenTelemetry log attributes, for `@opentelemetry/winston-transport` + * 0.29 and later. + * + * From 0.29 the transport lifts an `err` or `error` value off the record and gives it to the logs + * SDK as the record's exception, which becomes `exception.type`, `exception.message`, + * `exception.stacktrace` and `error.cause.*`. Only those fields survive: anything else on the error + * is dropped, and an error flattened to a JSON string arrives as one `exception.message` holding + * the whole JSON. So the error is left an object with just those fields, and the rest of it — + * `statusCode`, provider data, the whole cause chain — goes to `Detail` as JSON. + * + * Every other object value becomes a JSON string, so each attribute is a scalar and the record is + * flat whatever the transport line: 0.29 to 0.31 pass objects through as they are, and 0.32 and later + * turn them into nested map attributes, which most backends — Azure Log Analytics included — do not + * index. Scalars are left alone. A `Date` becomes its ISO string, unquoted. + * + * Use it on the transport to keep other transports' output nested, or through + * `createLogger({ flatten: 'otel' })` when the transport is added for you, as `WinstonInstrumentation` + * does. For a transport before 0.29, which has no exception handling, use `jsonStringifyValuesFormat`. + * + * Mutates `info` in place, so winston's Symbol-keyed routing properties are preserved. + */ +export const otelAttributesFormat = format((info, opts) => { + const { replacer } = (opts ?? {}) as OtelAttributesFormatOptions + const record = info as unknown as Record + const lifted = EXCEPTION_KEYS.find((key) => isExceptionCandidate(record[key])) + for (const key of Object.keys(record)) { + const value = record[key] + if (!isObject(value)) continue + if (key === lifted) splitException(record, key, value instanceof Error ? serializeError(value) : value, replacer) + else record[key] = flatValue(value, replacer) + } + return info +}) diff --git a/src/otel-transport.spec.ts b/src/otel-transport.spec.ts new file mode 100644 index 0000000..4c65e61 --- /dev/null +++ b/src/otel-transport.spec.ts @@ -0,0 +1,144 @@ +/** + * What a record looks like once it is an OpenTelemetry log record, through the real + * `@opentelemetry/winston-transport` and the logs SDK — the row a backend stores. + * + * Three transport lines, installed side by side under npm aliases: + * - 0.27: no exception handling; every attribute is passed through as it is. + * - 0.31: lifts `err`/`error` off the record as the exception (from 0.29). + * - 0.34: also normalises object attributes into nested maps, errors included (from 0.32). + * + * Each transport binds its logger when it is constructed, so the provider is registered first. + */ +import { logs } from '@opentelemetry/api-logs' +import { InMemoryLogRecordExporter, LoggerProvider, SimpleLogRecordProcessor } from '@opentelemetry/sdk-logs' +import { OpenTelemetryTransportV3 as Transport034 } from '@opentelemetry/winston-transport' +import { OpenTelemetryTransportV3 as Transport027 } from 'otel-winston-transport-0.27' +import { OpenTelemetryTransportV3 as Transport031 } from 'otel-winston-transport-0.31' +import { afterAll, beforeAll, describe, expect, it } from 'vitest' +import type TransportStream from 'winston-transport' +import { CallbackTransport, createLogger, type CreateLoggerOptions } from './index' +import { otelAttributesFormat } from './otel-attributes-format' + +type TransportClass = new (options?: TransportStream.TransportStreamOptions) => TransportStream + +const exporter = new InMemoryLogRecordExporter() +const provider = new LoggerProvider({ processors: [new SimpleLogRecordProcessor({ exporter })] }) + +beforeAll(() => { + logs.setGlobalLoggerProvider(provider) +}) + +afterAll(async () => { + await provider.shutdown() + logs.disable() +}) + +class ProviderError extends Error { + readonly name = 'ProviderError' + readonly statusCode = 413 + readonly data = { error: { code: 'request_too_large' } } +} + +const failure = () => new ProviderError('Request too large', { cause: new Error('body exceeds limit') }) +const at = new Date('2026-01-02T03:04:05.000Z') + +let sequence = 0 + +/** Logs one error line through a fresh logger on `Transport` and returns its exported attributes. */ +async function exported(Transport: TransportClass, options: Partial = {}, transport?: TransportStream) { + const message = `line ${++sequence}` + const logger = createLogger({ consoleOptions: { silent: true }, transports: [transport ?? new Transport()], ...options }) + logger.error(message, { error: failure(), at, request: { route: '/chat', attempt: 2 } }) + await new Promise((resolve) => setImmediate(resolve)) + const records = exporter.getFinishedLogRecords().filter((record) => record.body === message) + expect(records).toHaveLength(1) + return records[0].attributes as Record +} + +const isScalar = (value: unknown) => value === null || ['string', 'number', 'boolean'].includes(typeof value) + +describe('flatten: true', () => { + it('0.27 writes the error as one JSON attribute holding its message and status', async () => { + const attributes = await exported(Transport027, { flatten: true }) + expect(JSON.parse(attributes.error as string)).toMatchObject({ message: 'Request too large', statusCode: 413 }) + expect(attributes).not.toHaveProperty('exception.message') + }) + + it.each([ + ['0.31', Transport031], + ['0.34', Transport034], + ])( + '%s records the whole error JSON as exception.message, which is why flatten: true is for transports before 0.29', + async (_, Transport) => { + const attributes = await exported(Transport, { flatten: true }) + expect(String(attributes['exception.message']).startsWith('{')).toBe(true) + expect(attributes).not.toHaveProperty('exception.type') + }, + ) +}) + +describe('no flatten', () => { + it('0.34 records the exception but drops the rest of the error', async () => { + const attributes = await exported(Transport034) + expect(attributes['exception.message']).toBe('Request too large') + expect(JSON.stringify(attributes)).not.toContain('413') + }) +}) + +describe.each([ + ['0.31', Transport031], + ['0.34', Transport034], +])("flatten: 'otel' on %s", (_, Transport) => { + it('records the error as exception.type, exception.message and exception.stacktrace', async () => { + const attributes = await exported(Transport, { flatten: 'otel' }) + expect(attributes).toMatchObject({ 'exception.type': 'ProviderError', 'exception.message': 'Request too large' }) + expect(String(attributes['exception.stacktrace'])).toContain('Request too large') + }) + + it("records the error's cause as error.cause.message", async () => { + expect((await exported(Transport, { flatten: 'otel' }))['error.cause.message']).toBe('body exceeds limit') + }) + + it("keeps the error's status, provider data and cause chain under errorDetail", async () => { + const attributes = await exported(Transport, { flatten: 'otel' }) + expect(JSON.parse(attributes.errorDetail as string)).toMatchObject({ + statusCode: 413, + data: { error: { code: 'request_too_large' } }, + cause: { message: 'body exceeds limit' }, + }) + }) + + it('writes every attribute as a scalar, none of them [object Object]', async () => { + const attributes = await exported(Transport, { flatten: 'otel' }) + expect(Object.values(attributes).every(isScalar)).toBe(true) + expect(Object.values(attributes)).not.toContain('[object Object]') + }) + + it('writes other objects as JSON strings and a Date as its ISO string', async () => { + const attributes = await exported(Transport, { flatten: 'otel' }) + expect(attributes.request).toBe('{"route":"/chat","attempt":2}') + expect(attributes.at).toBe('2026-01-02T03:04:05.000Z') + }) +}) + +describe('otelAttributesFormat on the transport', () => { + it('flattens what the OpenTelemetry transport receives and leaves other transports nested', async () => { + const seen: Record[] = [] + const sibling = new CallbackTransport( + async ({ meta }) => void seen.push(meta), + () => undefined, + ) + const message = `line ${++sequence}` + const logger = createLogger({ + consoleOptions: { silent: true }, + transports: [new Transport034({ format: otelAttributesFormat() }), sibling], + }) + logger.error(message, { error: failure(), request: { route: '/chat' } }) + await new Promise((resolve) => setImmediate(resolve)) + + const [record] = exporter.getFinishedLogRecords().filter((r) => r.body === message) + expect(record.attributes).toMatchObject({ 'exception.type': 'ProviderError', request: '{"route":"/chat"}' }) + expect(seen[0].request).toEqual({ route: '/chat' }) + expect(seen[0].error).toMatchObject({ statusCode: 413 }) + }) +})