open-telemetry / opentelemetry-js-contrib

OpenTelemetry instrumentation for JavaScript modules
https://opentelemetry.io
Apache License 2.0
692 stars 506 forks source link

PinoInstrumentation doesn't work if constructor function has been called #2434

Closed bozzelliandrea closed 2 weeks ago

bozzelliandrea commented 1 month ago

Using PinoInstrumentation inside a nodejs project seems not to intercept logs

What version of OpenTelemetry are you using?

0.53.0 for standard nodejs libraries 0.41.0 for @opentelemetry/instrumentation-pino

What version of Node are you using?

20.17.0

What did you do?

const sdk = new NodeSDK({
  serviceName: "next-node-instrumentation",
  //spanProcessor: new SimpleSpanProcessor(new OTLPTraceExporter()),
  textMapPropagator: new W3CTraceContextPropagator(),
  traceExporter: new OTLPTraceExporter({
    url: `${OTEL_COLLECTOR_URL}/v1/traces`
  }),

  instrumentations: [
    //new HttpInstrumentation()
    ...getNodeAutoInstrumentations(),
    new PinoInstrumentation({
        logHook: (span, record) => {
            console.log("RECEIVE FROM HOOK")
        }
    }),
  ],

  logRecordProcessor: new logs.SimpleLogRecordProcessor(new logs.ConsoleLogRecordExporter()),

  /* also tried the exporter but doesn't work
  logRecordProcessors: [new logs.SimpleLogRecordProcessor(
    new OTLPLogExporter({
      url: `${OTEL_COLLECTOR_URL}/v1/logs`,
    }),
  )],
  */

})
sdk.start()

What did you expect to see?

Logs catched and printed in console with opentelemetry standard

What did you see instead?

No log captured or exported

Additional context

tested on Next and Fastify. Inside fastify context only works if the logger is never reinitialized.

trentm commented 2 weeks ago

@bozzelliandrea Ultimately the best help will be if you can show working reproduction code.

A couple guesses:

I trimmed down your OTel setup code into a use-pino.js file:

const logs = require('@opentelemetry/sdk-logs');
const {NodeSDK} = require('@opentelemetry/sdk-node');
const {PinoInstrumentation} = require('@opentelemetry/instrumentation-pino');

const sdk = new NodeSDK({
  serviceName: "next-node-instrumentation",
  instrumentations: [
    new PinoInstrumentation({
        logHook: (span, record) => {
            console.log("RECEIVE FROM HOOK")
        }
    }),
  ],
  logRecordProcessor: new logs.SimpleLogRecordProcessor(new logs.ConsoleLogRecordExporter()),
})
sdk.start()

const pino = require('pino');
const log = pino();
log.info('hi');

Running that works for me:

% node use-pino.js
{"level":30,"time":1727910091642,"pid":21081,"hostname":"peach.local","msg":"hi"}
{
  resource: {
    attributes: {
      'service.name': 'next-node-instrumentation',
      'telemetry.sdk.language': 'nodejs',
      'telemetry.sdk.name': 'opentelemetry',
      'telemetry.sdk.version': '1.26.0',
      'process.pid': 21081,
      'process.executable.name': 'node',
      'process.executable.path': '/Users/trentm/.nvm/versions/node/v18.20.4/bin/node',
      'process.command_args': [
        '/Users/trentm/.nvm/versions/node/v18.20.4/bin/node',
        '/Users/trentm/tmp/asdf.20241002T155620/use-pino.js'
      ],
      'process.runtime.version': '18.20.4',
      'process.runtime.name': 'nodejs',
      'process.runtime.description': 'Node.js',
      'process.command': '/Users/trentm/tmp/asdf.20241002T155620/use-pino.js',
      'process.owner': 'trentm',
      'host.name': 'peach.local',
      'host.arch': 'arm64'
    }
  },
  instrumentationScope: {
    name: '@opentelemetry/instrumentation-pino',
    version: '0.42.0',
    schemaUrl: undefined
  },
  timestamp: 1727910091642000,
  traceId: undefined,
  spanId: undefined,
  traceFlags: undefined,
  severityText: 'info',
  severityNumber: 9,
  body: 'hi',
  attributes: {}
}
bozzelliandrea commented 2 weeks ago

Hi @trentm , thanks for the reply 😄. actually I found the cause, on nextjs it is necessary to configure the instrumentation as a server external component on next.config.mjs

    ....
    // instrumentation config
    instrumentationHook: true,
    serverComponentsExternalPackages: ["pino", "@opentelemetry/instrumentation-pino"]

I'll close the issue, maybe the config could be useful for someone who's trying to do the same with nextjs