fix(pino): skip instrumentation for pino thread-stream workers

packages/collector/test/tracing/logging/pino/app.js

@@ -14,7 +14,10 @@ process.on('SIGTERM', () => {
 });
 
 require('./mockVersion');
-require('../../../..')();
+
+if (!process.env.NODE_OPTIONS || !process.env.NODE_OPTIONS.includes('src/immediate')) {
+  require('../../../..')();
+}
 
 const fetch = require('node-fetch-v2');
 const bodyParser = require('body-parser');
@@ -212,6 +215,22 @@ app.get('/express-pino-error-random-object-and-string', (req, res) => {
   finish(res);
 });
 
+app.get('/thread-stream-test', (req, res) => {
+  try {
+    const mode = process.env.PINO_WORKER_MODE || 'transport';
+
+    const logger =
+      mode === 'transport'
+        ? pino({ transport: { target: 'pino-pretty', options: { destination: 1 } } })
+        : pino({ destination: 1 });
+    logger.error('Pino worker test error log');
+
+    res.sendStatus(200);
+  } catch (e) {
+    res.status(500).send(`Failed: ${e.message}`);
+  }
+});
+
 function finish(res) {
   fetch(`http://127.0.0.1:${agentPort}`).then(() => {
     res.sendStatus(200);

packages/collector/test/tracing/logging/pino/test.js

@@ -102,6 +102,51 @@ describe('tracing/logging/pino', function () {
       });
     });
   });
