refactor: removed agent/log.js and move the fn to agent connection (#2012)

From #2010

Author: kirrg001

packages/collector/src/agent/log.js

@@ -5,11 +5,14 @@
 
 'use strict';
 
-const log = require('./log');
-
 const pidStore = require('../pidStore/internalPidStore');
 
-/** @type {NodeJS.WritableStream} */
+/** @type {import('../agentConnection')} */
+let downstreamConnection;
+
+/** @type {NodeJS.WritableStream & {
+ *    setDownstreamConnection: (downstreamConnection: import('../agentConnection')) => void
+ * }} */
 module.exports = {
   /**
    * @param {*} record
@@ -30,7 +33,17 @@ module.exports = {
       stack = record.err.stack;
     }
 
-    log(logLevel, message, stack);
+    // CASE: It could be that the preinit functionality calls the logger before the agent connection is properly set up.
+    if (downstreamConnection) {
+      downstreamConnection.sendLogToAgent(logLevel, message, stack);
+    }
+  },
+
+  /**
+   * @param {import('../agentConnection')} _downstreamConnection
+   */
+  setDownstreamConnection: _downstreamConnection => {
+    downstreamConnection = _downstreamConnection;
   }
 };
 

packages/collector/src/agent/loggerToAgentStream.js

@@ -216,6 +216,52 @@ exports.checkWhetherAgentIsReadyToAcceptData = function checkWhetherAgentIsReady
   checkWhetherResponseForPathIsOkay(`/com.instana.plugin.nodejs.${pidStore.pid}`, cb);
 };
 
+/**
+ * @param {*} logLevel
+ * @param {*} message
+ * @param {*} stackTrace
+ */
+exports.sendLogToAgent = function sendLogToAgent(logLevel, message, stackTrace) {
+  /** @type {{m: string, st?: string}} */
+  const payloadObject = {
+    m: message.trim()
+  };
+
+  if (stackTrace) {
+    payloadObject.st = stackTrace.trim();
+  }
+
+  const payload = Buffer.from(JSON.stringify(payloadObject), 'utf8');
+
+  const req = http.request(
+    {
+      host: agentOpts.host,
+      port: agentOpts.port,
+      path: '/com.instana.agent.logger',
+      method: 'POST',
+      agent: http.agent,
+      headers: {
+        'Content-Type': 'application/json; charset=UTF-8',
+        'Content-Length': payload.length,
+        'x-log-level': logLevel
+      }
+    },
+    res => {
+      res.resume();
+    }
+  );
+
+  function swallow() {
+    // swallow all errors
+  }
+
+  req.setTimeout(agentOpts.requestTimeout, swallow);
+  req.on('error', swallow);
+
+  req.write(payload);
+  req.end();
+};
+
 /**
  * @param {string} path
  * @param {(...args: *) => *} cb

packages/collector/src/agentConnection.js

@@ -113,6 +113,8 @@ function init(userConfig = {}) {
   const announceCycle = require('./announceCycle');
   const metrics = require('./metrics');
 
+  log.setDownstreamConnection(agentConnection);
+
   pidStore.init(config);
   agentOpts.init(config);
   announceCycle.init(config, pidStore);

packages/collector/src/index.js

@@ -158,6 +158,14 @@ exports.init = function init(userConfig = {}) {
 
 exports.getLogger = () => instanaLogger;
 
+/**
+ *
+ * @param {import('./agentConnection')} downstreamConnection
+ */
+exports.setDownstreamConnection = downstreamConnection => {
+  loggerToAgentStream.setDownstreamConnection(downstreamConnection);
+};
+
 /**
  * @param {import('@instana/core/src/core').GenericLogger | *} _logger
  * @returns {boolean}

packages/collector/src/logger.js

@@ -46,6 +46,7 @@ const ignoreEndpoints = process.env.IGNORE_ENDPOINTS && JSON.parse(process.env.I
 const disable = process.env.AGENT_DISABLE_TRACING && JSON.parse(process.env.AGENT_DISABLE_TRACING);
 
 const uuids = {};
+const agentLogs = [];
 let discoveries = {};
 let rejectAnnounceAttempts = 0;
 let requests = {};
@@ -136,6 +137,16 @@ app.head(
   })
 );
 
+app.post('/com.instana.agent.logger', (req, res) => {
+  logger.info('Received log message from agent: %j', req.body);
+  agentLogs.push(req.body);
+  res.sendStatus(200);
+});
+
+app.get('/agent/logs', (req, res) => {
+  res.json(agentLogs);
+});
+
 app.post(
   '/com.instana.plugin.nodejs.:pid',
   checkExistenceOfKnownPid(function handleEntityData(req, res) {

packages/collector/test/apps/agentStub.js

@@ -175,6 +175,15 @@ class AgentStubControls {
     });
   }
 
+  getAgentLogs() {
+    return fetch(`http://127.0.0.1:${this.agentPort}/agent/logs`, {
+      method: 'GET',
+      headers: {
+        'Content-Type': 'application/json'
+      }
+    }).then(response => response.json());
+  }
+
   async reset() {
     // eslint-disable-next-line no-console
     console.log(`[AgentStubControls] reset ${this.agentPort}`);

packages/collector/test/apps/agentStubControls.js

@@ -0,0 +1,44 @@
+/*
+ * (c) Copyright IBM Corp. 20215
+ */
+
+'use strict';
+
+// NOTE: c8 bug https://github.com/bcoe/c8/issues/166
+process.on('SIGTERM', () => {
+  process.disconnect();
+  process.exit(0);
+});
+
+const agentPort = process.env.INSTANA_AGENT_PORT;
+
+require('../../../..')({
+  // NOTE: The test env mutes all logs by default. No logs, no agent logs.
+  level: 'info'
+});
+
+const express = require('express');
+const port = require('../../../test_util/app-port')();
+const app = express();
+
+const logPrefix = `Agent Logs App (${process.pid}):\t`;
+
+app.get('/', (req, res) => {
+  res.send();
+});
+
+app.get('/trace', async (req, res) => {
+  await fetch(`http://127.0.0.1:${agentPort}`);
+  res.send();
+});
+
+app.listen(port, () => {
+  log(`Listening on port: ${port}`);
+});
+
+function log() {
+  /* eslint-disable no-console */
+  const args = Array.prototype.slice.call(arguments);
+  args[0] = logPrefix + args[0];
+  console.log.apply(console, args);
+}

