diff --git a/packages/dd-trace/src/exporters/agent/writer.js b/packages/dd-trace/src/exporters/agent/writer.js index 339a33b8bb0..1438b1080e7 100644 --- a/packages/dd-trace/src/exporters/agent/writer.js +++ b/packages/dd-trace/src/exporters/agent/writer.js @@ -3,7 +3,7 @@ const { inspect } = require('util') const request = require('../common/request') -const { startupLog } = require('../../startup-log') +const { logAgentError } = require('../../startup-log') const runtimeMetrics = require('../../runtime_metrics') const log = require('../../log') const tracerVersion = require('../../../../../package.json').version @@ -30,8 +30,10 @@ class AgentWriter extends BaseWriter { const { _headers, _lookup, _protocolVersion, _url } = this makeRequest(_protocolVersion, data, count, _url, _headers, _lookup, (err, res, status) => { - // Note that logging will only happen once, regardless of how many times this is called. - startupLog(status !== 404 && status !== 200 ? { status, message: err?.message ?? inspect(err) } : undefined) + // Log agent connection diagnostic error (only once) + if (status && status !== 404 && status !== 200) { + logAgentError({ status, message: err?.message ?? inspect(err) }) + } if (status) { runtimeMetrics.increment(`${METRIC_PREFIX}.responses`, true) diff --git a/packages/dd-trace/src/proxy.js b/packages/dd-trace/src/proxy.js index 80a6fba2f70..cc42333af8e 100644 --- a/packages/dd-trace/src/proxy.js +++ b/packages/dd-trace/src/proxy.js @@ -6,7 +6,7 @@ const DatadogTracer = require('./tracer') const getConfig = require('./config') const runtimeMetrics = require('./runtime_metrics') const log = require('./log') -const { setStartupLogPluginManager } = require('./startup-log') +const { setStartupLogPluginManager, startupLog } = require('./startup-log') const DynamicInstrumentation = require('./debugger') const telemetry = require('./telemetry') const nomenclature = require('./service-naming') @@ -288,6 +288,8 @@ class Tracer extends NoopProxy { this._pluginManager.configure(config) DynamicInstrumentation.configure(config) setStartupLogPluginManager(this._pluginManager) + // Emit startup log immediately after tracer is fully initialized + startupLog() } } diff --git a/packages/dd-trace/src/startup-log.js b/packages/dd-trace/src/startup-log.js index dac4df417b8..de3b04622fc 100644 --- a/packages/dd-trace/src/startup-log.js +++ b/packages/dd-trace/src/startup-log.js @@ -4,38 +4,45 @@ const os = require('os') const { inspect } = require('util') const tracerVersion = require('../../../package.json').version const { getAgentUrl } = require('./agent/url') -const { info, warn } = require('./log/writer') +const { warn } = require('./log/writer') const errors = {} let config let pluginManager /** @type {import('./sampling_rule')[]} */ let samplingRules = [] -let alreadyRan = false +let startupLogRan = false +let agentErrorLogged = false /** - * @param {{ status: number, message: string } } [agentError] + * Logs the tracer configuration on startup */ -function startupLog (agentError) { - if (alreadyRan || !config || !config.startupLogs || !pluginManager) { +function startupLog () { + if (startupLogRan || !config || !config.startupLogs || !pluginManager) { return } - alreadyRan = true + startupLogRan = true const out = tracerInfo() + warn('DATADOG TRACER CONFIGURATION - ' + out) +} - if (agentError) { - out.agent_error = agentError.message +/** + * Logs a diagnostic error when the agent connection fails + * @param {{ status: number, message: string }} agentError + */ +function logAgentError (agentError) { + if (agentErrorLogged || !config || !config.startupLogs) { + return } - info('DATADOG TRACER CONFIGURATION - ' + out) - if (agentError) { - warn('DATADOG TRACER DIAGNOSTIC - Agent Error: ' + agentError.message) - errors.agentError = { - code: agentError.status, - message: `Agent Error: ${agentError.message}`, - } + agentErrorLogged = true + + warn('DATADOG TRACER DIAGNOSTIC - Agent Error: ' + agentError.message) + errors.agentError = { + code: agentError.status, + message: `Agent Error: ${agentError.message}`, } } @@ -104,6 +111,7 @@ function setSamplingRules (theRules) { module.exports = { startupLog, + logAgentError, setStartupLogConfig, setStartupLogPluginManager, setSamplingRules, diff --git a/packages/dd-trace/test/startup-log.spec.js b/packages/dd-trace/test/startup-log.spec.js index 84ba6d28581..2199648228f 100644 --- a/packages/dd-trace/test/startup-log.spec.js +++ b/packages/dd-trace/test/startup-log.spec.js @@ -17,7 +17,6 @@ describe('startup logging', () => { let tracerInfoMethod before(() => { - sinon.stub(console, 'info') sinon.stub(console, 'warn') delete require.cache[require.resolve('../src/startup-log')] const { @@ -25,6 +24,7 @@ describe('startup logging', () => { setStartupLogPluginManager, setSamplingRules, startupLog, + logAgentError, tracerInfo, } = require('../src/startup-log') tracerInfoMethod = tracerInfo @@ -60,13 +60,11 @@ describe('startup logging', () => { ]) // Use sinon's stub instance directly to avoid type errors // eslint-disable-next-line no-console - const infoStub = /** @type {sinon.SinonStub} */ (console.info) - // eslint-disable-next-line no-console const warnStub = /** @type {sinon.SinonStub} */ (console.warn) - startupLog({ message: 'Error: fake error' }) - firstStderrCall = infoStub.firstCall - secondStderrCall = warnStub.firstCall - infoStub.restore() + startupLog() + logAgentError({ status: 500, message: 'Error: fake error' }) + firstStderrCall = warnStub.firstCall + secondStderrCall = warnStub.secondCall warnStub.restore() }) @@ -103,7 +101,7 @@ describe('startup logging', () => { }) }) - it('startupLog should correctly also output the diagnostic message', () => { + it('logAgentError should correctly output the diagnostic message separately', () => { assert.strictEqual(secondStderrCall.args[0], 'DATADOG TRACER DIAGNOSTIC - Agent Error: Error: fake error') }) }) @@ -114,7 +112,7 @@ describe('data_streams_enabled', () => { }) it('should be true when env var is true and config is unset', () => { - sinon.stub(console, 'info') + sinon.stub(console, 'warn') delete require.cache[require.resolve('../src/startup-log')] const { setStartupLogConfig, @@ -127,14 +125,14 @@ describe('data_streams_enabled', () => { setStartupLogPluginManager({ _pluginsByName: {} }) startupLog() /* eslint-disable-next-line no-console */ - const infoStub = /** @type {sinon.SinonStub} */ (console.info) - const logObj = JSON.parse(infoStub.firstCall.args[0].replace('DATADOG TRACER CONFIGURATION - ', '')) - infoStub.restore() + const warnStub = /** @type {sinon.SinonStub} */ (console.warn) + const logObj = JSON.parse(warnStub.firstCall.args[0].replace('DATADOG TRACER CONFIGURATION - ', '')) + warnStub.restore() assert.strictEqual(logObj.data_streams_enabled, true) }) it('should be true when env var is not set and config is true', () => { - sinon.stub(console, 'info') + sinon.stub(console, 'warn') delete require.cache[require.resolve('../src/startup-log')] const { setStartupLogConfig, @@ -147,14 +145,14 @@ describe('data_streams_enabled', () => { setStartupLogPluginManager({ _pluginsByName: {} }) startupLog() /* eslint-disable-next-line no-console */ - const infoStub = /** @type {sinon.SinonStub} */ (console.info) - const logObj = JSON.parse(infoStub.firstCall.args[0].replace('DATADOG TRACER CONFIGURATION - ', '')) - infoStub.restore() + const warnStub = /** @type {sinon.SinonStub} */ (console.warn) + const logObj = JSON.parse(warnStub.firstCall.args[0].replace('DATADOG TRACER CONFIGURATION - ', '')) + warnStub.restore() assert.strictEqual(logObj.data_streams_enabled, true) }) it('should be false when env var is true but config is false', () => { - sinon.stub(console, 'info') + sinon.stub(console, 'warn') delete require.cache[require.resolve('../src/startup-log')] const { setStartupLogConfig, @@ -167,9 +165,9 @@ describe('data_streams_enabled', () => { setStartupLogPluginManager({ _pluginsByName: {} }) startupLog() /* eslint-disable-next-line no-console */ - const infoStub = /** @type {sinon.SinonStub} */ (console.info) - const logObj = JSON.parse(infoStub.firstCall.args[0].replace('DATADOG TRACER CONFIGURATION - ', '')) - infoStub.restore() + const warnStub = /** @type {sinon.SinonStub} */ (console.warn) + const logObj = JSON.parse(warnStub.firstCall.args[0].replace('DATADOG TRACER CONFIGURATION - ', '')) + warnStub.restore() assert.strictEqual(logObj.data_streams_enabled, false) }) }) @@ -183,7 +181,7 @@ describe('profiling_enabled', () => { ['auto', true], ['true', true], ].forEach(([envVar, expected]) => { - sinon.stub(console, 'info') + sinon.stub(console, 'warn') delete require.cache[require.resolve('../src/startup-log')] const { setStartupLogConfig, @@ -196,9 +194,9 @@ describe('profiling_enabled', () => { setStartupLogPluginManager({ _pluginsByName: {} }) startupLog() /* eslint-disable-next-line no-console */ - const infoStub = /** @type {sinon.SinonStub} */ (console.info) - const logObj = JSON.parse(infoStub.firstCall.args[0].replace('DATADOG TRACER CONFIGURATION - ', '')) - infoStub.restore() + const warnStub = /** @type {sinon.SinonStub} */ (console.warn) + const logObj = JSON.parse(warnStub.firstCall.args[0].replace('DATADOG TRACER CONFIGURATION - ', '')) + warnStub.restore() assert.strictEqual(logObj.profiling_enabled, expected) }) })