fix: resolved bunyan npm installation warning (#1447)

refs https://jsw.ibm.com/browse/INSTA-12533

Co-authored-by: kirrg001 <[email protected]>
Co-authored-by: Arya <[email protected]>

Author: 3 people

package-lock.json

@@ -73,6 +73,10 @@
     {
       "name": "Arya Mohanan",
       "email": "[email protected]"
+    },
+    {
+      "name": "Abhilash Sivan",
+      "email": "[email protected]"
     }
   ],
   "bugs": {
@@ -81,15 +85,14 @@
   "dependencies": {
     "@instana/core": "4.5.0",
     "@instana/shared-metrics": "4.5.0",
-    "bunyan": "^1.8.15",
+    "pino": "^9.6.0",
     "semver": "^7.5.4",
     "serialize-error": "^8.1.0"
   },
   "optionalDependencies": {
     "@instana/autoprofile": "4.5.0"
   },
   "devDependencies": {
-    "@types/bunyan": "^1.8.8",
     "opentracing": "^0.14.5",
     "typeorm": "^0.3.20"
   }

packages/collector/package.json

@@ -267,9 +267,11 @@ exports.sendSpans = function sendSpans(spans, cb) {
     if (err && !maxContentErrorHasBeenLogged && err instanceof PayloadTooLargeError) {
       logLargeSpans(spans);
     } else if (err) {
-      logger.debug('Failed to send: %s', getSpanLengthInfo(spans));
+      const spanInfo = getSpanLengthInfo(spans);
+      logger.debug(`Failed to send: ${JSON.stringify(spanInfo)}`);
     } else {
-      logger.debug('Successfully sent: %s', getSpanLengthInfo(spans));
+      const spanInfo = getSpanLengthInfo(spans);
+      logger.debug(`Successfully sent:${JSON.stringify(spanInfo)}`);
     }
     cb(err);
   });

packages/collector/src/agent/bunyanToAgentStream.js renamed to packages/collector/src/agent/loggerToAgentStream.js

@@ -16,12 +16,12 @@ try {
   // thread (0).
 }
 
-const bunyan = require('bunyan');
-const { logger } = require('@instana/core');
+const uninstrumentedLogger = require('./uninstrumentedLogger');
 
-const bunyanToAgentStream = require('./agent/bunyanToAgentStream');
+const { logger } = require('@instana/core');
+const loggerToAgentStream = require('./agent/loggerToAgentStream');
 
-/** @type {bunyan | import('@instana/core/src/core').GenericLogger} */
+/** @type {import('@instana/core/src/core').GenericLogger} */
 let parentLogger = null;
 /** @type {Object.<string, (logger: import('@instana/core/src/core').GenericLogger) => *>} */
 const registry = {};
