diff --git a/packages/instrumentation-pino/src/instrumentation.ts b/packages/instrumentation-pino/src/instrumentation.ts index eb5d620384..b8305866ec 100644 --- a/packages/instrumentation-pino/src/instrumentation.ts +++ b/packages/instrumentation-pino/src/instrumentation.ts @@ -72,10 +72,12 @@ export class PinoInstrumentation extends InstrumentationBase { - return Object.assign( - otelMixin(ctx, level), - origMixin(ctx, level, ...rest) - ); + const otelMixinResult = otelMixin(ctx, level); + if (config.passLogCorrelationToMixin) { + return origMixin(otelMixinResult, level, ...rest); + } else { + return Object.assign(otelMixinResult, origMixin(ctx, level, ...rest)); + } }; } @@ -184,14 +186,17 @@ export class PinoInstrumentation extends InstrumentationBase = {}; + if (logKeys.traceId) record[logKeys.traceId] = spanContext.traceId; + if (logKeys.spanId) record[logKeys.spanId] = spanContext.spanId; + if (logKeys.traceFlags) + record[logKeys.traceFlags] = `0${spanContext.traceFlags.toString(16)}`; + instrumentation._callHook(span, record, level); return record; diff --git a/packages/instrumentation-pino/src/types.ts b/packages/instrumentation-pino/src/types.ts index 803b3b734e..e773637967 100644 --- a/packages/instrumentation-pino/src/types.ts +++ b/packages/instrumentation-pino/src/types.ts @@ -38,6 +38,13 @@ export interface PinoInstrumentationConfig extends InstrumentationConfig { */ disableLogCorrelation?: boolean; + /** + * Whether to pass the injected trace-context fields into the + * mixin function's context. + * @default false + */ + passLogCorrelationToMixin?: boolean; + /** * A function that allows injecting additional fields in log records. It is * called, as `logHook(span, record)`, for each log record emitted in a valid @@ -50,8 +57,8 @@ export interface PinoInstrumentationConfig extends InstrumentationConfig { * available. */ logKeys?: { - traceId: string; - spanId: string; - traceFlags: string; + traceId?: string; + spanId?: string; + traceFlags?: string; }; } diff --git a/packages/instrumentation-pino/test/pino.test.ts b/packages/instrumentation-pino/test/pino.test.ts index b8269cb741..5e0bac49c1 100644 --- a/packages/instrumentation-pino/test/pino.test.ts +++ b/packages/instrumentation-pino/test/pino.test.ts @@ -174,6 +174,47 @@ describe('PinoInstrumentation', () => { }); }); + it('injects span context to records with partial custom keys', () => { + const logKeys = { + traceId: 'traceId', + spanId: 'spanId', + }; + instrumentation.setConfig({ logKeys }); + tracer.startActiveSpan('abc', span => { + logger.info('a message'); + span.end(); + + sinon.assert.calledOnce(writeSpy); + const record = JSON.parse(writeSpy.firstCall.args[0].toString()); + const { traceId, spanId, traceFlags } = span.spanContext(); + assert.strictEqual(record['traceId'], traceId); + assert.strictEqual(record['spanId'], spanId); + assert.strictEqual(record['trace_id'], undefined); + assert.strictEqual(record['span_id'], undefined); + assert.strictEqual(record['trace_flags'], traceFlags); + assert.strictEqual(record['msg'], 'a message'); + }); + }); + + it('injects span context to records with an explicitly undefined custom key', () => { + const logKeys = { + traceFlags: undefined, + }; + instrumentation.setConfig({ logKeys }); + tracer.startActiveSpan('abc', span => { + logger.info('a message'); + span.end(); + + sinon.assert.calledOnce(writeSpy); + const record = JSON.parse(writeSpy.firstCall.args[0].toString()); + const { traceId, spanId } = span.spanContext(); + assert.strictEqual(record['trace_id'], traceId); + assert.strictEqual(record['span_id'], spanId); + assert.strictEqual(record['trace_flags'], undefined); + assert.strictEqual(record['msg'], 'a message'); + }); + }); + it('injects span context to child logger records', () => { const child = logger.child({ childField: 42 }); tracer.startActiveSpan('abc', span => { @@ -440,6 +481,52 @@ describe('PinoInstrumentation', () => { assert.strictEqual(record['span_id'], spanId); }); }); + + it('ensures user mixin can override values', () => { + const logger = pino( + { + mixin(mergeObject: object) { + return { ...mergeObject, trace_id: '123' }; + }, + }, + process.stdout + ); + instrumentation.setConfig({ + passLogCorrelationToMixin: true, + }); + tracer.startActiveSpan('abc', span => { + logger.info('a message'); + span.end(); + + const { spanId } = span.spanContext(); + const record = JSON.parse(stdoutSpy.firstCall.args[0].toString()); + assert.strictEqual(record['trace_id'], '123'); + assert.strictEqual(record['span_id'], spanId); + }); + }); + + it('ensures user mixin can eliminate values', () => { + const logger = pino( + { + mixin(mergeObject: object) { + return { ...mergeObject, trace_id: undefined }; + }, + }, + process.stdout + ); + instrumentation.setConfig({ + passLogCorrelationToMixin: true, + }); + tracer.startActiveSpan('abc', span => { + logger.info('a message'); + span.end(); + + const { spanId } = span.spanContext(); + const record = JSON.parse(stdoutSpy.firstCall.args[0].toString()); + assert.strictEqual(record['trace_id'], undefined); + assert.strictEqual(record['span_id'], spanId); + }); + }); }); describe('log sending', () => {