diff --git a/package-lock.json b/package-lock.json index 33a121f588..9606105e64 100644 --- a/package-lock.json +++ b/package-lock.json @@ -36157,7 +36157,6 @@ "version": "0.37.2", "license": "Apache-2.0", "dependencies": { - "@opentelemetry/core": "^1.8.0", "@opentelemetry/instrumentation": "^0.46.0", "@opentelemetry/semantic-conventions": "^1.0.0", "@opentelemetry/sql-common": "^0.40.0", @@ -44848,7 +44847,6 @@ "@opentelemetry/api": "^1.3.0", "@opentelemetry/context-async-hooks": "^1.8.0", "@opentelemetry/contrib-test-utils": "^0.35.1", - "@opentelemetry/core": "^1.8.0", "@opentelemetry/instrumentation": "^0.46.0", "@opentelemetry/sdk-trace-base": "^1.8.0", "@opentelemetry/sdk-trace-node": "^1.8.0", diff --git a/packages/opentelemetry-host-metrics/src/BaseMetrics.ts b/packages/opentelemetry-host-metrics/src/BaseMetrics.ts index 6d36f169d4..fa9453ff22 100644 --- a/packages/opentelemetry-host-metrics/src/BaseMetrics.ts +++ b/packages/opentelemetry-host-metrics/src/BaseMetrics.ts @@ -46,7 +46,7 @@ export abstract class BaseMetrics { constructor(config: MetricsCollectorConfig) { this._name = config.name || DEFAULT_NAME; const meterProvider = - config.meterProvider! || api.metrics.getMeterProvider(); + config.meterProvider || api.metrics.getMeterProvider(); if (!config.meterProvider) { this._logger.warn('No meter provider, using default'); } diff --git a/packages/opentelemetry-host-metrics/src/enum.ts b/packages/opentelemetry-host-metrics/src/enum.ts index c23bc57587..acfe4adc05 100644 --- a/packages/opentelemetry-host-metrics/src/enum.ts +++ b/packages/opentelemetry-host-metrics/src/enum.ts @@ -27,9 +27,16 @@ export enum METRIC_NAMES { PROCESS_MEMORY_USAGE = 'process.memory.usage', } -export enum METRIC_ATTRIBUTES { +export enum ATTRIBUTE_NAMES { SYSTEM_CPU_LOGICAL_NUMBER = 'system.cpu.logical_number', SYSTEM_CPU_STATE = 'system.cpu.state', + SYSTEM_MEMORY_STATE = 'system.memory.state', + SYSTEM_DEVICE = 'system.device', + SYSTEM_NETWORK_DIRECTION = 'system.network.direction', + SYSTEM_NETWORK_STATE = 'system.network.state', + // TODO: change value if semconv changes + // https://github.com/open-telemetry/opentelemetry-specification/issues/3776 + PROCESS_CPU_STATE = 'state', } export enum CPU_LABELS { @@ -41,7 +48,6 @@ export enum CPU_LABELS { } export enum NETWORK_LABELS { - DEVICE = 'device', RECEIVE = 'receive', TRANSMIT = 'transmit', } diff --git a/packages/opentelemetry-host-metrics/src/metric.ts b/packages/opentelemetry-host-metrics/src/metric.ts index 022ba8d051..2604e95d00 100644 --- a/packages/opentelemetry-host-metrics/src/metric.ts +++ b/packages/opentelemetry-host-metrics/src/metric.ts @@ -40,8 +40,8 @@ export class HostMetrics extends BaseMetrics { observableResult: api.BatchObservableResult, cpuUsages: CpuUsageData[] ): void { - const stateAttr = enums.METRIC_ATTRIBUTES.SYSTEM_CPU_STATE; - const cpuAttr = enums.METRIC_ATTRIBUTES.SYSTEM_CPU_LOGICAL_NUMBER; + const stateAttr = enums.ATTRIBUTE_NAMES.SYSTEM_CPU_STATE; + const cpuAttr = enums.ATTRIBUTE_NAMES.SYSTEM_CPU_LOGICAL_NUMBER; for (let i = 0, j = cpuUsages.length; i < j; i++) { const cpuUsage = cpuUsages[i]; @@ -93,25 +93,27 @@ export class HostMetrics extends BaseMetrics { observableResult: api.BatchObservableResult, processCpuUsage: ProcessCpuUsageData ): void { + const stateAttr = enums.ATTRIBUTE_NAMES.PROCESS_CPU_STATE; + observableResult.observe(this._processCpuTime, processCpuUsage.user, { - state: enums.CPU_LABELS.USER, + [stateAttr]: enums.CPU_LABELS.USER, }); observableResult.observe(this._processCpuTime, processCpuUsage.system, { - state: enums.CPU_LABELS.SYSTEM, + [stateAttr]: enums.CPU_LABELS.SYSTEM, }); observableResult.observe( this._processCpuUtilization, processCpuUsage.userP, { - state: enums.CPU_LABELS.USER, + [stateAttr]: enums.CPU_LABELS.USER, } ); observableResult.observe( this._processCpuUtilization, processCpuUsage.systemP, { - state: enums.CPU_LABELS.SYSTEM, + [stateAttr]: enums.CPU_LABELS.SYSTEM, } ); } @@ -120,18 +122,20 @@ export class HostMetrics extends BaseMetrics { observableResult: api.BatchObservableResult, memUsage: MemoryData ): void { + const stateAttr = enums.ATTRIBUTE_NAMES.SYSTEM_MEMORY_STATE; + observableResult.observe(this._memoryUsage, memUsage.used, { - state: enums.MEMORY_LABELS.USED, + [stateAttr]: enums.MEMORY_LABELS.USED, }); observableResult.observe(this._memoryUsage, memUsage.free, { - state: enums.MEMORY_LABELS.FREE, + [stateAttr]: enums.MEMORY_LABELS.FREE, }); observableResult.observe(this._memoryUtilization, memUsage.usedP, { - state: enums.MEMORY_LABELS.USED, + [stateAttr]: enums.MEMORY_LABELS.USED, }); observableResult.observe(this._memoryUtilization, memUsage.freeP, { - state: enums.MEMORY_LABELS.FREE, + [stateAttr]: enums.MEMORY_LABELS.FREE, }); } @@ -146,33 +150,36 @@ export class HostMetrics extends BaseMetrics { observableResult: api.BatchObservableResult, networkUsages: NetworkData[] ): void { + const deviceAttr = enums.ATTRIBUTE_NAMES.SYSTEM_DEVICE; + const directionAttr = enums.ATTRIBUTE_NAMES.SYSTEM_NETWORK_DIRECTION; + for (let i = 0, j = networkUsages.length; i < j; i++) { const networkUsage = networkUsages[i]; observableResult.observe(this._networkDropped, networkUsage.rx_dropped, { - [enums.NETWORK_LABELS.DEVICE]: networkUsage.iface, - direction: enums.NETWORK_LABELS.RECEIVE, + [deviceAttr]: networkUsage.iface, + [directionAttr]: enums.NETWORK_LABELS.RECEIVE, }); observableResult.observe(this._networkDropped, networkUsage.tx_dropped, { - device: networkUsage.iface, - direction: enums.NETWORK_LABELS.TRANSMIT, + [deviceAttr]: networkUsage.iface, + [directionAttr]: enums.NETWORK_LABELS.TRANSMIT, }); observableResult.observe(this._networkErrors, networkUsage.rx_errors, { - device: networkUsage.iface, - direction: enums.NETWORK_LABELS.RECEIVE, + [deviceAttr]: networkUsage.iface, + [directionAttr]: enums.NETWORK_LABELS.RECEIVE, }); observableResult.observe(this._networkErrors, networkUsage.tx_errors, { - device: networkUsage.iface, - direction: enums.NETWORK_LABELS.TRANSMIT, + [deviceAttr]: networkUsage.iface, + [directionAttr]: enums.NETWORK_LABELS.TRANSMIT, }); observableResult.observe(this._networkIo, networkUsage.rx_bytes, { - device: networkUsage.iface, - direction: enums.NETWORK_LABELS.RECEIVE, + [deviceAttr]: networkUsage.iface, + [directionAttr]: enums.NETWORK_LABELS.RECEIVE, }); observableResult.observe(this._networkIo, networkUsage.tx_bytes, { - device: networkUsage.iface, - direction: enums.NETWORK_LABELS.TRANSMIT, + [deviceAttr]: networkUsage.iface, + [directionAttr]: enums.NETWORK_LABELS.TRANSMIT, }); } } diff --git a/packages/opentelemetry-host-metrics/src/stats/common.ts b/packages/opentelemetry-host-metrics/src/stats/common.ts index 520dc2cd2b..6803905fb7 100644 --- a/packages/opentelemetry-host-metrics/src/stats/common.ts +++ b/packages/opentelemetry-host-metrics/src/stats/common.ts @@ -19,7 +19,7 @@ import * as os from 'os'; import { CpuUsageData, MemoryData, ProcessCpuUsageData } from '../types'; const MILLISECOND = 1 / 1e3; -let cpuUsageTime: number | undefined = undefined; +const MICROSECOND = 1 / 1e6; /** * We get data as soon as we load the module so the 1st collect @@ -77,19 +77,38 @@ export function getCpuUsageData(): CpuUsageData[] { } /** - * It returns process cpu load delta from last time - to be used with SumObservers. - * When called first time it will return 0 and then delta will be calculated + * We get data as soon as we load the module so the 1st collect + * of the metric already has valuable data to be sent. + */ +let prevProcData: { time: number; usage: NodeJS.CpuUsage } = { + time: Date.now(), + usage: process.cpuUsage(), +}; + +/** + * Gets the process CPU usage and returns + * - the time spent in `user` state + * - the time spent in `system` state + * - the % of time in `user` state since last measurement + * - the % of time in `system` state since last measurement */ export function getProcessCpuUsageData(): ProcessCpuUsageData { - if (typeof cpuUsageTime !== 'number') { - cpuUsageTime = new Date().getTime() - process.uptime() * 1000; - } - const timeElapsed = (new Date().getTime() - cpuUsageTime) / 1000; - const cpuUsage: NodeJS.CpuUsage = process.cpuUsage(); - const user = cpuUsage.user * MILLISECOND; - const system = cpuUsage.system * MILLISECOND; - const userP = user / timeElapsed; - const systemP = system / timeElapsed; + const currentTime = Date.now(); + const currentUsage = process.cpuUsage(); + const prevUsage = prevProcData.usage; + // According to semantic conventions we need to divide by + // - time elapsed (in microseconds to match `process.cpuUsage()` units) + // - number of CPUs + const timeElapsed = (currentTime - prevProcData.time) * 1000; + const cpusTimeElapsed = timeElapsed * prevOsData.cpus.length; + + const user = currentUsage.user * MICROSECOND; + const system = currentUsage.system * MICROSECOND; + const userP = (currentUsage.user - prevUsage.user) / cpusTimeElapsed; + const systemP = (currentUsage.system - prevUsage.system) / cpusTimeElapsed; + + prevProcData = { time: currentTime, usage: currentUsage }; + return { user, system, diff --git a/packages/opentelemetry-host-metrics/test/metric.test.ts b/packages/opentelemetry-host-metrics/test/metric.test.ts index 64e5cf3d90..196e74e702 100644 --- a/packages/opentelemetry-host-metrics/test/metric.test.ts +++ b/packages/opentelemetry-host-metrics/test/metric.test.ts @@ -27,10 +27,11 @@ import { import * as assert from 'assert'; import * as os from 'os'; import * as sinon from 'sinon'; -import { METRIC_ATTRIBUTES } from '../src/enum'; +import { ATTRIBUTE_NAMES } from '../src/enum'; import { HostMetrics } from '../src'; const cpuJson = require('./mocks/cpu.json'); +const processJson = require('./mocks/process.json'); const networkJson = require('./mocks/network.json'); class TestMetricReader extends MetricReader { @@ -75,7 +76,20 @@ const mockedOS = { }, }; -const INTERVAL = 3000; +const mockedProcess = { + uptime: function () { + return 0; + }, + procIdx: 0, + cpuUsage: function () { + return processJson[this.procIdx++ % 2]; + }, + memoryUsage: { + rss: function () { + return 123456; + }, + }, +}; describe('Host Metrics', () => { let meterProvider: MeterProvider; @@ -113,24 +127,17 @@ describe('Host Metrics', () => { sandbox = sinon.createSandbox(); sandbox.useFakeTimers(); - sandbox.stub(os, 'freemem').callsFake(() => { - return mockedOS.freemem(); - }); - sandbox.stub(os, 'totalmem').returns(mockedOS.totalmem()); + sandbox.stub(os, 'freemem').callsFake(mockedOS.freemem); + sandbox.stub(os, 'totalmem').callsFake(mockedOS.totalmem); sandbox.stub(os, 'cpus').callsFake(() => mockedOS.cpus()); - sandbox.stub(process, 'uptime').returns(0); - sandbox.stub(SI, 'networkStats').callsFake(() => { - return mockedSI.networkStats(); - }); - sandbox.stub(process, 'cpuUsage').callsFake(() => { - return { - user: 90713560, - system: 63192630, - }; - }); - sandbox.stub(process.memoryUsage, 'rss').callsFake(() => { - return 123456; - }); + sandbox.stub(process, 'uptime').callsFake(mockedProcess.uptime); + sandbox + .stub(process, 'cpuUsage') + .callsFake(() => mockedProcess.cpuUsage()); + sandbox + .stub(process.memoryUsage, 'rss') + .callsFake(mockedProcess.memoryUsage.rss); + sandbox.stub(SI, 'networkStats').callsFake(mockedSI.networkStats); reader = new TestMetricReader(); @@ -144,13 +151,9 @@ describe('Host Metrics', () => { await hostMetrics.start(); - const dateStub = sandbox - .stub(Date.prototype, 'getTime') - .returns(process.uptime() * 1000 + 1); // Drop first frame cpu metrics, see - // src/common.ts getCpuUsageData + // src/common.ts getCpuUsageData/getProcessCpuUsageData await reader.collect(); - dateStub.returns(process.uptime() * 1000 + INTERVAL); // advance the clock for the next collection sandbox.clock.tick(1000); @@ -162,8 +165,12 @@ describe('Host Metrics', () => { sandbox.restore(); }); - const sysCpuStateAttr = METRIC_ATTRIBUTES.SYSTEM_CPU_STATE; - const sysCpuNumAttr = METRIC_ATTRIBUTES.SYSTEM_CPU_LOGICAL_NUMBER; + const sysCpuStateAttr = ATTRIBUTE_NAMES.SYSTEM_CPU_STATE; + const sysCpuNumAttr = ATTRIBUTE_NAMES.SYSTEM_CPU_LOGICAL_NUMBER; + const sysMemStateAttr = ATTRIBUTE_NAMES.SYSTEM_MEMORY_STATE; + const sysDeviceAttr = ATTRIBUTE_NAMES.SYSTEM_DEVICE; + const sysNetDirAttr = ATTRIBUTE_NAMES.SYSTEM_NETWORK_DIRECTION; + const procCpuStateAttr = ATTRIBUTE_NAMES.PROCESS_CPU_STATE; it('should export CPU time metrics', async () => { const metric = await getRecords(reader, 'system.cpu.time'); @@ -280,50 +287,74 @@ describe('Host Metrics', () => { it('should export Memory usage metrics', async () => { const metric = await getRecords(reader, 'system.memory.usage'); - ensureValue(metric, { state: 'used' }, 1024 * 1024 - 1024); - ensureValue(metric, { state: 'free' }, 1024); + ensureValue(metric, { [sysMemStateAttr]: 'used' }, 1024 * 1024 - 1024); + ensureValue(metric, { [sysMemStateAttr]: 'free' }, 1024); }); it('should export Memory utilization metrics', async () => { const metric = await getRecords(reader, 'system.memory.utilization'); - ensureValue(metric, { state: 'used' }, 0.9990234375); - ensureValue(metric, { state: 'free' }, 0.0009765625); + ensureValue(metric, { [sysMemStateAttr]: 'used' }, 0.9990234375); + ensureValue(metric, { [sysMemStateAttr]: 'free' }, 0.0009765625); }); it('should export Network io dropped', async () => { const metric = await getRecords(reader, 'system.network.dropped'); - ensureValue(metric, { direction: 'receive', device: 'eth0' }, 1200); - ensureValue(metric, { direction: 'transmit', device: 'eth0' }, 12); + ensureValue( + metric, + { [sysNetDirAttr]: 'receive', [sysDeviceAttr]: 'eth0' }, + 1200 + ); + ensureValue( + metric, + { [sysNetDirAttr]: 'transmit', [sysDeviceAttr]: 'eth0' }, + 12 + ); }); it('should export Network io errors', async () => { const metric = await getRecords(reader, 'system.network.errors'); - ensureValue(metric, { direction: 'receive', device: 'eth0' }, 3); - ensureValue(metric, { direction: 'transmit', device: 'eth0' }, 15); + ensureValue( + metric, + { [sysNetDirAttr]: 'receive', [sysDeviceAttr]: 'eth0' }, + 3 + ); + ensureValue( + metric, + { [sysNetDirAttr]: 'transmit', [sysDeviceAttr]: 'eth0' }, + 15 + ); }); it('should export Network io bytes', async () => { const metric = await getRecords(reader, 'system.network.io'); - ensureValue(metric, { direction: 'receive', device: 'eth0' }, 123123); - ensureValue(metric, { direction: 'transmit', device: 'eth0' }, 321321); + ensureValue( + metric, + { [sysNetDirAttr]: 'receive', [sysDeviceAttr]: 'eth0' }, + 123123 + ); + ensureValue( + metric, + { [sysNetDirAttr]: 'transmit', [sysDeviceAttr]: 'eth0' }, + 321321 + ); }); it('should export Process CPU time metrics', async () => { const metric = await getRecords(reader, 'process.cpu.time'); - ensureValue(metric, { state: 'user' }, 90713.56); - ensureValue(metric, { state: 'system' }, 63192.630000000005); + ensureValue(metric, { [procCpuStateAttr]: 'user' }, 90.71356); + ensureValue(metric, { [procCpuStateAttr]: 'system' }, 63.192629999999994); }); it('should export Process CPU utilization metrics', async () => { const metric = await getRecords(reader, 'process.cpu.utilization'); - ensureValue(metric, { state: 'user' }, 30247.935978659552); - ensureValue(metric, { state: 'system' }, 21071.23374458153); + ensureValue(metric, { [procCpuStateAttr]: 'user' }, 0.025); + ensureValue(metric, { [procCpuStateAttr]: 'system' }, 0.05); }); it('should export Process Memory usage metrics', async () => { diff --git a/packages/opentelemetry-host-metrics/test/mocks/process.json b/packages/opentelemetry-host-metrics/test/mocks/process.json new file mode 100644 index 0000000000..11ba6c2f57 --- /dev/null +++ b/packages/opentelemetry-host-metrics/test/mocks/process.json @@ -0,0 +1,10 @@ +[ + { + "user": 90663560, + "system": 63092630 + }, + { + "user": 90713560, + "system": 63192630 + } +] \ No newline at end of file diff --git a/plugins/node/opentelemetry-instrumentation-aws-sdk/src/services/MessageAttributes.ts b/plugins/node/opentelemetry-instrumentation-aws-sdk/src/services/MessageAttributes.ts index a894d5ad86..1f7e6213c7 100644 --- a/plugins/node/opentelemetry-instrumentation-aws-sdk/src/services/MessageAttributes.ts +++ b/plugins/node/opentelemetry-instrumentation-aws-sdk/src/services/MessageAttributes.ts @@ -55,6 +55,9 @@ class ContextGetter keys( carrier: SQS.MessageBodyAttributeMap | SNS.MessageAttributeMap ): string[] { + if (carrier == null) { + return []; + } return Object.keys(carrier); } diff --git a/plugins/node/opentelemetry-instrumentation-aws-sdk/test/MessageAttributes.test.ts b/plugins/node/opentelemetry-instrumentation-aws-sdk/test/MessageAttributes.test.ts index 51d63442f0..826fa3f15e 100644 --- a/plugins/node/opentelemetry-instrumentation-aws-sdk/test/MessageAttributes.test.ts +++ b/plugins/node/opentelemetry-instrumentation-aws-sdk/test/MessageAttributes.test.ts @@ -17,10 +17,12 @@ import { expect } from 'expect'; import { MAX_MESSAGE_ATTRIBUTES, + contextGetter, contextSetter, injectPropagationContext, addPropagationFieldsToAttributeNames, } from '../src/services/MessageAttributes'; +import { SNS, SQS } from '../src/aws-sdk.types'; describe('MessageAttributes', () => { describe('MAX_MESSAGE_ATTRIBUTES', () => { @@ -29,6 +31,30 @@ describe('MessageAttributes', () => { }); }); + describe('contextGetter', () => { + it('returns context keys if there are available attributes', () => { + const contextCarrier = { + key1: { DataType: 'String', StringValue: 'value1' }, + }; + const expectedKeys = ['key1']; + + expect(contextGetter.keys(contextCarrier)).toEqual(expectedKeys); + }); + + it('returns empty context keys if there are no available attributes', () => { + const contextCarrier = undefined; + const expectedKeys: string[] = []; + + expect( + contextGetter.keys( + contextCarrier as unknown as + | SQS.MessageBodyAttributeMap + | SNS.MessageAttributeMap + ) + ).toEqual(expectedKeys); + }); + }); + describe('contextSetter', () => { it('should set parent context in sqs receive callback', () => { const contextKey = 'key'; diff --git a/plugins/node/opentelemetry-instrumentation-graphql/src/instrumentation.ts b/plugins/node/opentelemetry-instrumentation-graphql/src/instrumentation.ts index 217744e3da..0f60623da3 100644 --- a/plugins/node/opentelemetry-instrumentation-graphql/src/instrumentation.ts +++ b/plugins/node/opentelemetry-instrumentation-graphql/src/instrumentation.ts @@ -59,6 +59,7 @@ const DEFAULT_CONFIG: GraphQLInstrumentationConfig = { mergeItems: false, depth: -1, allowValues: false, + ignoreResolveSpans: false, }; const supportedVersions = ['>=14']; @@ -474,7 +475,11 @@ export class GraphQLInstrumentation extends InstrumentationBase { if (!contextValue) { contextValue = {}; } - if (contextValue[OTEL_GRAPHQL_DATA_SYMBOL]) { + + if ( + contextValue[OTEL_GRAPHQL_DATA_SYMBOL] || + this._getConfig().ignoreResolveSpans + ) { return { schema, document, diff --git a/plugins/node/opentelemetry-instrumentation-graphql/src/types.ts b/plugins/node/opentelemetry-instrumentation-graphql/src/types.ts index b206b449f4..7cedff14a8 100644 --- a/plugins/node/opentelemetry-instrumentation-graphql/src/types.ts +++ b/plugins/node/opentelemetry-instrumentation-graphql/src/types.ts @@ -39,6 +39,13 @@ export interface GraphQLInstrumentationConfig extends InstrumentationConfig { */ depth?: number; + /** + * Do not create spans for resolvers. + * + * @default false + */ + ignoreResolveSpans?: boolean; + /** * Don't create spans for the execution of the default resolver on object properties. * diff --git a/plugins/node/opentelemetry-instrumentation-graphql/test/graphql.test.ts b/plugins/node/opentelemetry-instrumentation-graphql/test/graphql.test.ts index d570a38e1a..ffa186600d 100644 --- a/plugins/node/opentelemetry-instrumentation-graphql/test/graphql.test.ts +++ b/plugins/node/opentelemetry-instrumentation-graphql/test/graphql.test.ts @@ -689,6 +689,37 @@ describe('graphql', () => { }); }); + describe('when ignoreResolveSpans is true', () => { + beforeEach(() => { + create({ + ignoreResolveSpans: true, + }); + }); + + afterEach(() => { + exporter.reset(); + graphQLInstrumentation.disable(); + }); + + it('should not create a span for a defined resolver', async () => { + const schema = buildSchema(` + type Query { + hello: String + } + `); + + const rootValue = { + hello: () => 'world', + }; + + await graphql({ schema, source: '{ hello }', rootValue }); + const resolveSpans = exporter + .getFinishedSpans() + .filter(span => span.name === `${SpanNames.RESOLVE} hello`); + assert.deepStrictEqual(resolveSpans.length, 0); + }); + }); + describe('when allowValues is set to true', () => { describe('AND source is query with param', () => { let spans: ReadableSpan[]; diff --git a/plugins/node/opentelemetry-instrumentation-mongodb/examples/src/server.ts b/plugins/node/opentelemetry-instrumentation-mongodb/examples/src/server.ts index 5953812d34..b308fdc934 100644 --- a/plugins/node/opentelemetry-instrumentation-mongodb/examples/src/server.ts +++ b/plugins/node/opentelemetry-instrumentation-mongodb/examples/src/server.ts @@ -2,10 +2,10 @@ import * as api from '@opentelemetry/api'; import { setupTracing } from './tracer'; -import { accessDB } from './utils'; - setupTracing('example-mongodb-server') +import { accessDB } from './utils'; + import * as http from 'http'; import { IncomingMessage, ServerResponse } from 'http'; import * as mongodb from 'mongodb'; diff --git a/plugins/node/opentelemetry-instrumentation-pg/package.json b/plugins/node/opentelemetry-instrumentation-pg/package.json index 89c4354e59..befc51959b 100644 --- a/plugins/node/opentelemetry-instrumentation-pg/package.json +++ b/plugins/node/opentelemetry-instrumentation-pg/package.json @@ -71,7 +71,6 @@ "typescript": "4.4.4" }, "dependencies": { - "@opentelemetry/core": "^1.8.0", "@opentelemetry/instrumentation": "^0.46.0", "@opentelemetry/semantic-conventions": "^1.0.0", "@opentelemetry/sql-common": "^0.40.0", diff --git a/plugins/node/opentelemetry-instrumentation-pino/README.md b/plugins/node/opentelemetry-instrumentation-pino/README.md index 288a69756b..7d8c7393f1 100644 --- a/plugins/node/opentelemetry-instrumentation-pino/README.md +++ b/plugins/node/opentelemetry-instrumentation-pino/README.md @@ -30,7 +30,15 @@ registerInstrumentations({ new PinoInstrumentation({ // Optional hook to insert additional context to log object. logHook: (span, record, level) => { - record['resource.service.name'] = provider.resource.attributes['service.name']; + record['resource.service.name'] = + provider.resource.attributes['service.name']; + }, + // Log span context under custom keys + // This is optional, and will default to "trace_id", "span_id" and "trace_flags" as the keys + logKeys: { + traceId: 'traceId', + spanId: 'spanId', + traceFlags: 'traceFlags', }, }), // other instrumentations @@ -45,7 +53,7 @@ logger.info('foobar'); ### Fields added to pino log objects -For the current active span, the following fields are injected: +For the current active span, the following fields are injected. These field names can be optionally configured via `logKeys` in the PinoInstrumentation config: * `trace_id` * `span_id` diff --git a/plugins/node/opentelemetry-instrumentation-pino/src/instrumentation.ts b/plugins/node/opentelemetry-instrumentation-pino/src/instrumentation.ts index 5cd5003039..3c5824b359 100644 --- a/plugins/node/opentelemetry-instrumentation-pino/src/instrumentation.ts +++ b/plugins/node/opentelemetry-instrumentation-pino/src/instrumentation.ts @@ -31,6 +31,12 @@ import { VERSION } from './version'; const pinoVersions = ['>=5.14.0 <9']; +const DEFAULT_LOG_KEYS = { + traceId: 'trace_id', + spanId: 'span_id', + traceFlags: 'trace_flags', +}; + export class PinoInstrumentation extends InstrumentationBase { constructor(config: PinoInstrumentationConfig = {}) { super('@opentelemetry/instrumentation-pino', VERSION, config); @@ -137,10 +143,12 @@ export class PinoInstrumentation extends InstrumentationBase { return {}; } + const logKeys = instrumentation.getConfig().logKeys ?? DEFAULT_LOG_KEYS; + const record = { - trace_id: spanContext.traceId, - span_id: spanContext.spanId, - trace_flags: `0${spanContext.traceFlags.toString(16)}`, + [logKeys.traceId]: spanContext.traceId, + [logKeys.spanId]: spanContext.spanId, + [logKeys.traceFlags]: `0${spanContext.traceFlags.toString(16)}`, }; instrumentation._callHook(span, record, level); diff --git a/plugins/node/opentelemetry-instrumentation-pino/src/types.ts b/plugins/node/opentelemetry-instrumentation-pino/src/types.ts index 4bf80f5a34..52484885a7 100644 --- a/plugins/node/opentelemetry-instrumentation-pino/src/types.ts +++ b/plugins/node/opentelemetry-instrumentation-pino/src/types.ts @@ -26,4 +26,11 @@ export type LogHookFunction = ( export interface PinoInstrumentationConfig extends InstrumentationConfig { logHook?: LogHookFunction; + + /** Configure the names of field injected into logs when there is span context available. */ + logKeys?: { + traceId: string; + spanId: string; + traceFlags: string; + }; } diff --git a/plugins/node/opentelemetry-instrumentation-pino/test/common.ts b/plugins/node/opentelemetry-instrumentation-pino/test/common.ts new file mode 100644 index 0000000000..006f169e32 --- /dev/null +++ b/plugins/node/opentelemetry-instrumentation-pino/test/common.ts @@ -0,0 +1,121 @@ +/* + * Copyright The OpenTelemetry Authors + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * https://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +import * as assert from 'assert'; +import * as sinon from 'sinon'; + +import { PinoInstrumentation, PinoInstrumentationConfig } from '../src'; + +import type { pino as Pino } from 'pino'; +import { Span } from '@opentelemetry/api'; +import { Writable } from 'stream'; + +export const kMessage = 'log-message'; + +export interface TestContext { + stream: Writable; + writeSpy: sinon.SinonSpy; + logger: Pino.Logger; +} + +export interface TestInstrumentation { + instrumentation: PinoInstrumentation; + pino: typeof Pino; +} + +export type TestInstrumentationAndContext = TestContext & TestInstrumentation; + +export function assertRecord( + record: any, + span: Span, + expectedKeys?: PinoInstrumentationConfig['logKeys'] +) { + const { traceId, spanId, traceFlags } = span.spanContext(); + assert.strictEqual(record[expectedKeys?.traceId ?? 'trace_id'], traceId); + assert.strictEqual(record[expectedKeys?.spanId ?? 'span_id'], spanId); + assert.strictEqual( + record[expectedKeys?.traceFlags ?? 'trace_flags'], + `0${traceFlags.toString(16)}` + ); + assert.strictEqual(kMessage, record['msg']); +} + +export function assertInjection( + span: Span, + testContext: TestContext, + expectedKeys?: PinoInstrumentationConfig['logKeys'] +) { + sinon.assert.calledOnce(testContext.writeSpy); + const record = JSON.parse(testContext.writeSpy.firstCall.args[0].toString()); + assertRecord(record, span, expectedKeys); + return record; +} + +export function testInjection( + span: Span, + testContext: TestContext, + expectedKeys?: PinoInstrumentationConfig['logKeys'] +) { + testContext.logger.info(kMessage); + return assertInjection(span, testContext, expectedKeys); +} + +export function testNoInjection(testContext: TestContext) { + testContext.logger.info(kMessage); + sinon.assert.calledOnce(testContext.writeSpy); + const record = JSON.parse(testContext.writeSpy.firstCall.args[0].toString()); + assert.strictEqual(record['trace_id'], undefined); + assert.strictEqual(record['span_id'], undefined); + assert.strictEqual(record['trace_flags'], undefined); + assert.strictEqual(kMessage, record['msg']); + return record; +} + +export function initTestContext( + testInstrumentation: TestInstrumentation, + importType: 'global' | 'default' | 'pino' = 'global' +): TestContext { + const stream = new Writable(); + stream._write = () => {}; + const writeSpy = sinon.spy(stream, 'write'); + const logger = + importType === 'global' + ? testInstrumentation.pino(stream) + : // @ts-expect-error the same function reexported + testInstrumentation.pino[importType](stream); + + return { stream, writeSpy, logger }; +} + +export function setupInstrumentation( + config?: PinoInstrumentationConfig +): TestInstrumentation { + const instrumentation = new PinoInstrumentation(config); + if (config?.enabled !== false) { + instrumentation.enable(); + } + const pino = require('pino'); + return { instrumentation, pino }; +} + +export function setupInstrumentationAndInitTestContext( + config?: PinoInstrumentationConfig, + importType: 'global' | 'default' | 'pino' = 'global' +) { + const instrumentation = setupInstrumentation(config); + const context = initTestContext(instrumentation, importType); + return { ...instrumentation, ...context }; +} diff --git a/plugins/node/opentelemetry-instrumentation-pino/test/pino-disabled.test.ts b/plugins/node/opentelemetry-instrumentation-pino/test/pino-disabled.test.ts new file mode 100644 index 0000000000..f8258db444 --- /dev/null +++ b/plugins/node/opentelemetry-instrumentation-pino/test/pino-disabled.test.ts @@ -0,0 +1,86 @@ +/* + * Copyright The OpenTelemetry Authors + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * https://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +import * as assert from 'assert'; + +import { + InMemorySpanExporter, + SimpleSpanProcessor, +} from '@opentelemetry/sdk-trace-base'; +import { + TestContext, + TestInstrumentation, + initTestContext, + setupInstrumentation, + testInjection, + testNoInjection, +} from './common'; +import { context, trace } from '@opentelemetry/api'; + +import { AsyncHooksContextManager } from '@opentelemetry/context-async-hooks'; +import { NodeTracerProvider } from '@opentelemetry/sdk-trace-node'; + +const memoryExporter = new InMemorySpanExporter(); +const provider = new NodeTracerProvider(); +const tracer = provider.getTracer('default'); +provider.addSpanProcessor(new SimpleSpanProcessor(memoryExporter)); +context.setGlobalContextManager(new AsyncHooksContextManager()); + +describe('PinoInstrumentation', () => { + describe('disabled instrumentation', () => { + let testInstrumentation: TestInstrumentation; + let testContext: TestContext; + before(() => { + testInstrumentation = setupInstrumentation(); + testContext = initTestContext(testInstrumentation); + testInstrumentation.instrumentation.disable(); + }); + after(() => testInstrumentation.instrumentation.enable()); + + beforeEach(() => { + testContext = initTestContext(testInstrumentation); + }); + + it('does not inject span context', () => { + const span = tracer.startSpan('abc'); + context.with(trace.setSpan(context.active(), span), () => { + testNoInjection(testContext); + }); + }); + + it('does not call log hook', () => { + const span = tracer.startSpan('abc'); + testInstrumentation.instrumentation.setConfig({ + enabled: false, + logHook: (_span, record) => { + record['resource.service.name'] = 'test-service'; + }, + }); + context.with(trace.setSpan(context.active(), span), () => { + const record = testNoInjection(testContext); + assert.strictEqual(record['resource.service.name'], undefined); + }); + }); + + it('injects span context once re-enabled', () => { + testInstrumentation.instrumentation.enable(); + const span = tracer.startSpan('abc'); + context.with(trace.setSpan(context.active(), span), () => { + testInjection(span, testContext); + }); + }); + }); +}); diff --git a/plugins/node/opentelemetry-instrumentation-pino/test/pino-enabled.test.ts b/plugins/node/opentelemetry-instrumentation-pino/test/pino-enabled.test.ts new file mode 100644 index 0000000000..10bce070dc --- /dev/null +++ b/plugins/node/opentelemetry-instrumentation-pino/test/pino-enabled.test.ts @@ -0,0 +1,238 @@ +/* + * Copyright The OpenTelemetry Authors + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * https://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +import * as assert from 'assert'; +import * as semver from 'semver'; +import * as sinon from 'sinon'; + +import { INVALID_SPAN_CONTEXT, context, trace } from '@opentelemetry/api'; +import { + InMemorySpanExporter, + SimpleSpanProcessor, +} from '@opentelemetry/sdk-trace-base'; +import { + TestInstrumentationAndContext, + assertInjection, + assertRecord, + initTestContext, + kMessage, + setupInstrumentationAndInitTestContext, + testInjection, + testNoInjection, +} from './common'; + +import { AsyncHooksContextManager } from '@opentelemetry/context-async-hooks'; +import { NodeTracerProvider } from '@opentelemetry/sdk-trace-node'; +import type { pino as Pino } from 'pino'; + +const memoryExporter = new InMemorySpanExporter(); +const provider = new NodeTracerProvider(); +const tracer = provider.getTracer('default'); +provider.addSpanProcessor(new SimpleSpanProcessor(memoryExporter)); +context.setGlobalContextManager(new AsyncHooksContextManager()); + +describe('PinoInstrumentation', () => { + let testContext: TestInstrumentationAndContext; + + describe('enabled instrumentation', () => { + beforeEach(() => { + testContext = setupInstrumentationAndInitTestContext(); + }); + + it('injects span context to records', () => { + const span = tracer.startSpan('abc'); + context.with(trace.setSpan(context.active(), span), () => { + testInjection(span, testContext); + }); + }); + + it('injects span context to records with custom keys', () => { + const logKeys = { + traceId: 'traceId', + spanId: 'spanId', + traceFlags: 'traceFlags', + }; + + testContext = setupInstrumentationAndInitTestContext({ logKeys }); + + const span = tracer.startSpan('abc'); + context.with(trace.setSpan(context.active(), span), () => { + testInjection(span, testContext, logKeys); + }); + }); + + it('injects span context to records in default export', function () { + // @ts-expect-error the same function reexported + if (!testContext.pino.default) { + this.skip(); + } + initTestContext(testContext, 'default'); + const span = tracer.startSpan('abc'); + context.with(trace.setSpan(context.active(), span), () => { + testInjection(span, testContext); + }); + }); + + it('injects span context to records in named export', function () { + // @ts-expect-error the same function reexported + if (!testContext.pino.pino) { + this.skip(); + } + initTestContext(testContext, 'pino'); + const span = tracer.startSpan('abc'); + context.with(trace.setSpan(context.active(), span), () => { + testInjection(span, testContext); + }); + }); + + it('injects span context to child logger records', () => { + const span = tracer.startSpan('abc'); + context.with(trace.setSpan(context.active(), span), () => { + const child = testContext.logger.child({ foo: 42 }); + child.info(kMessage); + assertInjection(span, testContext); + }); + }); + + it('calls the users log hook', () => { + const span = tracer.startSpan('abc'); + testContext.instrumentation.setConfig({ + enabled: true, + logHook: (_span, record, level) => { + record['resource.service.name'] = 'test-service'; + if (semver.satisfies(testContext.pino.version, '>= 7.9.0')) { + assert.strictEqual(level, 30); + } + }, + }); + context.with(trace.setSpan(context.active(), span), () => { + const record = testInjection(span, testContext); + assert.strictEqual(record['resource.service.name'], 'test-service'); + }); + }); + + it('does not inject span context if no span is active', () => { + assert.strictEqual(trace.getSpan(context.active()), undefined); + testNoInjection(testContext); + }); + + it('does not inject span context if span context is invalid', () => { + const span = trace.wrapSpanContext(INVALID_SPAN_CONTEXT); + context.with(trace.setSpan(context.active(), span), () => { + testNoInjection(testContext); + }); + }); + + it('does not propagate exceptions from user hooks', () => { + const span = tracer.startSpan('abc'); + testContext.instrumentation.setConfig({ + enabled: true, + logHook: () => { + throw new Error('Oops'); + }, + }); + context.with(trace.setSpan(context.active(), span), () => { + testInjection(span, testContext); + }); + }); + }); + + describe('logger construction', () => { + let stdoutSpy: sinon.SinonSpy; + + beforeEach(() => { + testContext = setupInstrumentationAndInitTestContext(); + + stdoutSpy = sinon.spy(process.stdout, 'write'); + }); + + afterEach(() => { + stdoutSpy.restore(); + }); + + it('does not fail when constructing logger without arguments', () => { + testContext.logger = testContext.pino(); + const span = tracer.startSpan('abc'); + context.with(trace.setSpan(context.active(), span), () => { + testContext.logger.info(kMessage); + }); + const record = JSON.parse(stdoutSpy.firstCall.args[0].toString()); + assertRecord(record, span); + }); + + it('preserves user options and adds a mixin', () => { + testContext.logger = testContext.pino( + { name: 'LogLog' }, + testContext.stream + ); + + const span = tracer.startSpan('abc'); + context.with(trace.setSpan(context.active(), span), () => { + const record = testInjection(span, testContext); + assert.strictEqual(record['name'], 'LogLog'); + }); + }); + + describe('binary arguments', () => { + it('is possible to construct logger with undefined options', () => { + testContext.logger = testContext.pino( + undefined as unknown as Pino.LoggerOptions, + testContext.stream + ); + const span = tracer.startSpan('abc'); + context.with(trace.setSpan(context.active(), span), () => { + testInjection(span, testContext); + }); + }); + + it('preserves user mixins', () => { + testContext.logger = testContext.pino( + { name: 'LogLog', mixin: () => ({ a: 2, b: 'bar' }) }, + testContext.stream + ); + + const span = tracer.startSpan('abc'); + context.with(trace.setSpan(context.active(), span), () => { + const record = testInjection(span, testContext); + assert.strictEqual(record['a'], 2); + assert.strictEqual(record['b'], 'bar'); + assert.strictEqual(record['name'], 'LogLog'); + }); + }); + + it('ensures user mixin values take precedence', () => { + testContext.logger = testContext.pino( + { + mixin() { + return { trace_id: '123' }; + }, + }, + testContext.stream + ); + + const span = tracer.startSpan('abc'); + context.with(trace.setSpan(context.active(), span), () => { + testContext.logger.info(kMessage); + }); + + const record = JSON.parse( + testContext.writeSpy.firstCall.args[0].toString() + ); + assert.strictEqual(record['trace_id'], '123'); + }); + }); + }); +}); diff --git a/plugins/node/opentelemetry-instrumentation-pino/test/pino.test.ts b/plugins/node/opentelemetry-instrumentation-pino/test/pino.test.ts deleted file mode 100644 index 36c2ac01c2..0000000000 --- a/plugins/node/opentelemetry-instrumentation-pino/test/pino.test.ts +++ /dev/null @@ -1,375 +0,0 @@ -/* - * Copyright The OpenTelemetry Authors - * - * Licensed under the Apache License, Version 2.0 (the "License"); - * you may not use this file except in compliance with the License. - * You may obtain a copy of the License at - * - * https://www.apache.org/licenses/LICENSE-2.0 - * - * Unless required by applicable law or agreed to in writing, software - * distributed under the License is distributed on an "AS IS" BASIS, - * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. - * See the License for the specific language governing permissions and - * limitations under the License. - */ - -import { - InMemorySpanExporter, - SimpleSpanProcessor, -} from '@opentelemetry/sdk-trace-base'; -import { context, trace, Span, INVALID_SPAN_CONTEXT } from '@opentelemetry/api'; -import { NodeTracerProvider } from '@opentelemetry/sdk-trace-node'; -import { AsyncHooksContextManager } from '@opentelemetry/context-async-hooks'; -import { - runTestFixture, - TestCollector, -} from '@opentelemetry/contrib-test-utils'; -import { Writable } from 'stream'; -import * as assert from 'assert'; -import * as sinon from 'sinon'; -import * as semver from 'semver'; -import type { pino as Pino } from 'pino'; - -import { PinoInstrumentation } from '../src'; - -const memoryExporter = new InMemorySpanExporter(); -const provider = new NodeTracerProvider(); -const tracer = provider.getTracer('default'); -provider.addSpanProcessor(new SimpleSpanProcessor(memoryExporter)); -context.setGlobalContextManager(new AsyncHooksContextManager()); - -const kMessage = 'log-message'; - -describe('PinoInstrumentation', () => { - let stream: Writable; - let writeSpy: sinon.SinonSpy; - let pino: typeof Pino; - let instrumentation: PinoInstrumentation; - let logger: Pino.Logger; - - function assertRecord(record: any, span: Span) { - const { traceId, spanId, traceFlags } = span.spanContext(); - assert.strictEqual(record['trace_id'], traceId); - assert.strictEqual(record['span_id'], spanId); - assert.strictEqual(record['trace_flags'], `0${traceFlags.toString(16)}`); - assert.strictEqual(kMessage, record['msg']); - } - - function assertInjection(span: Span) { - sinon.assert.calledOnce(writeSpy); - const record = JSON.parse(writeSpy.firstCall.args[0].toString()); - assertRecord(record, span); - return record; - } - - function testInjection(span: Span) { - logger.info(kMessage); - return assertInjection(span); - } - - function testNoInjection() { - logger.info(kMessage); - sinon.assert.calledOnce(writeSpy); - const record = JSON.parse(writeSpy.firstCall.args[0].toString()); - assert.strictEqual(record['trace_id'], undefined); - assert.strictEqual(record['span_id'], undefined); - assert.strictEqual(record['trace_flags'], undefined); - assert.strictEqual(kMessage, record['msg']); - return record; - } - - function init(importType: 'global' | 'default' | 'pino' = 'global') { - stream = new Writable(); - stream._write = () => {}; - writeSpy = sinon.spy(stream, 'write'); - if (importType === 'global') { - logger = pino(stream); - } else { - // @ts-expect-error the same function reexported - logger = pino[importType](stream); - } - } - - before(() => { - instrumentation = new PinoInstrumentation(); - instrumentation.enable(); - pino = require('pino'); - }); - - describe('enabled instrumentation', () => { - beforeEach(() => { - init(); - }); - - it('injects span context to records', () => { - const span = tracer.startSpan('abc'); - context.with(trace.setSpan(context.active(), span), () => { - testInjection(span); - }); - }); - - it('injects span context to records in default export', function () { - // @ts-expect-error the same function reexported - if (!pino.default) { - this.skip(); - } - init('default'); - const span = tracer.startSpan('abc'); - context.with(trace.setSpan(context.active(), span), () => { - testInjection(span); - }); - }); - - it('injects span context to records in named export', function () { - // @ts-expect-error the same function reexported - if (!pino.pino) { - this.skip(); - } - init('pino'); - const span = tracer.startSpan('abc'); - context.with(trace.setSpan(context.active(), span), () => { - testInjection(span); - }); - }); - - it('injects span context to child logger records', () => { - const span = tracer.startSpan('abc'); - context.with(trace.setSpan(context.active(), span), () => { - const child = logger.child({ foo: 42 }); - child.info(kMessage); - assertInjection(span); - }); - }); - - it('calls the users log hook', () => { - const span = tracer.startSpan('abc'); - instrumentation.setConfig({ - enabled: true, - logHook: (_span, record, level) => { - record['resource.service.name'] = 'test-service'; - if (semver.satisfies(pino.version, '>= 7.9.0')) { - assert.strictEqual(level, 30); - } - }, - }); - context.with(trace.setSpan(context.active(), span), () => { - const record = testInjection(span); - assert.strictEqual(record['resource.service.name'], 'test-service'); - }); - }); - - it('does not inject span context if no span is active', () => { - assert.strictEqual(trace.getSpan(context.active()), undefined); - testNoInjection(); - }); - - it('does not inject span context if span context is invalid', () => { - const span = trace.wrapSpanContext(INVALID_SPAN_CONTEXT); - context.with(trace.setSpan(context.active(), span), () => { - testNoInjection(); - }); - }); - - it('does not propagate exceptions from user hooks', () => { - const span = tracer.startSpan('abc'); - instrumentation.setConfig({ - enabled: true, - logHook: () => { - throw new Error('Oops'); - }, - }); - context.with(trace.setSpan(context.active(), span), () => { - testInjection(span); - }); - }); - }); - - describe('logger construction', () => { - let stdoutSpy: sinon.SinonSpy; - - beforeEach(() => { - stream = new Writable(); - stream._write = () => {}; - writeSpy = sinon.spy(stream, 'write'); - stdoutSpy = sinon.spy(process.stdout, 'write'); - }); - - afterEach(() => { - stdoutSpy.restore(); - }); - - it('does not fail when constructing logger without arguments', () => { - logger = pino(); - const span = tracer.startSpan('abc'); - context.with(trace.setSpan(context.active(), span), () => { - logger.info(kMessage); - }); - const record = JSON.parse(stdoutSpy.firstCall.args[0].toString()); - assertRecord(record, span); - }); - - it('preserves user options and adds a mixin', () => { - logger = pino({ name: 'LogLog' }, stream); - - const span = tracer.startSpan('abc'); - context.with(trace.setSpan(context.active(), span), () => { - const record = testInjection(span); - assert.strictEqual(record['name'], 'LogLog'); - }); - }); - - describe('binary arguments', () => { - it('is possible to construct logger with undefined options', () => { - logger = pino(undefined as unknown as Pino.LoggerOptions, stream); - const span = tracer.startSpan('abc'); - context.with(trace.setSpan(context.active(), span), () => { - testInjection(span); - }); - }); - - it('preserves user mixins', () => { - logger = pino( - { - name: 'LogLog', - mixin: () => ({ a: 2, b: 'bar' }), - }, - stream - ); - - const span = tracer.startSpan('abc'); - context.with(trace.setSpan(context.active(), span), () => { - const record = testInjection(span); - assert.strictEqual(record['a'], 2); - assert.strictEqual(record['b'], 'bar'); - assert.strictEqual(record['name'], 'LogLog'); - }); - }); - - it('ensures user mixin values take precedence', () => { - logger = pino( - { - mixin() { - return { trace_id: '123' }; - }, - }, - stream - ); - - const span = tracer.startSpan('abc'); - context.with(trace.setSpan(context.active(), span), () => { - logger.info(kMessage); - }); - - const record = JSON.parse(writeSpy.firstCall.args[0].toString()); - assert.strictEqual(record['trace_id'], '123'); - }); - }); - }); - - describe('disabled instrumentation', () => { - before(() => { - instrumentation.disable(); - }); - - after(() => { - instrumentation.enable(); - }); - - beforeEach(() => init()); - - it('does not inject span context', () => { - const span = tracer.startSpan('abc'); - context.with(trace.setSpan(context.active(), span), () => { - testNoInjection(); - }); - }); - - it('does not call log hook', () => { - const span = tracer.startSpan('abc'); - instrumentation.setConfig({ - enabled: false, - logHook: (_span, record) => { - record['resource.service.name'] = 'test-service'; - }, - }); - context.with(trace.setSpan(context.active(), span), () => { - const record = testNoInjection(); - assert.strictEqual(record['resource.service.name'], undefined); - }); - }); - - it('injects span context once re-enabled', () => { - instrumentation.enable(); - const span = tracer.startSpan('abc'); - context.with(trace.setSpan(context.active(), span), () => { - testInjection(span); - }); - }); - }); - - it('should work with ESM default import', async function () { - let logRecords: any[]; - await runTestFixture({ - cwd: __dirname, - argv: ['fixtures/use-pino-default-import.mjs'], - env: { - NODE_OPTIONS: - '--experimental-loader=@opentelemetry/instrumentation/hook.mjs', - NODE_NO_WARNINGS: '1', - }, - checkResult: (err, stdout, _stderr) => { - assert.ifError(err); - logRecords = stdout - .trim() - .split('\n') - .map(ln => JSON.parse(ln)); - assert.strictEqual(logRecords.length, 1); - }, - checkCollector: (collector: TestCollector) => { - // Check that both log records had the trace-context of the span injected. - const spans = collector.sortedSpans; - assert.strictEqual(spans.length, 1); - logRecords.forEach(rec => { - assert.strictEqual(rec.trace_id, spans[0].traceId); - assert.strictEqual(rec.span_id, spans[0].spanId); - }); - }, - }); - }); - - it('should work with ESM named import', async function () { - if (semver.lt(pino.version, '6.8.0')) { - // Pino 6.8.0 added named ESM exports (https://github.com/pinojs/pino/pull/936). - this.skip(); - } else { - let logRecords: any[]; - await runTestFixture({ - cwd: __dirname, - argv: ['fixtures/use-pino-named-import.mjs'], - env: { - NODE_OPTIONS: - '--experimental-loader=@opentelemetry/instrumentation/hook.mjs', - NODE_NO_WARNINGS: '1', - }, - checkResult: (err, stdout, _stderr) => { - assert.ifError(err); - logRecords = stdout - .trim() - .split('\n') - .map(ln => JSON.parse(ln)); - assert.strictEqual(logRecords.length, 1); - }, - checkCollector: (collector: TestCollector) => { - // Check that both log records had the trace-context of the span injected. - const spans = collector.sortedSpans; - assert.strictEqual(spans.length, 1); - logRecords.forEach(rec => { - assert.strictEqual(rec.trace_id, spans[0].traceId); - assert.strictEqual(rec.span_id, spans[0].spanId); - }); - }, - }); - } - }); -});