+  describe('pino thread-stream worker', function () {
+    let controls;
+
+    before(async () => {
+      controls = new ProcessControls({
+        dirname: __dirname,
+        useGlobalAgent: true,
+        env: {
+          PINO_WORKER_MODE: 'transport',
+          PINO_EXPRESS: 'false',
+          NODE_OPTIONS: `--require ${path.join(__dirname, '../../../..', 'src', 'immediate.js')}`
+        }
+      });
+
+      await controls.startAndWaitForAgentConnection();
+    });
+
+    beforeEach(async () => {
+      await agentControls.clearReceivedTraceData();
+    });
+
+    after(async () => {
+      await controls.stop();
+    });
+
+    it('must trace without errors', async () => {
+      await controls.sendRequest({
+        method: 'GET',
+        path: '/thread-stream-test'
+      });
+      await testUtils.delay(1000);
+      const spans = await agentControls.getSpans();
+
+      const logSpan = spans.find(s => s.n === 'log.pino');
+      expect(logSpan).to.exist;
+      expect(logSpan.data.log.message).to.equal('Pino worker test error log');
+
+      const httpSpan = spans.find(s => s.n === 'node.http.server');
+      expect(httpSpan).to.exist;
+      expect(httpSpan.data.http.path_tpl).to.equal('/thread-stream-test');
+      expect(httpSpan.data.http.status).to.equal(200);
+
+      expect(spans).to.have.lengthOf(2);
+    });
+  });
 
   function runTests(pinoVersion, useExpressPino) {
     const suffix = useExpressPino ? ' (express-pino)' : '';

packages/core/src/util/excludedFromInstrumentation.js

@@ -13,22 +13,61 @@
 // no value and also creates confusing log output, so we exclude them here explicitly.
 const excludePattern = /^.*\/(?:npm(?:\.js)?|npm-cli(?:\.js)?|yarn(?:\.js)?|yarn\/lib\/cli(?:\.js)?)$/i;
 
+/**
+ * Determines if the current process is a Pino thread-stream worker.
+ * Pino uses background worker threads for "thread-stream" logging, which should not be instrumented.
+ * @returns {boolean}
+ */
+function isPinoThreadStreamWorker() {
+  try {
+    const { isMainThread, workerData } = require('worker_threads');
+    if (isMainThread) return false;
+
+    if (workerData && typeof workerData === 'object') {
+      const nested = workerData.workerData;
+      const isPinoWorker =
+        typeof workerData.filename === 'string' &&
+        nested &&
+        nested.$context &&
+        typeof nested.$context.threadStreamVersion === 'string';
+
+      if (isPinoWorker) {
+        return true;
+      }
+    }
+    return false;
+  } catch {
+    return false;
+  }
+}
+
 /**
  * @type {Function}
  * @returns {boolean}
  */
 module.exports = exports = function isExcludedFromInstrumentation() {
   const mainModule = process.argv[1];
-  const excludedFromInstrumentation = typeof mainModule === 'string' && excludePattern.test(mainModule);
+  let excludedFromInstrumentation = typeof mainModule === 'string' && excludePattern.test(mainModule);
+  let reason = 'npm-yarn';
+
+  if (!excludedFromInstrumentation && isPinoThreadStreamWorker()) {
+    excludedFromInstrumentation = true;
+    reason = 'pino-thread-stream';
+  }
 
-  if (excludedFromInstrumentation) {
-    const logLevelIsDebugOrInfo =
-      process.env.INSTANA_DEBUG ||
-      (process.env.INSTANA_LOG_LEVEL &&
-        (process.env.INSTANA_LOG_LEVEL.toLowerCase() === 'info' ||
-          process.env.INSTANA_LOG_LEVEL.toLowerCase() === 'debug'));
+  const logEnabled =
+    process.env.INSTANA_DEBUG ||
+    (process.env.INSTANA_LOG_LEVEL && ['info', 'debug'].includes(process.env.INSTANA_LOG_LEVEL.toLowerCase()));
 
-    if (logLevelIsDebugOrInfo) {
+  if (excludedFromInstrumentation && logEnabled) {
+    if (reason === 'pino-thread-stream') {
+      // eslint-disable-next-line no-console
+      console.log(
+        // eslint-disable-next-line max-len
+        `[Instana] INFO: Skipping instrumentation for process ${process.pid} - detected as a Pino thread-stream worker. ` +
+          'Logging threads do not require instrumentation.'
+      );
+    } else {
       // eslint-disable-next-line no-console
       console.log(
         `[Instana] INFO: Not instrumenting process ${process.pid}: ${process.argv[0]} ${mainModule}` +

packages/core/test/util/excludedFromInstrumentation_test.js

@@ -66,6 +66,165 @@ describe('util.excludedFromInstrumentation', () => {
     expect(isExcluded('/usr/local/npmx.js')).to.be.false;
   });
 
+  describe('pino thread-stream worker detection', () => {
+    let originalRequire;
+
+    beforeEach(() => {
+      originalRequire = require.cache[require.resolve('worker_threads')];
+    });
+
+    afterEach(() => {
+      if (originalRequire) {
+        require.cache[require.resolve('worker_threads')] = originalRequire;
+      } else {
+        delete require.cache[require.resolve('worker_threads')];
+      }
+      delete require.cache[require.resolve('../../src/util/excludedFromInstrumentation')];
+    });
+
+    it('should exclude Pino thread-stream worker with valid structure', () => {
+      mockWorkerThreads({
+        isMainThread: false,
+        workerData: {
+          filename: '/path/to/worker.js',
+          workerData: {
+            $context: {
+              threadStreamVersion: '2.0.0'
+            },
+            target: 'pino-pretty'
+          }
+        }
+      });
+
+      const checkExclusion = require('../../src/util/excludedFromInstrumentation');
+      expect(checkExclusion()).to.be.true;
+    });
+
+    it('should exclude Pino thread-stream worker with targets property', () => {
+      mockWorkerThreads({
+        isMainThread: false,
+        workerData: {
+          filename: '/path/to/worker.js',
+          workerData: {
+            $context: {
+              threadStreamVersion: '2.1.0'
+            },
+            targets: [{ target: 'pino-pretty' }]
+          }
+        }
+      });
+
+      const checkExclusion = require('../../src/util/excludedFromInstrumentation');
+      expect(checkExclusion()).to.be.true;
+    });
+
+    it('should not exclude main thread', () => {
+      mockWorkerThreads({
+        isMainThread: true,
+        workerData: {
+          filename: '/path/to/worker.js',
+          workerData: {
+            $context: {
+              threadStreamVersion: '2.0.0'
+            }
+          }
+        }
+      });
+
+      const checkExclusion = require('../../src/util/excludedFromInstrumentation');
+      expect(checkExclusion()).to.be.false;
+    });
+
+    it('should not exclude worker without workerData', () => {
+      mockWorkerThreads({
+        isMainThread: false,
+        workerData: null
+      });
+
+      const checkExclusion = require('../../src/util/excludedFromInstrumentation');
+      expect(checkExclusion()).to.be.false;
+    });
+
+    it('should not exclude worker without filename', () => {
+      mockWorkerThreads({
+        isMainThread: false,
+        workerData: {
+          workerData: {
+            $context: {
+              threadStreamVersion: '2.0.0'
+            }
+          }
+        }
+      });
+
+      const checkExclusion = require('../../src/util/excludedFromInstrumentation');
+      expect(checkExclusion()).to.be.false;
+    });
+
+    it('should not exclude worker without nested workerData', () => {
+      mockWorkerThreads({
+        isMainThread: false,
+        workerData: {
+          filename: '/path/to/worker.js'
+        }
+      });
+
+      const checkExclusion = require('../../src/util/excludedFromInstrumentation');
+      expect(checkExclusion()).to.be.false;
+    });
+
+    it('should not exclude worker without $context', () => {
+      mockWorkerThreads({
+        isMainThread: false,
+        workerData: {
+          filename: '/path/to/worker.js',
+          workerData: {
+            someOtherProperty: 'value'
+          }
+        }
+      });
+
+      const checkExclusion = require('../../src/util/excludedFromInstrumentation');
+      expect(checkExclusion()).to.be.false;
+    });
+
+    it('should not exclude worker without threadStreamVersion', () => {
+      mockWorkerThreads({
+        isMainThread: false,
+        workerData: {
+          filename: '/path/to/worker.js',
+          workerData: {
+            $context: {
+              someOtherProperty: 'value'
+            }
+          }
+        }
+      });
+
+      const checkExclusion = require('../../src/util/excludedFromInstrumentation');
+      expect(checkExclusion()).to.be.false;
+    });
+
+    it('should not exclude non-Pino worker thread', () => {
+      mockWorkerThreads({
+        isMainThread: false,
+        workerData: {
+          customData: 'some other worker'
+        }
+      });
+
+      const checkExclusion = require('../../src/util/excludedFromInstrumentation');
+      expect(checkExclusion()).to.be.false;
+    });
+
+    function mockWorkerThreads(mockData) {
+      const mockModule = {
+        exports: mockData
+      };
+      require.cache[require.resolve('worker_threads')] = mockModule;
+    }
+  });
+
   function isExcluded(argv1) {
     process.argv[1] = argv1;
     return isExcludedFromInstrumentation();