diff --git a/packages/collector/src/agent/log.js b/packages/collector/src/agent/log.js deleted file mode 100644 index ceb413218b..0000000000 --- a/packages/collector/src/agent/log.js +++ /dev/null @@ -1,54 +0,0 @@ -/* - * (c) Copyright IBM Corp. 2021 - * (c) Copyright Instana Inc. and contributors 2016 - */ - -'use strict'; - -const { http } = require('@instana/core').uninstrumentedHttp; -const agentOpts = require('./opts'); - -/** - * @param {'debug' | 'info' | 'warning' | 'error'} logLevel - * @param {string} message - * @param {*} stackTrace - */ -module.exports = function log(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(); - } - ); - - req.setTimeout(agentOpts.requestTimeout, swallow); - req.on('error', swallow); - - req.write(payload); - req.end(); -}; - -function swallow() { - // swallow all errors -} diff --git a/packages/collector/src/agent/loggerToAgentStream.js b/packages/collector/src/agent/loggerToAgentStream.js index 053539fbd9..9e80fa981a 100644 --- a/packages/collector/src/agent/loggerToAgentStream.js +++ b/packages/collector/src/agent/loggerToAgentStream.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; } }; diff --git a/packages/collector/src/agentConnection.js b/packages/collector/src/agentConnection.js index 856630a2de..7996406268 100644 --- a/packages/collector/src/agentConnection.js +++ b/packages/collector/src/agentConnection.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 diff --git a/packages/collector/src/index.js b/packages/collector/src/index.js index 0bb842abfb..3c2c96954d 100644 --- a/packages/collector/src/index.js +++ b/packages/collector/src/index.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); diff --git a/packages/collector/src/logger.js b/packages/collector/src/logger.js index c31bcbf348..215a8c4c31 100644 --- a/packages/collector/src/logger.js +++ b/packages/collector/src/logger.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} diff --git a/packages/collector/test/apps/agentStub.js b/packages/collector/test/apps/agentStub.js index f102919ca8..d87647388b 100644 --- a/packages/collector/test/apps/agentStub.js +++ b/packages/collector/test/apps/agentStub.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) { diff --git a/packages/collector/test/apps/agentStubControls.js b/packages/collector/test/apps/agentStubControls.js index 3606eeeef5..a69b4d5ac0 100644 --- a/packages/collector/test/apps/agentStubControls.js +++ b/packages/collector/test/apps/agentStubControls.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}`); diff --git a/packages/collector/test/tracing/misc/agent-logs/app.js b/packages/collector/test/tracing/misc/agent-logs/app.js new file mode 100644 index 0000000000..c3f6940e72 --- /dev/null +++ b/packages/collector/test/tracing/misc/agent-logs/app.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); +} diff --git a/packages/collector/test/tracing/misc/agent-logs/test.js b/packages/collector/test/tracing/misc/agent-logs/test.js new file mode 100644 index 0000000000..c4ca978296 --- /dev/null +++ b/packages/collector/test/tracing/misc/agent-logs/test.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); + }); + }); + }); +});