@@ -35,37 +35,63 @@ exports.init = function init(config, isReInit) {
     // A bunyan or pino logger has been provided via config. In either case we create a child logger directly under the
     // given logger which serves as the parent for all loggers we create later on.
     parentLogger = config.logger.child({
-      module: 'instana-nodejs-logger-parent',
-      __in: 1
+      module: 'instana-nodejs-logger-parent'
     });
   } else if (config.logger && hasLoggingFunctions(config.logger)) {
-    // A custom non-bunyan logger has been provided via config. We use it as is.
+    // A custom non-bunyan/non-pino logger has been provided via config. We use it as is.
     parentLogger = config.logger;
   } else {
-    // No custom logger has been provided via config, we create a new bunyan logger as the parent logger for all loggers
+    // No custom logger has been provided via config, we create a new pino logger as the parent logger for all loggers
     // we create later on.
-    parentLogger = bunyan.createLogger({
+    parentLogger = uninstrumentedLogger({
       name: '@instana/collector',
-      thread: threadId,
-      __in: 1
+      level: 'info'
     });
   }
-  if (isBunyan(parentLogger)) {
+
+  // Passing the log stream to agentStream for Debugging purposes
+  // TODO: consider adding winston and other major loggers also for this
+  if (isPinoLogger(parentLogger)) {
+    // This consoleStream creates a destination stream for the logger that writes log data to the standard output.
+    // Since we are using multistream here, this needs to be specified explicitly
+
+    const consoleStream = uninstrumentedLogger.destination(parentLogger.destination);
+
+    const multiStream = {
+      /**
+       * Custom write method to send logs to multiple destinations
+       * @param {string} chunk
+       */
+      write(chunk) {
+        consoleStream.write(chunk);
+
+        loggerToAgentStream.write(chunk);
+      }
+    };
+
+    parentLogger = uninstrumentedLogger(
+      {
+        ...parentLogger.levels,
+        level: parentLogger.level || 'info',
+        base: parentLogger.bindings()
+      },
+      multiStream
+    );
+  } else if (parentLogger && parentLogger.addStream) {
     // in case we are using a bunyan logger we also forward logs to the agent
-    /** @type {bunyan} */ (parentLogger).addStream({
+    parentLogger.addStream({
       type: 'raw',
-      stream: bunyanToAgentStream,
+      stream: loggerToAgentStream,
       level: 'info'
     });
-    if (process.env['INSTANA_DEBUG']) {
-      /** @type {bunyan} */ (parentLogger).level('debug');
-    } else if (config.level) {
-      /** @type {bunyan} */ (parentLogger).level(/** @type {import('bunyan').LogLevel} */ (config.level));
-    } else if (process.env['INSTANA_LOG_LEVEL']) {
-      /** @type {bunyan} */ (parentLogger).level(
-        /** @type {import('bunyan').LogLevel} */ (process.env['INSTANA_LOG_LEVEL'].toLowerCase())
-      );
-    }
+  }
+
+  if (process.env['INSTANA_DEBUG']) {
+    setLoggerLevel(parentLogger, 'debug');
+  } else if (config.level) {
+    setLoggerLevel(parentLogger, config.level);
+  } else if (process.env['INSTANA_LOG_LEVEL']) {
+    setLoggerLevel(parentLogger, process.env['INSTANA_LOG_LEVEL'].toLowerCase());
   }
 
   if (isReInit) {
@@ -81,18 +107,21 @@ exports.init = function init(config, isReInit) {
 /**
  * @param {string} loggerName
  * @param {(logger: import('@instana/core/src/core').GenericLogger) => *} [reInitFn]
+ * @param {string|null} [level] - Optional log level
  * @returns {import('@instana/core/src/core').GenericLogger}
  */
-exports.getLogger = function getLogger(loggerName, reInitFn) {
+exports.getLogger = function getLogger(loggerName, reInitFn, level) {
   if (!parentLogger) {
     exports.init({});
   }
+
   let _logger;
 
   if (typeof parentLogger.child === 'function') {
     // Either bunyan or pino, both support parent-child relationships between loggers.
     _logger = parentLogger.child({
-      module: loggerName
+      module: loggerName,
+      threadId
     });
   } else {
     // Unknown logger type (neither bunyan nor pino), we simply return the user provided custom logger as-is.
@@ -106,17 +135,13 @@ exports.getLogger = function getLogger(loggerName, reInitFn) {
     registry[loggerName] = reInitFn;
   }
 
+  if (level) {
+    setLoggerLevel(_logger, level);
+  }
+
   return /** @type {import('@instana/core/src/core').GenericLogger} */ (_logger);
 };
 
-/**
- * @param {import('bunyan') | *} _logger
- * @returns {boolean}
- */
-function isBunyan(_logger) {
-  return _logger instanceof bunyan;
-}
-
 /**
  * @param {import('@instana/core/src/core').GenericLogger | *} _logger
  * @returns {boolean}
@@ -129,3 +154,25 @@ function hasLoggingFunctions(_logger) {
     typeof _logger.error === 'function'
   );
 }
+
+/**
+ * @param {import("@instana/core/src/core").GenericLogger} _logger
+ * @param {string|number} level
+ */
+function setLoggerLevel(_logger, level) {
+  if (typeof _logger.setLevel === 'function') {
+    _logger.setLevel(level);
+  } else {
+    _logger.level = level;
+  }
+}
+
+/**
+ * @param {*} _logger
+ * @returns {boolean}
+ */
+function isPinoLogger(_logger) {
+  return (
+    _logger && typeof _logger === 'object' && typeof _logger.child === 'function' && typeof _logger.level === 'string'
+  );
+}

packages/collector/src/agentConnection.js

@@ -0,0 +1,30 @@
+/*
+ * (c) Copyright IBM Corp. 2024
+ */
+
+'use strict';
+
+const pinoWasRequiredBeforeUs = Object.keys(require.cache).some(key => key.includes('node_modules/pino'));
+
+// eslint-disable-next-line import/no-extraneous-dependencies, instana/no-unsafe-require
+
+const pino = require('pino').default;
+
+// TODO: Fix the issue with Pino instrumentation. If Pino is required multiple times,
+//       only the first require is instrumented. `onFileLoad` causes the behavior for that.
+//       See https://jsw.ibm.com/browse/INSTA-23066
+// NOTE: We need the removal of the cache here anyway, because we do not want to trigger the pino instrumentation.
+//       This is an uninstrumented pino logger.
+//       If pino was required before us, we leave the cache as it is.
+// NOTE: Clearing the require cache is only needed because of onFileLoad usage in the pino instrumentation.
+//       As soon as we can migrate to use onModuleLoad in the instrumentation,
+//       we can remove this and ensure that the internal logger is called before the instr initialization.
+if (!pinoWasRequiredBeforeUs) {
+  Object.keys(require.cache).forEach(key => {
+    if (key.includes('node_modules/pino')) {
+      delete require.cache[key];
+    }
+  });
+}
+
+module.exports = pino;