From 921cc535d3f0312115d8f477005c66cbbd1df377 Mon Sep 17 00:00:00 2001 From: Hector Hernandez <39923391+hectorhdzg@users.noreply.github.com> Date: Thu, 1 Feb 2024 15:47:55 -0800 Subject: [PATCH 1/5] Allow log level to be configured for auto instrumentation and BunyanStream --- .../README.md | 1 + .../src/OpenTelemetryBunyanStream.ts | 26 ++++++++++++------- .../src/instrumentation.ts | 4 ++- .../src/types.ts | 6 +++++ .../test/bunyan.test.ts | 16 ++++++++++++ 5 files changed, 42 insertions(+), 11 deletions(-) diff --git a/plugins/node/opentelemetry-instrumentation-bunyan/README.md b/plugins/node/opentelemetry-instrumentation-bunyan/README.md index c12b489658..0cdbb84aff 100644 --- a/plugins/node/opentelemetry-instrumentation-bunyan/README.md +++ b/plugins/node/opentelemetry-instrumentation-bunyan/README.md @@ -86,6 +86,7 @@ Log injection can be disabled with the `disableLogCorrelation: true` option. | Option | Type | Description | | ----------------------- | ----------------- | ----------- | | `disableLogSending` | `boolean` | Whether to disable [log sending](#log-sending). Default `false`. | +| `logSendingLevel` | `SeverityNumber` | Control severity level for [log sending](#log-sending). Default `SeverityNumber.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-bunyan/src/OpenTelemetryBunyanStream.ts b/plugins/node/opentelemetry-instrumentation-bunyan/src/OpenTelemetryBunyanStream.ts index 8b3d1c8977..59965fdf07 100644 --- a/plugins/node/opentelemetry-instrumentation-bunyan/src/OpenTelemetryBunyanStream.ts +++ b/plugins/node/opentelemetry-instrumentation-bunyan/src/OpenTelemetryBunyanStream.ts @@ -102,12 +102,15 @@ function severityNumberFromBunyanLevel(lvl: number) { */ export class OpenTelemetryBunyanStream { private _otelLogger: Logger; + private _logSendingLevel: SeverityNumber; - constructor() { + constructor(options?: { logSendingLevel?: SeverityNumber }) { this._otelLogger = logs.getLogger( DEFAULT_INSTRUMENTATION_SCOPE_NAME, DEFAULT_INSTRUMENTATION_SCOPE_VERSION ); + this._logSendingLevel = + options?.logSendingLevel || SeverityNumber.UNSPECIFIED; } /** @@ -149,14 +152,17 @@ export class OpenTelemetryBunyanStream { } else { fields.time = time; // Expose non-Date "time" field on attributes. } - const otelRec = { - timestamp, - observedTimestamp: timestamp, - severityNumber: severityNumberFromBunyanLevel(level), - severityText: nameFromLevel[level], - body: msg, - attributes: fields, - }; - this._otelLogger.emit(otelRec); + const severityNumber = severityNumberFromBunyanLevel(level); + if (this._logSendingLevel <= severityNumber) { + const otelRec = { + timestamp, + observedTimestamp: timestamp, + severityNumber: severityNumber, + severityText: nameFromLevel[level], + body: msg, + attributes: fields, + }; + this._otelLogger.emit(otelRec); + } } } diff --git a/plugins/node/opentelemetry-instrumentation-bunyan/src/instrumentation.ts b/plugins/node/opentelemetry-instrumentation-bunyan/src/instrumentation.ts index c78e27b50b..206b258c13 100644 --- a/plugins/node/opentelemetry-instrumentation-bunyan/src/instrumentation.ts +++ b/plugins/node/opentelemetry-instrumentation-bunyan/src/instrumentation.ts @@ -159,7 +159,9 @@ export class BunyanInstrumentation extends InstrumentationBase< this._diag.debug('Adding OpenTelemetryBunyanStream to logger'); logger.addStream({ type: 'raw', - stream: new OpenTelemetryBunyanStream(), + stream: new OpenTelemetryBunyanStream({ + logSendingLevel: config.logSendingLevel, + }), level: logger.level(), }); } diff --git a/plugins/node/opentelemetry-instrumentation-bunyan/src/types.ts b/plugins/node/opentelemetry-instrumentation-bunyan/src/types.ts index 7a2f5f686b..8820dc8b5c 100644 --- a/plugins/node/opentelemetry-instrumentation-bunyan/src/types.ts +++ b/plugins/node/opentelemetry-instrumentation-bunyan/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 BunyanInstrumentationConfig extends InstrumentationConfig { */ disableLogSending?: boolean; + /** + * Control Log sending severity level, logs will be sent for specified severity and higher. + */ + logSendingLevel?: 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-bunyan/test/bunyan.test.ts b/plugins/node/opentelemetry-instrumentation-bunyan/test/bunyan.test.ts index 5ca3744d3d..5883dc2389 100644 --- a/plugins/node/opentelemetry-instrumentation-bunyan/test/bunyan.test.ts +++ b/plugins/node/opentelemetry-instrumentation-bunyan/test/bunyan.test.ts @@ -319,6 +319,22 @@ describe('BunyanInstrumentation', () => { assert.strictEqual(rec.body, 'hi'); assert.strictEqual(rec.attributes.aProperty, 'bar'); }); + + it('log record level configuration', () => { + instrumentation.setConfig({ logSendingLevel: SeverityNumber.WARN }); + + // Changing `disableLogSending` only has an impact on Loggers created + // *after* it is set. So we cannot test with the `log` created in + // `beforeEach()` above. + log = Logger.createLogger({ name: 'test-logger-name', stream }); + + log.info('info log'); + log.warn('warn log'); + const logRecords = memExporter.getFinishedLogRecords(); + // Only one log record match configured severity + assert.strictEqual(logRecords.length, 1); + assert.strictEqual(logRecords[0].body, 'warn log'); + }); }); describe('disabled instrumentation', () => { From 9b9ac516ea1e3adb35698119849d26be0646f71e Mon Sep 17 00:00:00 2001 From: Hector Hernandez <39923391+hectorhdzg@users.noreply.github.com> Date: Fri, 16 Feb 2024 15:59:46 -0800 Subject: [PATCH 2/5] Addressing comments --- .../README.md | 2 +- .../src/OpenTelemetryBunyanStream.ts | 26 +++++++---------- .../src/instrumentation.ts | 29 ++++++++++++++++--- .../src/types.ts | 2 +- .../test/bunyan.test.ts | 2 +- 5 files changed, 38 insertions(+), 23 deletions(-) diff --git a/plugins/node/opentelemetry-instrumentation-bunyan/README.md b/plugins/node/opentelemetry-instrumentation-bunyan/README.md index 0cdbb84aff..b4eb4eae1f 100644 --- a/plugins/node/opentelemetry-instrumentation-bunyan/README.md +++ b/plugins/node/opentelemetry-instrumentation-bunyan/README.md @@ -86,7 +86,7 @@ Log injection can be disabled with the `disableLogCorrelation: true` option. | Option | Type | Description | | ----------------------- | ----------------- | ----------- | | `disableLogSending` | `boolean` | Whether to disable [log sending](#log-sending). Default `false`. | -| `logSendingLevel` | `SeverityNumber` | Control severity level for [log sending](#log-sending). Default `SeverityNumber.UNSPECIFIED`. | +| `logSeverity` | `SeverityNumber` | Control severity level for [log sending](#log-sending). Default `SeverityNumber.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-bunyan/src/OpenTelemetryBunyanStream.ts b/plugins/node/opentelemetry-instrumentation-bunyan/src/OpenTelemetryBunyanStream.ts index 59965fdf07..8b3d1c8977 100644 --- a/plugins/node/opentelemetry-instrumentation-bunyan/src/OpenTelemetryBunyanStream.ts +++ b/plugins/node/opentelemetry-instrumentation-bunyan/src/OpenTelemetryBunyanStream.ts @@ -102,15 +102,12 @@ function severityNumberFromBunyanLevel(lvl: number) { */ export class OpenTelemetryBunyanStream { private _otelLogger: Logger; - private _logSendingLevel: SeverityNumber; - constructor(options?: { logSendingLevel?: SeverityNumber }) { + constructor() { this._otelLogger = logs.getLogger( DEFAULT_INSTRUMENTATION_SCOPE_NAME, DEFAULT_INSTRUMENTATION_SCOPE_VERSION ); - this._logSendingLevel = - options?.logSendingLevel || SeverityNumber.UNSPECIFIED; } /** @@ -152,17 +149,14 @@ export class OpenTelemetryBunyanStream { } else { fields.time = time; // Expose non-Date "time" field on attributes. } - const severityNumber = severityNumberFromBunyanLevel(level); - if (this._logSendingLevel <= severityNumber) { - const otelRec = { - timestamp, - observedTimestamp: timestamp, - severityNumber: severityNumber, - severityText: nameFromLevel[level], - body: msg, - attributes: fields, - }; - this._otelLogger.emit(otelRec); - } + const otelRec = { + timestamp, + observedTimestamp: timestamp, + severityNumber: severityNumberFromBunyanLevel(level), + severityText: nameFromLevel[level], + body: msg, + attributes: fields, + }; + this._otelLogger.emit(otelRec); } } diff --git a/plugins/node/opentelemetry-instrumentation-bunyan/src/instrumentation.ts b/plugins/node/opentelemetry-instrumentation-bunyan/src/instrumentation.ts index 206b258c13..2675e33c43 100644 --- a/plugins/node/opentelemetry-instrumentation-bunyan/src/instrumentation.ts +++ b/plugins/node/opentelemetry-instrumentation-bunyan/src/instrumentation.ts @@ -25,6 +25,7 @@ import { BunyanInstrumentationConfig } from './types'; import { VERSION } from './version'; import { OpenTelemetryBunyanStream } from './OpenTelemetryBunyanStream'; import type * as BunyanLogger from 'bunyan'; +import { SeverityNumber } from '@opentelemetry/api-logs'; const DEFAULT_CONFIG: BunyanInstrumentationConfig = { disableLogSending: false, @@ -157,12 +158,15 @@ export class BunyanInstrumentation extends InstrumentationBase< return; } this._diag.debug('Adding OpenTelemetryBunyanStream to logger'); + let currentLevel = logger.level(); + if (config.logSeverity) { + const bunyanLevel = bunyanLevelFromSeverity(config.logSeverity); + currentLevel = bunyanLevel || currentLevel; + } logger.addStream({ type: 'raw', - stream: new OpenTelemetryBunyanStream({ - logSendingLevel: config.logSendingLevel, - }), - level: logger.level(), + stream: new OpenTelemetryBunyanStream(), + level: currentLevel, }); } @@ -184,3 +188,20 @@ export class BunyanInstrumentation extends InstrumentationBase< ); } } + +function bunyanLevelFromSeverity(severity: SeverityNumber): string | undefined { + if (severity >= SeverityNumber.FATAL) { + return 'fatal'; + } else 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 'trace'; + } + return; +} diff --git a/plugins/node/opentelemetry-instrumentation-bunyan/src/types.ts b/plugins/node/opentelemetry-instrumentation-bunyan/src/types.ts index 8820dc8b5c..ee915064f5 100644 --- a/plugins/node/opentelemetry-instrumentation-bunyan/src/types.ts +++ b/plugins/node/opentelemetry-instrumentation-bunyan/src/types.ts @@ -32,7 +32,7 @@ export interface BunyanInstrumentationConfig extends InstrumentationConfig { /** * Control Log sending severity level, logs will be sent for specified severity and higher. */ - logSendingLevel?: SeverityNumber; + logSeverity?: SeverityNumber; /** * Whether to disable the injection trace-context fields, and possibly other diff --git a/plugins/node/opentelemetry-instrumentation-bunyan/test/bunyan.test.ts b/plugins/node/opentelemetry-instrumentation-bunyan/test/bunyan.test.ts index 5883dc2389..1a326778c0 100644 --- a/plugins/node/opentelemetry-instrumentation-bunyan/test/bunyan.test.ts +++ b/plugins/node/opentelemetry-instrumentation-bunyan/test/bunyan.test.ts @@ -321,7 +321,7 @@ describe('BunyanInstrumentation', () => { }); it('log record level configuration', () => { - instrumentation.setConfig({ logSendingLevel: SeverityNumber.WARN }); + instrumentation.setConfig({ logSeverity: SeverityNumber.WARN }); // Changing `disableLogSending` only has an impact on Loggers created // *after* it is set. So we cannot test with the `log` created in From fdce25c20c45c3d2ba93c3db216df7d17c888589 Mon Sep 17 00:00:00 2001 From: Hector Hernandez <39923391+hectorhdzg@users.noreply.github.com> Date: Mon, 26 Feb 2024 14:57:17 -0800 Subject: [PATCH 3/5] Update --- .../README.md | 2 +- .../src/instrumentation.ts | 6 +++--- .../test/bunyan.test.ts | 15 +++++++++++++-- 3 files changed, 17 insertions(+), 6 deletions(-) diff --git a/plugins/node/opentelemetry-instrumentation-bunyan/README.md b/plugins/node/opentelemetry-instrumentation-bunyan/README.md index b9f419d6be..5d4c2f5f28 100644 --- a/plugins/node/opentelemetry-instrumentation-bunyan/README.md +++ b/plugins/node/opentelemetry-instrumentation-bunyan/README.md @@ -87,7 +87,7 @@ Log injection can be disabled with the `disableLogCorrelation: true` option. | 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`. | +| `logSeverity` | `SeverityNumber` | Control severity level for [log sending](#log-sending). Default `SeverityNumber.UNSPECIFIED`, it will use Bunnyan 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-bunyan/src/instrumentation.ts b/plugins/node/opentelemetry-instrumentation-bunyan/src/instrumentation.ts index 2675e33c43..d3e76a74ce 100644 --- a/plugins/node/opentelemetry-instrumentation-bunyan/src/instrumentation.ts +++ b/plugins/node/opentelemetry-instrumentation-bunyan/src/instrumentation.ts @@ -158,15 +158,15 @@ export class BunyanInstrumentation extends InstrumentationBase< return; } this._diag.debug('Adding OpenTelemetryBunyanStream to logger'); - let currentLevel = logger.level(); + let streamLevel = logger.level(); if (config.logSeverity) { const bunyanLevel = bunyanLevelFromSeverity(config.logSeverity); - currentLevel = bunyanLevel || currentLevel; + streamLevel = bunyanLevel || streamLevel; } logger.addStream({ type: 'raw', stream: new OpenTelemetryBunyanStream(), - level: currentLevel, + level: streamLevel, }); } diff --git a/plugins/node/opentelemetry-instrumentation-bunyan/test/bunyan.test.ts b/plugins/node/opentelemetry-instrumentation-bunyan/test/bunyan.test.ts index 1a326778c0..3fef96b180 100644 --- a/plugins/node/opentelemetry-instrumentation-bunyan/test/bunyan.test.ts +++ b/plugins/node/opentelemetry-instrumentation-bunyan/test/bunyan.test.ts @@ -320,10 +320,10 @@ describe('BunyanInstrumentation', () => { assert.strictEqual(rec.attributes.aProperty, 'bar'); }); - it('log record level configuration', () => { + it('log record level configuration (higher than default)', () => { instrumentation.setConfig({ logSeverity: SeverityNumber.WARN }); - // Changing `disableLogSending` only has an impact on Loggers created + // Setting `logSeverity` only has an impact on Loggers created // *after* it is set. So we cannot test with the `log` created in // `beforeEach()` above. log = Logger.createLogger({ name: 'test-logger-name', stream }); @@ -335,6 +335,17 @@ describe('BunyanInstrumentation', () => { assert.strictEqual(logRecords.length, 1); assert.strictEqual(logRecords[0].body, 'warn log'); }); + + it('log record level configuration (lower than default)', () => { + instrumentation.setConfig({ logSeverity: SeverityNumber.DEBUG }); + log = Logger.createLogger({ name: 'test-logger-name', stream }); + log.info('info log'); + log.debug('debug log'); + const logRecords = memExporter.getFinishedLogRecords(); + // Only one log record match configured severity + assert.strictEqual(logRecords.length, 1); + assert.strictEqual(logRecords[0].body, 'debug log'); + }); }); describe('disabled instrumentation', () => { From 04232cc4bc7abc6c9e9a2011128177c430f36341 Mon Sep 17 00:00:00 2001 From: Hector Hernandez <39923391+hectorhdzg@users.noreply.github.com> Date: Mon, 11 Mar 2024 11:20:58 -0700 Subject: [PATCH 4/5] Update plugins/node/opentelemetry-instrumentation-bunyan/test/bunyan.test.ts Co-authored-by: Trent Mick --- .../test/bunyan.test.ts | 10 +++++++--- 1 file changed, 7 insertions(+), 3 deletions(-) diff --git a/plugins/node/opentelemetry-instrumentation-bunyan/test/bunyan.test.ts b/plugins/node/opentelemetry-instrumentation-bunyan/test/bunyan.test.ts index 3fef96b180..4d41fcc908 100644 --- a/plugins/node/opentelemetry-instrumentation-bunyan/test/bunyan.test.ts +++ b/plugins/node/opentelemetry-instrumentation-bunyan/test/bunyan.test.ts @@ -341,10 +341,14 @@ describe('BunyanInstrumentation', () => { log = Logger.createLogger({ name: 'test-logger-name', stream }); log.info('info log'); log.debug('debug log'); + + // Just the log.info() writes to `stream`. + sinon.assert.calledOnce(writeSpy); + // Both log.info() and log.debug() should be written to the OTel Logs SDK. const logRecords = memExporter.getFinishedLogRecords(); - // Only one log record match configured severity - assert.strictEqual(logRecords.length, 1); - assert.strictEqual(logRecords[0].body, 'debug log'); + assert.strictEqual(logRecords.length, 2); + assert.strictEqual(logRecords[0].body, 'info log'); + assert.strictEqual(logRecords[1].body, 'debug log'); }); }); From e9662bf362e7e5d90e624884ddbccda72fbedc1e Mon Sep 17 00:00:00 2001 From: Hector Hernandez <39923391+hectorhdzg@users.noreply.github.com> Date: Mon, 11 Mar 2024 14:40:22 -0700 Subject: [PATCH 5/5] Add test coverage --- .../test/bunyan.test.ts | 63 +++++++++++++++++-- 1 file changed, 59 insertions(+), 4 deletions(-) diff --git a/plugins/node/opentelemetry-instrumentation-bunyan/test/bunyan.test.ts b/plugins/node/opentelemetry-instrumentation-bunyan/test/bunyan.test.ts index 4d41fcc908..13f2cf3356 100644 --- a/plugins/node/opentelemetry-instrumentation-bunyan/test/bunyan.test.ts +++ b/plugins/node/opentelemetry-instrumentation-bunyan/test/bunyan.test.ts @@ -320,14 +320,40 @@ describe('BunyanInstrumentation', () => { assert.strictEqual(rec.attributes.aProperty, 'bar'); }); - it('log record level configuration (higher than default)', () => { - instrumentation.setConfig({ logSeverity: SeverityNumber.WARN }); + it('log record error level', () => { + instrumentation.setConfig({ logSeverity: SeverityNumber.FATAL }); + // Setting `logSeverity` only has an impact on Loggers created + // *after* it is set. So we cannot test with the `log` created in + // `beforeEach()` above. + log = Logger.createLogger({ name: 'test-logger-name', stream }); + log.error('error log'); + log.fatal('fatal log'); + const logRecords = memExporter.getFinishedLogRecords(); + // Only one log record match configured severity + assert.strictEqual(logRecords.length, 1); + assert.strictEqual(logRecords[0].body, 'fatal log'); + }); + it('log record error level', () => { + instrumentation.setConfig({ logSeverity: SeverityNumber.ERROR }); // Setting `logSeverity` only has an impact on Loggers created // *after* it is set. So we cannot test with the `log` created in // `beforeEach()` above. log = Logger.createLogger({ name: 'test-logger-name', stream }); + log.warn('warn log'); + log.error('error log'); + const logRecords = memExporter.getFinishedLogRecords(); + // Only one log record match configured severity + assert.strictEqual(logRecords.length, 1); + assert.strictEqual(logRecords[0].body, 'error log'); + }); + it('log record warn level', () => { + instrumentation.setConfig({ logSeverity: SeverityNumber.WARN }); + // Setting `logSeverity` only has an impact on Loggers created + // *after* it is set. So we cannot test with the `log` created in + // `beforeEach()` above. + log = Logger.createLogger({ name: 'test-logger-name', stream }); log.info('info log'); log.warn('warn log'); const logRecords = memExporter.getFinishedLogRecords(); @@ -336,12 +362,25 @@ describe('BunyanInstrumentation', () => { assert.strictEqual(logRecords[0].body, 'warn log'); }); - it('log record level configuration (lower than default)', () => { + it('log record info level', () => { + instrumentation.setConfig({ logSeverity: SeverityNumber.INFO }); + // Setting `logSeverity` only has an impact on Loggers created + // *after* it is set. So we cannot test with the `log` created in + // `beforeEach()` above. + log = Logger.createLogger({ name: 'test-logger-name', stream }); + log.debug('debug log'); + log.info('info log'); + const logRecords = memExporter.getFinishedLogRecords(); + // Only one log record match configured severity + assert.strictEqual(logRecords.length, 1); + assert.strictEqual(logRecords[0].body, 'info log'); + }); + + it('log record debug level', () => { instrumentation.setConfig({ logSeverity: SeverityNumber.DEBUG }); log = Logger.createLogger({ name: 'test-logger-name', stream }); log.info('info log'); log.debug('debug log'); - // Just the log.info() writes to `stream`. sinon.assert.calledOnce(writeSpy); // Both log.info() and log.debug() should be written to the OTel Logs SDK. @@ -350,6 +389,22 @@ describe('BunyanInstrumentation', () => { assert.strictEqual(logRecords[0].body, 'info log'); assert.strictEqual(logRecords[1].body, 'debug log'); }); + + it('log record trace level', () => { + instrumentation.setConfig({ logSeverity: SeverityNumber.TRACE }); + log = Logger.createLogger({ name: 'test-logger-name', stream }); + log.info('info log'); + log.debug('debug log'); + log.debug('trace log'); + // Just the log.info() writes to `stream`. + sinon.assert.calledOnce(writeSpy); + // Both log.info() and log.debug() should be written to the OTel Logs SDK. + const logRecords = memExporter.getFinishedLogRecords(); + assert.strictEqual(logRecords.length, 3); + assert.strictEqual(logRecords[0].body, 'info log'); + assert.strictEqual(logRecords[1].body, 'debug log'); + assert.strictEqual(logRecords[2].body, 'trace log'); + }); }); describe('disabled instrumentation', () => {