From 9a9a674ad70f3a57cd3f05d4d17f672d7df779a0 Mon Sep 17 00:00:00 2001 From: Hector Hernandez <39923391+hectorhdzg@users.noreply.github.com> Date: Fri, 15 Mar 2024 12:34:07 -0700 Subject: [PATCH 1/3] Allow log level to be configured for log sending --- package-lock.json | 2 + .../README.md | 1 + .../package.json | 1 + .../src/instrumentation.ts | 29 ++++++- .../src/types.ts | 6 ++ .../test/winston.test.ts | 82 +++++++++++++++++++ 6 files changed, 120 insertions(+), 1 deletion(-) diff --git a/package-lock.json b/package-lock.json index 3db09a62fa..8477a592be 100644 --- a/package-lock.json +++ b/package-lock.json @@ -38688,6 +38688,7 @@ "version": "0.35.0", "license": "Apache-2.0", "dependencies": { + "@opentelemetry/api-logs": "^0.49.1", "@opentelemetry/instrumentation": "^0.49.1" }, "devDependencies": { @@ -47325,6 +47326,7 @@ "version": "file:plugins/node/opentelemetry-instrumentation-winston", "requires": { "@opentelemetry/api": "^1.3.0", + "@opentelemetry/api-logs": "^0.49.1", "@opentelemetry/context-async-hooks": "^1.21.0", "@opentelemetry/instrumentation": "^0.49.1", "@opentelemetry/sdk-trace-base": "^1.21.0", diff --git a/plugins/node/opentelemetry-instrumentation-winston/README.md b/plugins/node/opentelemetry-instrumentation-winston/README.md index d6bcbcca99..90d80acc66 100644 --- a/plugins/node/opentelemetry-instrumentation-winston/README.md +++ b/plugins/node/opentelemetry-instrumentation-winston/README.md @@ -60,6 +60,7 @@ logger.info('foobar'); | Option | Type | Description | | ----------------------- | ----------------- | ----------- | | `disableLogSending` | `boolean` | Whether to disable [log sending](#log-sending). Default `false`. | +| `logSeverity` | `SeverityNumber` | Control severity level for [log sending](#log-sending). Default `SeverityNumber.UNSPECIFIED`, it will use Winston Logger's current level when unspecified. | | `disableLogCorrelation` | `boolean` | Whether to disable [log correlation](#log-correlation). Default `false`. | | `logHook` | `LogHookFunction` | An option hook to inject additional context to a log record after trace-context has been added. This requires `disableLogCorrelation` to be false. | diff --git a/plugins/node/opentelemetry-instrumentation-winston/package.json b/plugins/node/opentelemetry-instrumentation-winston/package.json index bdec39fcfd..71f180765f 100644 --- a/plugins/node/opentelemetry-instrumentation-winston/package.json +++ b/plugins/node/opentelemetry-instrumentation-winston/package.json @@ -64,6 +64,7 @@ "winston2": "npm:winston@2.4.7" }, "dependencies": { + "@opentelemetry/api-logs": "^0.49.1", "@opentelemetry/instrumentation": "^0.49.1" }, "homepage": "https://github.com/open-telemetry/opentelemetry-js-contrib/tree/main/plugins/node/opentelemetry-instrumentation-winston#readme" diff --git a/plugins/node/opentelemetry-instrumentation-winston/src/instrumentation.ts b/plugins/node/opentelemetry-instrumentation-winston/src/instrumentation.ts index d89107144c..97d408c2cc 100644 --- a/plugins/node/opentelemetry-instrumentation-winston/src/instrumentation.ts +++ b/plugins/node/opentelemetry-instrumentation-winston/src/instrumentation.ts @@ -15,6 +15,7 @@ */ import { context, trace, isSpanContextValid, Span } from '@opentelemetry/api'; +import { SeverityNumber } from '@opentelemetry/api-logs'; import { InstrumentationBase, InstrumentationNodeModuleDefinition, @@ -206,7 +207,16 @@ export class WinstonInstrumentation extends InstrumentationBase { let newTransports = Array.isArray(originalTransports) ? originalTransports : []; - const openTelemetryTransport = new OpenTelemetryTransportV3(); + let transportOptions = {}; + if (config.logSeverity) { + const winstonLevel = winstonLevelFromSeverity( + config.logSeverity + ); + transportOptions = { level: winstonLevel }; + } + const openTelemetryTransport = new OpenTelemetryTransportV3( + transportOptions + ); if (originalTransports && !Array.isArray(originalTransports)) { newTransports = [originalTransports]; } @@ -245,3 +255,20 @@ export class WinstonInstrumentation extends InstrumentationBase { return record; } } + +function winstonLevelFromSeverity( + severity: SeverityNumber +): string | undefined { + if (severity >= SeverityNumber.ERROR) { + return 'error'; + } else if (severity >= SeverityNumber.WARN) { + return 'warn'; + } else if (severity >= SeverityNumber.INFO) { + return 'info'; + } else if (severity >= SeverityNumber.DEBUG) { + return 'debug'; + } else if (severity >= SeverityNumber.TRACE) { + return 'silly'; + } + return; +} diff --git a/plugins/node/opentelemetry-instrumentation-winston/src/types.ts b/plugins/node/opentelemetry-instrumentation-winston/src/types.ts index 5621bc8797..e6fabea502 100644 --- a/plugins/node/opentelemetry-instrumentation-winston/src/types.ts +++ b/plugins/node/opentelemetry-instrumentation-winston/src/types.ts @@ -15,6 +15,7 @@ */ import { Span } from '@opentelemetry/api'; +import { SeverityNumber } from '@opentelemetry/api-logs'; import { InstrumentationConfig } from '@opentelemetry/instrumentation'; // eslint-disable-next-line @typescript-eslint/no-explicit-any @@ -28,6 +29,11 @@ export interface WinstonInstrumentationConfig extends InstrumentationConfig { */ disableLogSending?: boolean; + /** + * Control Log sending severity level, logs will be sent for specified severity and higher. + */ + logSeverity?: SeverityNumber; + /** * Whether to disable the injection trace-context fields, and possibly other * fields from `logHook()`, into log records for log correlation. diff --git a/plugins/node/opentelemetry-instrumentation-winston/test/winston.test.ts b/plugins/node/opentelemetry-instrumentation-winston/test/winston.test.ts index fe62a946b9..caf6e67515 100644 --- a/plugins/node/opentelemetry-instrumentation-winston/test/winston.test.ts +++ b/plugins/node/opentelemetry-instrumentation-winston/test/winston.test.ts @@ -383,4 +383,86 @@ describe('WinstonInstrumentation', () => { } }); }); + describe('logSeverity config', () => { + beforeEach(() => { + instrumentation.setConfig({ + disableLogSending: false, + }); + memoryLogExporter.getFinishedLogRecords().length = 0; // clear + }); + + it('error severity', () => { + if (!isWinston2) { + instrumentation.setConfig({ + disableLogSending: false, + logSeverity: SeverityNumber.ERROR, + }); + initLogger(); + logger.warn('warn'); + logger.error('error'); + const logRecords = memoryLogExporter.getFinishedLogRecords(); + assert.strictEqual(logRecords.length, 1); + assert.strictEqual(logRecords[0].body, 'error'); + } + }); + + it('warn severity', () => { + if (!isWinston2) { + instrumentation.setConfig({ + disableLogSending: false, + logSeverity: SeverityNumber.WARN, + }); + initLogger(); + logger.info('info'); + logger.warn('warn'); + const logRecords = memoryLogExporter.getFinishedLogRecords(); + assert.strictEqual(logRecords.length, 1); + assert.strictEqual(logRecords[0].body, 'warn'); + } + }); + + it('info severity', () => { + if (!isWinston2) { + instrumentation.setConfig({ + disableLogSending: false, + logSeverity: SeverityNumber.INFO, + }); + initLogger(); + logger.debug('debug'); + logger.info('info'); + const logRecords = memoryLogExporter.getFinishedLogRecords(); + assert.strictEqual(logRecords.length, 1); + assert.strictEqual(logRecords[0].body, 'info'); + } + }); + + it('debug severity', () => { + if (!isWinston2) { + instrumentation.setConfig({ + disableLogSending: false, + logSeverity: SeverityNumber.DEBUG, + }); + initLogger(); + logger.silly('silly'); + logger.debug('debug'); + const logRecords = memoryLogExporter.getFinishedLogRecords(); + assert.strictEqual(logRecords.length, 1); + assert.strictEqual(logRecords[0].body, 'debug'); + } + }); + + it('trace severity', () => { + if (!isWinston2) { + instrumentation.setConfig({ + disableLogSending: false, + logSeverity: SeverityNumber.TRACE, + }); + initLogger(); + logger.silly('silly'); + const logRecords = memoryLogExporter.getFinishedLogRecords(); + assert.strictEqual(logRecords.length, 1); + assert.strictEqual(logRecords[0].body, 'silly'); + } + }); + }); }); From ecbaef9303454b64313beab4895c4e815cdb44fe Mon Sep 17 00:00:00 2001 From: Hector Hernandez <39923391+hectorhdzg@users.noreply.github.com> Date: Mon, 15 Apr 2024 13:54:38 -0700 Subject: [PATCH 2/3] Support other winston levels --- package-lock.json | 3 +- .../src/instrumentation.ts | 132 +++++++++++++++--- .../src/internal-types.ts | 1 - .../test/winston.test.ts | 57 ++------ 4 files changed, 131 insertions(+), 62 deletions(-) diff --git a/package-lock.json b/package-lock.json index 3c3af978ce..a1a7846d38 100644 --- a/package-lock.json +++ b/package-lock.json @@ -38673,6 +38673,7 @@ "version": "0.36.0", "license": "Apache-2.0", "dependencies": { + "@opentelemetry/api-logs": "^0.50.0", "@opentelemetry/instrumentation": "^0.50.0" }, "devDependencies": { @@ -47288,7 +47289,7 @@ "version": "file:plugins/node/opentelemetry-instrumentation-winston", "requires": { "@opentelemetry/api": "^1.3.0", - "@opentelemetry/api-logs": "^0.49.1", + "@opentelemetry/api-logs": "^0.50.0", "@opentelemetry/context-async-hooks": "^1.21.0", "@opentelemetry/instrumentation": "^0.50.0", "@opentelemetry/sdk-trace-base": "^1.21.0", diff --git a/plugins/node/opentelemetry-instrumentation-winston/src/instrumentation.ts b/plugins/node/opentelemetry-instrumentation-winston/src/instrumentation.ts index 97d408c2cc..de72ed235b 100644 --- a/plugins/node/opentelemetry-instrumentation-winston/src/instrumentation.ts +++ b/plugins/node/opentelemetry-instrumentation-winston/src/instrumentation.ts @@ -209,8 +209,9 @@ export class WinstonInstrumentation extends InstrumentationBase { : []; let transportOptions = {}; if (config.logSeverity) { - const winstonLevel = winstonLevelFromSeverity( - config.logSeverity + const winstonLevel = instrumentation._winstonLevelFromSeverity( + config.logSeverity, + args[0].levels ); transportOptions = { level: winstonLevel }; } @@ -254,21 +255,118 @@ export class WinstonInstrumentation extends InstrumentationBase { } return record; } -} -function winstonLevelFromSeverity( - severity: SeverityNumber -): string | undefined { - if (severity >= SeverityNumber.ERROR) { - return 'error'; - } else if (severity >= SeverityNumber.WARN) { - return 'warn'; - } else if (severity >= SeverityNumber.INFO) { - return 'info'; - } else if (severity >= SeverityNumber.DEBUG) { - return 'debug'; - } else if (severity >= SeverityNumber.TRACE) { - return 'silly'; + private _winstonLevelFromSeverity( + severity: SeverityNumber, + winstonLevels: { [key: string]: number } | undefined + ): string | undefined { + if (winstonLevels) { + if (isNpmLevels(winstonLevels)) { + if (severity >= SeverityNumber.ERROR) { + return 'error'; + } else if (severity >= SeverityNumber.WARN) { + return 'warn'; + } else if (severity >= SeverityNumber.INFO) { + return 'info'; + } else if (severity >= SeverityNumber.DEBUG3) { + return 'http'; + } else if (severity >= SeverityNumber.DEBUG2) { + return 'verbose'; + } else if (severity >= SeverityNumber.DEBUG) { + return 'debug'; + } else if (severity >= SeverityNumber.TRACE) { + return 'silly'; + } + } else if (isCliLevels(winstonLevels)) { + if (severity >= SeverityNumber.ERROR) { + return 'error'; + } else if (severity >= SeverityNumber.WARN) { + return 'warn'; + } else if (severity >= SeverityNumber.INFO3) { + return 'help'; + } else if (severity >= SeverityNumber.INFO2) { + return 'data'; + } else if (severity >= SeverityNumber.INFO) { + return 'info'; + } else if (severity >= SeverityNumber.DEBUG) { + return 'debug'; + } else if (severity >= SeverityNumber.TRACE4) { + return 'prompt'; + } else if (severity >= SeverityNumber.TRACE3) { + return 'verbose'; + } else if (severity >= SeverityNumber.TRACE2) { + return 'input'; + } else if (severity >= SeverityNumber.TRACE) { + return 'silly'; + } + } else if (isSyslogLevels(winstonLevels)) { + if (severity >= SeverityNumber.FATAL2) { + return 'emerg'; + } else if (severity >= SeverityNumber.FATAL) { + return 'alert'; + } else if (severity >= SeverityNumber.ERROR2) { + return 'crit'; + } else if (severity >= SeverityNumber.ERROR) { + return 'error'; + } else if (severity >= SeverityNumber.WARN) { + return 'warning'; + } else if (severity >= SeverityNumber.INFO2) { + return 'notice'; + } else if (severity >= SeverityNumber.INFO) { + return 'info'; + } else if (severity >= SeverityNumber.TRACE) { + return 'debug'; + } + } + // Unknown level + this._diag.warn( + 'failed to configure severity with existing winston levels' + ); + } + + function isCliLevels(arg: any): boolean { + return ( + arg && + arg.error !== undefined && + arg.warn && + arg.help && + arg.data && + arg.info && + arg.debug && + arg.prompt && + arg.verbose && + arg.input && + arg.silly + ); + } + + function isNpmLevels(arg: any): boolean { + return ( + arg && + arg.error !== undefined && + arg.warn && + arg.info && + arg.http && + arg.verbose && + arg.debug && + arg.silly + ); + } + + function isSyslogLevels(arg: any): boolean { + return ( + arg && + arg.emerg !== undefined && + arg.alert && + arg.crit && + arg.error && + arg.warning && + arg.notice && + arg.info && + arg.debug + ); + } + + return; } - return; } diff --git a/plugins/node/opentelemetry-instrumentation-winston/src/internal-types.ts b/plugins/node/opentelemetry-instrumentation-winston/src/internal-types.ts index cba7ee90d2..e71eff3c83 100644 --- a/plugins/node/opentelemetry-instrumentation-winston/src/internal-types.ts +++ b/plugins/node/opentelemetry-instrumentation-winston/src/internal-types.ts @@ -22,7 +22,6 @@ import type { export type Winston3LogMethod = Winston3Logger['write']; export type Winston3ConfigureMethod = Winston3Logger['configure']; export type { Winston3Logger }; - export type { Winston2LogMethod }; export type Winston2LoggerModule = { Logger: Winston2Logger & { diff --git a/plugins/node/opentelemetry-instrumentation-winston/test/winston.test.ts b/plugins/node/opentelemetry-instrumentation-winston/test/winston.test.ts index caf6e67515..02c4dd20b4 100644 --- a/plugins/node/opentelemetry-instrumentation-winston/test/winston.test.ts +++ b/plugins/node/opentelemetry-instrumentation-winston/test/winston.test.ts @@ -391,77 +391,48 @@ describe('WinstonInstrumentation', () => { memoryLogExporter.getFinishedLogRecords().length = 0; // clear }); - it('error severity', () => { + it('npm levels', () => { if (!isWinston2) { instrumentation.setConfig({ disableLogSending: false, logSeverity: SeverityNumber.ERROR, }); - initLogger(); - logger.warn('warn'); - logger.error('error'); + initLogger(LevelsType.npm); + logger.log('verbose', 'verbose'); + logger.log('error', 'error'); const logRecords = memoryLogExporter.getFinishedLogRecords(); assert.strictEqual(logRecords.length, 1); assert.strictEqual(logRecords[0].body, 'error'); } }); - it('warn severity', () => { + it('cli levels', () => { if (!isWinston2) { instrumentation.setConfig({ disableLogSending: false, logSeverity: SeverityNumber.WARN, }); - initLogger(); - logger.info('info'); - logger.warn('warn'); + initLogger(LevelsType.cli); + logger.log('prompt', 'prompt'); + logger.log('warn', 'warn'); const logRecords = memoryLogExporter.getFinishedLogRecords(); assert.strictEqual(logRecords.length, 1); assert.strictEqual(logRecords[0].body, 'warn'); } }); - it('info severity', () => { - if (!isWinston2) { - instrumentation.setConfig({ - disableLogSending: false, - logSeverity: SeverityNumber.INFO, - }); - initLogger(); - logger.debug('debug'); - logger.info('info'); - const logRecords = memoryLogExporter.getFinishedLogRecords(); - assert.strictEqual(logRecords.length, 1); - assert.strictEqual(logRecords[0].body, 'info'); - } - }); - - it('debug severity', () => { - if (!isWinston2) { - instrumentation.setConfig({ - disableLogSending: false, - logSeverity: SeverityNumber.DEBUG, - }); - initLogger(); - logger.silly('silly'); - logger.debug('debug'); - const logRecords = memoryLogExporter.getFinishedLogRecords(); - assert.strictEqual(logRecords.length, 1); - assert.strictEqual(logRecords[0].body, 'debug'); - } - }); - - it('trace severity', () => { + it('syslog levels', () => { if (!isWinston2) { instrumentation.setConfig({ disableLogSending: false, - logSeverity: SeverityNumber.TRACE, + logSeverity: SeverityNumber.WARN, }); - initLogger(); - logger.silly('silly'); + initLogger(LevelsType.syslog); + logger.log('notice', 'notice'); + logger.log('emerg', 'emerg'); const logRecords = memoryLogExporter.getFinishedLogRecords(); assert.strictEqual(logRecords.length, 1); - assert.strictEqual(logRecords[0].body, 'silly'); + assert.strictEqual(logRecords[0].body, 'emerg'); } }); }); From 3a2256de0d25cb3eccf3dcb0126b3827e3019de4 Mon Sep 17 00:00:00 2001 From: Hector Hernandez <39923391+hectorhdzg@users.noreply.github.com> Date: Thu, 18 Apr 2024 11:42:08 -0700 Subject: [PATCH 3/3] Updating tests, transport callback update --- .../src/OpenTelemetryTransportV3.ts | 10 ++-- .../test/winston.test.ts | 48 +++++++++++++++---- 2 files changed, 44 insertions(+), 14 deletions(-) diff --git a/packages/winston-transport/src/OpenTelemetryTransportV3.ts b/packages/winston-transport/src/OpenTelemetryTransportV3.ts index fe759676e9..a7e164adce 100644 --- a/packages/winston-transport/src/OpenTelemetryTransportV3.ts +++ b/packages/winston-transport/src/OpenTelemetryTransportV3.ts @@ -27,17 +27,15 @@ export class OpenTelemetryTransportV3 extends TransportStream { this._logger = logs.getLogger('@opentelemetry/winston-transport', VERSION); } - public override log(info: any, next: () => void) { + public override log(info: any, callback: () => void) { try { emitLogRecord(info, this._logger); } catch (error) { this.emit('warn', error); } - setImmediate(() => { - this.emit('logged', info); - }); - if (next) { - setImmediate(next); + this.emit('logged', info); + if (callback) { + callback(); } } } diff --git a/plugins/node/opentelemetry-instrumentation-winston/test/winston.test.ts b/plugins/node/opentelemetry-instrumentation-winston/test/winston.test.ts index 02c4dd20b4..2ecb4eab37 100644 --- a/plugins/node/opentelemetry-instrumentation-winston/test/winston.test.ts +++ b/plugins/node/opentelemetry-instrumentation-winston/test/winston.test.ts @@ -395,14 +395,24 @@ describe('WinstonInstrumentation', () => { if (!isWinston2) { instrumentation.setConfig({ disableLogSending: false, - logSeverity: SeverityNumber.ERROR, + logSeverity: SeverityNumber.DEBUG, }); initLogger(LevelsType.npm); + logger.log('silly', 'silly'); + logger.log('debug', 'debug'); logger.log('verbose', 'verbose'); + logger.log('http', 'http'); + logger.log('info', 'info'); + logger.log('warn', 'warn'); logger.log('error', 'error'); const logRecords = memoryLogExporter.getFinishedLogRecords(); - assert.strictEqual(logRecords.length, 1); - assert.strictEqual(logRecords[0].body, 'error'); + assert.strictEqual(logRecords.length, 6); + assert.strictEqual(logRecords[0].body, 'debug'); + assert.strictEqual(logRecords[1].body, 'verbose'); + assert.strictEqual(logRecords[2].body, 'http'); + assert.strictEqual(logRecords[3].body, 'info'); + assert.strictEqual(logRecords[4].body, 'warn'); + assert.strictEqual(logRecords[5].body, 'error'); } }); @@ -410,14 +420,26 @@ describe('WinstonInstrumentation', () => { if (!isWinston2) { instrumentation.setConfig({ disableLogSending: false, - logSeverity: SeverityNumber.WARN, + logSeverity: SeverityNumber.INFO, }); initLogger(LevelsType.cli); + logger.log('silly', 'silly'); + logger.log('input', 'input'); + logger.log('verbose', 'verbose'); logger.log('prompt', 'prompt'); + logger.log('debug', 'debug'); + logger.log('info', 'info'); + logger.log('data', 'data'); + logger.log('help', 'help'); logger.log('warn', 'warn'); + logger.log('error', 'error'); const logRecords = memoryLogExporter.getFinishedLogRecords(); - assert.strictEqual(logRecords.length, 1); - assert.strictEqual(logRecords[0].body, 'warn'); + assert.strictEqual(logRecords.length, 5); + assert.strictEqual(logRecords[0].body, 'info'); + assert.strictEqual(logRecords[1].body, 'data'); + assert.strictEqual(logRecords[2].body, 'help'); + assert.strictEqual(logRecords[3].body, 'warn'); + assert.strictEqual(logRecords[4].body, 'error'); } }); @@ -428,11 +450,21 @@ describe('WinstonInstrumentation', () => { logSeverity: SeverityNumber.WARN, }); initLogger(LevelsType.syslog); + logger.log('debug', 'debug'); + logger.log('info', 'info'); logger.log('notice', 'notice'); + logger.log('warning', 'warning'); + logger.log('error', 'error'); + logger.log('crit', 'crit'); + logger.log('alert', 'alert'); logger.log('emerg', 'emerg'); const logRecords = memoryLogExporter.getFinishedLogRecords(); - assert.strictEqual(logRecords.length, 1); - assert.strictEqual(logRecords[0].body, 'emerg'); + assert.strictEqual(logRecords.length, 5); + assert.strictEqual(logRecords[0].body, 'warning'); + assert.strictEqual(logRecords[1].body, 'error'); + assert.strictEqual(logRecords[2].body, 'crit'); + assert.strictEqual(logRecords[3].body, 'alert'); + assert.strictEqual(logRecords[4].body, 'emerg'); } }); });