Skip to content

Commit 6bef168

Browse files
bm1549claude
andauthored
fix(startup-log): emit immediately after init and send to stderr (#7470)
* fix(startup-log): emit immediately after init and send to stderr Startup logs now emit immediately after tracer initialization instead of being delayed until the first payload is sent to the agent. They are also sent to stderr (via console.error) instead of stdout, following Unix conventions and aligning with other Datadog language tracers. Changes: - Added startupLog() call in proxy.js after initialization completes - Changed output from info() to error() to use stderr - Removed duplicate late call in writer.js that was firing on first payload - Updated tests to expect console.error instead of console.info Co-Authored-By: Claude Sonnet 4.5 <noreply@anthropic.com> * fix(tests): update data_streams_enabled tests to use console.error After merging master, the new data_streams_enabled tests were still using console.info instead of console.error. Updated all three tests in that describe block to use console.error to match the stderr output change. Co-Authored-By: Claude Sonnet 4.5 <noreply@anthropic.com> * fix(startup-log): separate initialization and agent diagnostic logs Previously, the startup log and agent connection diagnostic were coupled together in a single call. This meant that if the startup log was emitted immediately (as intended), we would lose the agent connection diagnostic that happens on the first write attempt. Changes: - Split startupLog() into two separate functions: - startupLog(): Logs tracer configuration immediately after init - logAgentError(): Logs agent connection diagnostic on first write error - Each function maintains its own "already ran" flag to log only once - Updated writer.js to call logAgentError() when agent responds with error - Updated tests to verify both logs are emitted correctly and separately This ensures users get both the immediate startup configuration log AND the agent connection diagnostic if there's an issue reaching the agent. Co-Authored-By: Claude Sonnet 4.5 <noreply@anthropic.com> * fix(startup-log): use warn for both startup log and agent diagnostic Changed startup log to use warn() instead of error() for consistency. Both the startup configuration log and agent diagnostic now use warn(), which outputs to stderr via console.warn(). Changes: - startup-log.js: Changed startupLog() to use warn() instead of error() - Removed unused error import from log/writer - Updated all tests to expect console.warn instead of console.error This is more semantically appropriate since both logs are diagnostic information rather than actual errors. Co-Authored-By: Claude Sonnet 4.5 <noreply@anthropic.com> --------- Co-authored-by: Claude Sonnet 4.5 <noreply@anthropic.com>
1 parent a3dff51 commit 6bef168

4 files changed

Lines changed: 53 additions & 43 deletions

File tree

packages/dd-trace/src/exporters/agent/writer.js

Lines changed: 5 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -3,7 +3,7 @@
33
const { inspect } = require('util')
44

55
const request = require('../common/request')
6-
const { startupLog } = require('../../startup-log')
6+
const { logAgentError } = require('../../startup-log')
77
const runtimeMetrics = require('../../runtime_metrics')
88
const log = require('../../log')
99
const tracerVersion = require('../../../../../package.json').version
@@ -30,8 +30,10 @@ class AgentWriter extends BaseWriter {
3030

3131
const { _headers, _lookup, _protocolVersion, _url } = this
3232
makeRequest(_protocolVersion, data, count, _url, _headers, _lookup, (err, res, status) => {
33-
// Note that logging will only happen once, regardless of how many times this is called.
34-
startupLog(status !== 404 && status !== 200 ? { status, message: err?.message ?? inspect(err) } : undefined)
33+
// Log agent connection diagnostic error (only once)
34+
if (status && status !== 404 && status !== 200) {
35+
logAgentError({ status, message: err?.message ?? inspect(err) })
36+
}
3537

3638
if (status) {
3739
runtimeMetrics.increment(`${METRIC_PREFIX}.responses`, true)

packages/dd-trace/src/proxy.js

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -6,7 +6,7 @@ const DatadogTracer = require('./tracer')
66
const getConfig = require('./config')
77
const runtimeMetrics = require('./runtime_metrics')
88
const log = require('./log')
9-
const { setStartupLogPluginManager } = require('./startup-log')
9+
const { setStartupLogPluginManager, startupLog } = require('./startup-log')
1010
const DynamicInstrumentation = require('./debugger')
1111
const telemetry = require('./telemetry')
1212
const nomenclature = require('./service-naming')
@@ -288,6 +288,8 @@ class Tracer extends NoopProxy {
288288
this._pluginManager.configure(config)
289289
DynamicInstrumentation.configure(config)
290290
setStartupLogPluginManager(this._pluginManager)
291+
// Emit startup log immediately after tracer is fully initialized
292+
startupLog()
291293
}
292294
}
293295

packages/dd-trace/src/startup-log.js

Lines changed: 23 additions & 15 deletions
Original file line numberDiff line numberDiff line change
@@ -4,38 +4,45 @@ const os = require('os')
44
const { inspect } = require('util')
55
const tracerVersion = require('../../../package.json').version
66
const { getAgentUrl } = require('./agent/url')
7-
const { info, warn } = require('./log/writer')
7+
const { warn } = require('./log/writer')
88

99
const errors = {}
1010
let config
1111
let pluginManager
1212
/** @type {import('./sampling_rule')[]} */
1313
let samplingRules = []
14-
let alreadyRan = false
14+
let startupLogRan = false
15+
let agentErrorLogged = false
1516

1617
/**
17-
* @param {{ status: number, message: string } } [agentError]
18+
* Logs the tracer configuration on startup
1819
*/
19-
function startupLog (agentError) {
20-
if (alreadyRan || !config || !config.startupLogs || !pluginManager) {
20+
function startupLog () {
21+
if (startupLogRan || !config || !config.startupLogs || !pluginManager) {
2122
return
2223
}
2324

24-
alreadyRan = true
25+
startupLogRan = true
2526

2627
const out = tracerInfo()
28+
warn('DATADOG TRACER CONFIGURATION - ' + out)
29+
}
2730

28-
if (agentError) {
29-
out.agent_error = agentError.message
31+
/**
32+
* Logs a diagnostic error when the agent connection fails
33+
* @param {{ status: number, message: string }} agentError
34+
*/
35+
function logAgentError (agentError) {
36+
if (agentErrorLogged || !config || !config.startupLogs) {
37+
return
3038
}
3139

32-
info('DATADOG TRACER CONFIGURATION - ' + out)
33-
if (agentError) {
34-
warn('DATADOG TRACER DIAGNOSTIC - Agent Error: ' + agentError.message)
35-
errors.agentError = {
36-
code: agentError.status,
37-
message: `Agent Error: ${agentError.message}`,
38-
}
40+
agentErrorLogged = true
41+
42+
warn('DATADOG TRACER DIAGNOSTIC - Agent Error: ' + agentError.message)
43+
errors.agentError = {
44+
code: agentError.status,
45+
message: `Agent Error: ${agentError.message}`,
3946
}
4047
}
4148

@@ -104,6 +111,7 @@ function setSamplingRules (theRules) {
104111

105112
module.exports = {
106113
startupLog,
114+
logAgentError,
107115
setStartupLogConfig,
108116
setStartupLogPluginManager,
109117
setSamplingRules,

packages/dd-trace/test/startup-log.spec.js

Lines changed: 22 additions & 24 deletions
Original file line numberDiff line numberDiff line change
@@ -17,14 +17,14 @@ describe('startup logging', () => {
1717
let tracerInfoMethod
1818

1919
before(() => {
20-
sinon.stub(console, 'info')
2120
sinon.stub(console, 'warn')
2221
delete require.cache[require.resolve('../src/startup-log')]
2322
const {
2423
setStartupLogConfig,
2524
setStartupLogPluginManager,
2625
setSamplingRules,
2726
startupLog,
27+
logAgentError,
2828
tracerInfo,
2929
} = require('../src/startup-log')
3030
tracerInfoMethod = tracerInfo
@@ -60,13 +60,11 @@ describe('startup logging', () => {
6060
])
6161
// Use sinon's stub instance directly to avoid type errors
6262
// eslint-disable-next-line no-console
63-
const infoStub = /** @type {sinon.SinonStub} */ (console.info)
64-
// eslint-disable-next-line no-console
6563
const warnStub = /** @type {sinon.SinonStub} */ (console.warn)
66-
startupLog({ message: 'Error: fake error' })
67-
firstStderrCall = infoStub.firstCall
68-
secondStderrCall = warnStub.firstCall
69-
infoStub.restore()
64+
startupLog()
65+
logAgentError({ status: 500, message: 'Error: fake error' })
66+
firstStderrCall = warnStub.firstCall
67+
secondStderrCall = warnStub.secondCall
7068
warnStub.restore()
7169
})
7270

@@ -103,7 +101,7 @@ describe('startup logging', () => {
103101
})
104102
})
105103

106-
it('startupLog should correctly also output the diagnostic message', () => {
104+
it('logAgentError should correctly output the diagnostic message separately', () => {
107105
assert.strictEqual(secondStderrCall.args[0], 'DATADOG TRACER DIAGNOSTIC - Agent Error: Error: fake error')
108106
})
109107
})
@@ -114,7 +112,7 @@ describe('data_streams_enabled', () => {
114112
})
115113

116114
it('should be true when env var is true and config is unset', () => {
117-
sinon.stub(console, 'info')
115+
sinon.stub(console, 'warn')
118116
delete require.cache[require.resolve('../src/startup-log')]
119117
const {
120118
setStartupLogConfig,
@@ -127,14 +125,14 @@ describe('data_streams_enabled', () => {
127125
setStartupLogPluginManager({ _pluginsByName: {} })
128126
startupLog()
129127
/* eslint-disable-next-line no-console */
130-
const infoStub = /** @type {sinon.SinonStub} */ (console.info)
131-
const logObj = JSON.parse(infoStub.firstCall.args[0].replace('DATADOG TRACER CONFIGURATION - ', ''))
132-
infoStub.restore()
128+
const warnStub = /** @type {sinon.SinonStub} */ (console.warn)
129+
const logObj = JSON.parse(warnStub.firstCall.args[0].replace('DATADOG TRACER CONFIGURATION - ', ''))
130+
warnStub.restore()
133131
assert.strictEqual(logObj.data_streams_enabled, true)
134132
})
135133

136134
it('should be true when env var is not set and config is true', () => {
137-
sinon.stub(console, 'info')
135+
sinon.stub(console, 'warn')
138136
delete require.cache[require.resolve('../src/startup-log')]
139137
const {
140138
setStartupLogConfig,
@@ -147,14 +145,14 @@ describe('data_streams_enabled', () => {
147145
setStartupLogPluginManager({ _pluginsByName: {} })
148146
startupLog()
149147
/* eslint-disable-next-line no-console */
150-
const infoStub = /** @type {sinon.SinonStub} */ (console.info)
151-
const logObj = JSON.parse(infoStub.firstCall.args[0].replace('DATADOG TRACER CONFIGURATION - ', ''))
152-
infoStub.restore()
148+
const warnStub = /** @type {sinon.SinonStub} */ (console.warn)
149+
const logObj = JSON.parse(warnStub.firstCall.args[0].replace('DATADOG TRACER CONFIGURATION - ', ''))
150+
warnStub.restore()
153151
assert.strictEqual(logObj.data_streams_enabled, true)
154152
})
155153

156154
it('should be false when env var is true but config is false', () => {
157-
sinon.stub(console, 'info')
155+
sinon.stub(console, 'warn')
158156
delete require.cache[require.resolve('../src/startup-log')]
159157
const {
160158
setStartupLogConfig,
@@ -167,9 +165,9 @@ describe('data_streams_enabled', () => {
167165
setStartupLogPluginManager({ _pluginsByName: {} })
168166
startupLog()
169167
/* eslint-disable-next-line no-console */
170-
const infoStub = /** @type {sinon.SinonStub} */ (console.info)
171-
const logObj = JSON.parse(infoStub.firstCall.args[0].replace('DATADOG TRACER CONFIGURATION - ', ''))
172-
infoStub.restore()
168+
const warnStub = /** @type {sinon.SinonStub} */ (console.warn)
169+
const logObj = JSON.parse(warnStub.firstCall.args[0].replace('DATADOG TRACER CONFIGURATION - ', ''))
170+
warnStub.restore()
173171
assert.strictEqual(logObj.data_streams_enabled, false)
174172
})
175173
})
@@ -183,7 +181,7 @@ describe('profiling_enabled', () => {
183181
['auto', true],
184182
['true', true],
185183
].forEach(([envVar, expected]) => {
186-
sinon.stub(console, 'info')
184+
sinon.stub(console, 'warn')
187185
delete require.cache[require.resolve('../src/startup-log')]
188186
const {
189187
setStartupLogConfig,
@@ -196,9 +194,9 @@ describe('profiling_enabled', () => {
196194
setStartupLogPluginManager({ _pluginsByName: {} })
197195
startupLog()
198196
/* eslint-disable-next-line no-console */
199-
const infoStub = /** @type {sinon.SinonStub} */ (console.info)
200-
const logObj = JSON.parse(infoStub.firstCall.args[0].replace('DATADOG TRACER CONFIGURATION - ', ''))
201-
infoStub.restore()
197+
const warnStub = /** @type {sinon.SinonStub} */ (console.warn)
198+
const logObj = JSON.parse(warnStub.firstCall.args[0].replace('DATADOG TRACER CONFIGURATION - ', ''))
199+
warnStub.restore()
202200
assert.strictEqual(logObj.profiling_enabled, expected)
203201
})
204202
})

0 commit comments

Comments
 (0)