packages/collector/test/tracing/misc/agent-logs/app.js

@@ -0,0 +1,55 @@
+/*
+ * (c) Copyright IBM Corp. 2025
+ */
+
+'use strict';
+
+const { expect } = require('chai');
+const supportedVersion = require('@instana/core').tracing.supportedVersion;
+const config = require('../../../../../core/test/config');
+const testUtils = require('../../../../../core/test/test_util');
+const ProcessControls = require('../../../test_util/ProcessControls');
+const globalAgent = require('../../../globalAgent');
+const agentControls = globalAgent.instance;
+
+const mochaSuiteFn = supportedVersion(process.versions.node) ? describe : describe.skip;
+
+mochaSuiteFn('tracing/agent logs', function () {
+  this.timeout(config.getTestTimeout());
+  globalAgent.setUpCleanUpHooks();
+
+  describe('Ensure agent logs are transmitted', function () {
+    let controls;
+
+    before(async () => {
+      controls = new ProcessControls({
+        dirname: __dirname,
+        useGlobalAgent: true
+      });
+
+      await controls.startAndWaitForAgentConnection();
+    });
+
+    beforeEach(async () => {
+      await agentControls.clearReceivedTraceData();
+    });
+
+    after(async () => {
+      await controls.stop();
+    });
+
+    it('expect agent logs data', async () => {
+      await controls.sendRequest({
+        path: '/trace'
+      });
+
+      await testUtils.retry(async () => {
+        const spans = await agentControls.getSpans();
+        const agentLogs = await agentControls.getAgentLogs();
+
+        expect(spans.length).to.equal(2);
+        expect(agentLogs.length).to.equal(9);
+      });
+    });
+  });
+});