diff --git a/packages/instrumentation-winston/package.json b/packages/instrumentation-winston/package.json index 22754881d5..b1674b5221 100644 --- a/packages/instrumentation-winston/package.json +++ b/packages/instrumentation-winston/package.json @@ -10,10 +10,7 @@ "directory": "packages/instrumentation-winston" }, "scripts": { - "test": "npm run test-v1-v2 && npm run test-v3 && nyc merge .nyc_output ./coverage/coverage-final.json", - "test-v1-v2": "tav winston 2.4.7 npm run test-run", - "test-v3": "npm run test-run", - "test-run": "nyc --no-clean mocha 'test/**/*.test.ts'", + "test": "nyc mocha 'test/**/*.test.ts'", "test-all-versions": "tav", "tdd": "npm run test-run -- --watch-extensions ts --watch", "clean": "rimraf build/*", diff --git a/packages/instrumentation-winston/test/winston.test.ts b/packages/instrumentation-winston/test/winston.test.ts index d9e848b845..f395b1c7cb 100644 --- a/packages/instrumentation-winston/test/winston.test.ts +++ b/packages/instrumentation-winston/test/winston.test.ts @@ -61,7 +61,11 @@ describe('WinstonInstrumentation', () => { cli, } - function initLogger(levelsType?: LevelsType) { + /** + * Set `logger` to a new Winston logger instance with the given + * configuration, and setup with `writeSpy` to spy on emitted logs. + */ + function initLogger(levelsType?: LevelsType, formatType?: string) { const winston = require('winston'); let levels = winston.config.npm.levels; @@ -71,6 +75,19 @@ describe('WinstonInstrumentation', () => { levels = winston.config.cli.levels; } + let format; + switch (formatType) { + case 'colorize': + format = winston.format.colorize(); + break; + case 'none': + case undefined: + format = undefined; + break; + default: + throw new Error(`unknown formatType: "${formatType}"`); + } + const stream = new Writable(); stream._write = () => {}; writeSpy = sinon.spy(stream, 'write'); @@ -80,6 +97,7 @@ describe('WinstonInstrumentation', () => { logger = winston.createLogger({ level: 'debug', levels: levels, + format, transports: [ new winston.transports.Stream({ stream, @@ -91,6 +109,7 @@ describe('WinstonInstrumentation', () => { isWinston2 = true; logger = new winston.Logger({ levels: levels, + format, transports: [ new winston.transports.File({ stream, @@ -236,6 +255,32 @@ describe('WinstonInstrumentation', () => { } }); + it('emit LogRecord with correct severity* when colorize() formatter is used', () => { + if (!isWinston2) { + instrumentation.setConfig({ + disableLogSending: false, + }); + initLogger(LevelsType.npm, 'colorize'); + + logger.log('debug', kMessage); + logger.log('info', kMessage); + logger.log('warn', kMessage); + const logRecords = memoryLogExporter.getFinishedLogRecords(); + assert.strictEqual(logRecords.length, 3); + assert.strictEqual(logRecords[0].severityText, 'debug'); + assert.strictEqual(logRecords[0].severityNumber, 5); + assert.strictEqual(logRecords[0].body, kMessage); + assert.strictEqual(logRecords[1].severityText, 'info'); + assert.strictEqual(logRecords[1].severityNumber, 9); + assert.strictEqual(logRecords[1].body, kMessage); + assert.strictEqual(logRecords[2].severityText, 'warn'); + assert.strictEqual(logRecords[2].severityNumber, 13); + assert.strictEqual(logRecords[2].body, kMessage); + + initLogger(); + } + }); + it('do not emit log record if @opentelemetry/winston-transport load fails', () => { const module = require('module'); const originalRequire = module.prototype.require; diff --git a/packages/winston-transport/src/utils.ts b/packages/winston-transport/src/utils.ts index 976d0f55da..c2a658d713 100644 --- a/packages/winston-transport/src/utils.ts +++ b/packages/winston-transport/src/utils.ts @@ -60,19 +60,23 @@ function getSeverityNumber(level: string): SeverityNumber | undefined { } export function emitLogRecord( - record: Record, + record: Record, logger: Logger ): void { const { message, level, ...splat } = record; const attributes: LogAttributes = {}; + // Ensures the log level is read from a symbol property, avoiding any + // accidental inclusion of ANSI color codes that may be present in the string + // property. + const levelSym = record[Symbol.for('level')]; for (const key in splat) { if (Object.prototype.hasOwnProperty.call(splat, key)) { attributes[key] = splat[key]; } } const logRecord: LogRecord = { - severityNumber: getSeverityNumber(level), - severityText: level, + severityNumber: getSeverityNumber(levelSym), + severityText: levelSym, body: message, attributes: attributes, }; diff --git a/packages/winston-transport/test/openTelemetryTransport.test.ts b/packages/winston-transport/test/openTelemetryTransport.test.ts index 8440ab38a6..d6cf91a9bc 100644 --- a/packages/winston-transport/test/openTelemetryTransport.test.ts +++ b/packages/winston-transport/test/openTelemetryTransport.test.ts @@ -74,13 +74,18 @@ describe('OpenTelemetryTransportV3', () => { it('npm levels', () => { const callback = () => {}; const transport = new OpenTelemetryTransportV3(); - transport.log({ message: kMessage, level: 'error' }, callback); - transport.log({ message: kMessage, level: 'warn' }, callback); - transport.log({ message: kMessage, level: 'info' }, callback); - transport.log({ message: kMessage, level: 'http' }, callback); - transport.log({ message: kMessage, level: 'verbose' }, callback); - transport.log({ message: kMessage, level: 'debug' }, callback); - transport.log({ message: kMessage, level: 'silly' }, callback); + const sym = Symbol.for('level'); + for (const level of [ + 'error', + 'warn', + 'info', + 'http', + 'verbose', + 'debug', + 'silly', + ]) { + transport.log({ message: kMessage, level, [sym]: level }, callback); + } const logRecords = memoryLogExporter.getFinishedLogRecords(); assert.strictEqual(logRecords.length, 7); assert.strictEqual(logRecords[0].severityNumber, SeverityNumber.ERROR); @@ -95,16 +100,21 @@ describe('OpenTelemetryTransportV3', () => { it('cli levels', () => { const callback = () => {}; const transport = new OpenTelemetryTransportV3(); - transport.log({ message: kMessage, level: 'error' }, callback); - transport.log({ message: kMessage, level: 'warn' }, callback); - transport.log({ message: kMessage, level: 'help' }, callback); - transport.log({ message: kMessage, level: 'data' }, callback); - transport.log({ message: kMessage, level: 'info' }, callback); - transport.log({ message: kMessage, level: 'debug' }, callback); - transport.log({ message: kMessage, level: 'verbose' }, callback); - transport.log({ message: kMessage, level: 'prompt' }, callback); - transport.log({ message: kMessage, level: 'input' }, callback); - transport.log({ message: kMessage, level: 'silly' }, callback); + const sym = Symbol.for('level'); + for (const level of [ + 'error', + 'warn', + 'help', + 'data', + 'info', + 'debug', + 'verbose', + 'prompt', + 'input', + 'silly', + ]) { + transport.log({ message: kMessage, level, [sym]: level }, callback); + } const logRecords = memoryLogExporter.getFinishedLogRecords(); assert.strictEqual(logRecords.length, 10); assert.strictEqual(logRecords[0].severityNumber, SeverityNumber.ERROR); @@ -122,14 +132,19 @@ describe('OpenTelemetryTransportV3', () => { it('syslog levels', () => { const callback = () => {}; const transport = new OpenTelemetryTransportV3(); - transport.log({ message: kMessage, level: 'emerg' }, callback); - transport.log({ message: kMessage, level: 'alert' }, callback); - transport.log({ message: kMessage, level: 'crit' }, callback); - transport.log({ message: kMessage, level: 'error' }, callback); - transport.log({ message: kMessage, level: 'warning' }, callback); - transport.log({ message: kMessage, level: 'notice' }, callback); - transport.log({ message: kMessage, level: 'info' }, callback); - transport.log({ message: kMessage, level: 'debug' }, callback); + const sym = Symbol.for('level'); + for (const level of [ + 'emerg', + 'alert', + 'crit', + 'error', + 'warning', + 'notice', + 'info', + 'debug', + ]) { + transport.log({ message: kMessage, level, [sym]: level }, callback); + } const logRecords = memoryLogExporter.getFinishedLogRecords(); assert.strictEqual(logRecords.length, 8); assert.strictEqual(logRecords[0].severityNumber, SeverityNumber.FATAL3);