fix(instrumentation-pino): instrument pino used in ESM (open-telemetr…

…y#1831)

This also reduces the number of pino versions tested with
test-all-versions test (from 42 to 13, currently).

plugins/node/opentelemetry-instrumentation-pino/.tav.yml

@@ -1,5 +1,5 @@
 pino:
-  - versions: "^8.0.0 || ^7.11.0 || 7.8.0 || 7.2.0 || ^6.13.1 || 5.17.0 || 5.14.0"
+  - versions: "^8.16.2 || 8.12.1 || 8.8.0 || 8.4.0 || 8.0.0 || ^7.11.0 || 7.8.0 || 7.2.0 || ^6.13.3 || 5.17.0 || 5.14.0"
     node: ">=14"
     commands: npm run test
   - versions: "^7.11.0 || 7.8.0 || 7.2.0 || ^6.13.1 || 5.17.0 || 5.14.0"

plugins/node/opentelemetry-instrumentation-pino/package.json

@@ -46,6 +46,7 @@
   "devDependencies": {
     "@opentelemetry/api": "^1.3.0",
     "@opentelemetry/context-async-hooks": "^1.8.0",
+    "@opentelemetry/contrib-test-utils": "^0.35.0",
     "@opentelemetry/sdk-trace-base": "^1.8.0",
     "@opentelemetry/sdk-trace-node": "^1.8.0",
     "@types/mocha": "7.0.2",

plugins/node/opentelemetry-instrumentation-pino/src/instrumentation.ts

@@ -41,12 +41,14 @@ export class PinoInstrumentation extends InstrumentationBase {
       new InstrumentationNodeModuleDefinition<any>(
         'pino',
         pinoVersions,
-        (pinoModule, moduleVersion) => {
+        (module, moduleVersion?: string) => {
           diag.debug(`Applying patch for pino@${moduleVersion}`);
+          const isESM = module[Symbol.toStringTag] === 'Module';
+          const moduleExports = isESM ? module.default : module;
           const instrumentation = this;
           const patchedPino = Object.assign((...args: unknown[]) => {
             if (args.length === 0) {
-              return pinoModule({
+              return moduleExports({
                 mixin: instrumentation._getMixinFunction(),
               });
             }
@@ -61,21 +63,28 @@ export class PinoInstrumentation extends InstrumentationBase {
                 args.splice(0, 0, {
                   mixin: instrumentation._getMixinFunction(),
                 });
-                return pinoModule(...args);
+                return moduleExports(...args);
               }
             }
 
             args[0] = instrumentation._combineOptions(args[0]);
 
-            return pinoModule(...args);
-          }, pinoModule);
+            return moduleExports(...args);
+          }, moduleExports);
 
           if (typeof patchedPino.pino === 'function') {
             patchedPino.pino = patchedPino;
           }
           if (typeof patchedPino.default === 'function') {
             patchedPino.default = patchedPino;
           }
+          if (isESM) {
+            if (module.pino) {
+              // This was added in [email protected] (https://github.com/pinojs/pino/pull/936).
+              module.pino = patchedPino;
+            }
+            module.default = patchedPino;
+          }
 
           return patchedPino;
         }

plugins/node/opentelemetry-instrumentation-pino/test/fixtures/use-pino-default-import.mjs

@@ -0,0 +1,42 @@
+/*
+ * 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.
+ */
+
+// Use pino from an ES module:
+//    node --experimental-loader=@opentelemetry/instrumentation/hook.mjs use-pino-default-import.mjs
+
+import { trace } from '@opentelemetry/api';
+import { createTestNodeSdk } from '@opentelemetry/contrib-test-utils';
+
+import { PinoInstrumentation } from '../../build/src/index.js';
+
+const sdk = createTestNodeSdk({
+  serviceName: 'use-pino',
+  instrumentations: [
+    new PinoInstrumentation()
+  ]
+})
+sdk.start();
+
+import pino from 'pino';
+const logger = pino();
+
+const tracer = trace.getTracer();
+await tracer.startActiveSpan('manual', async (span) => {
+  logger.info('hi from logger')
+  span.end();
+});
+
+await sdk.shutdown();

plugins/node/opentelemetry-instrumentation-pino/test/fixtures/use-pino-named-import.mjs

@@ -0,0 +1,42 @@
+/*
+ * 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.
+ */
+
+// Use pino from an ES module:
+//    node --experimental-loader=@opentelemetry/instrumentation/hook.mjs use-pino-named-import.mjs
+
+import { trace } from '@opentelemetry/api';
+import { createTestNodeSdk } from '@opentelemetry/contrib-test-utils';
+
+import { PinoInstrumentation } from '../../build/src/index.js';
+
+const sdk = createTestNodeSdk({
+  serviceName: 'use-pino',
+  instrumentations: [
+    new PinoInstrumentation()
+  ]
+})
+sdk.start();
+
+import { pino } from 'pino'; // named import, supported with pino >=6.8.0
+const logger = pino();
+
+const tracer = trace.getTracer();
+await tracer.startActiveSpan('manual', async (span) => {
+  logger.info('hi from logger')
+  span.end();
+});
+
+await sdk.shutdown();

plugins/node/opentelemetry-instrumentation-pino/test/pino.test.ts

@@ -21,6 +21,10 @@ import {
 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';
@@ -303,4 +307,69 @@ describe('PinoInstrumentation', () => {
       });
     });
   });
+
+  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);
+          });
+        },
+      });
+    }
+  });
 });