Skip to content

fix(startup-log): emit immediately after init and send to stderr #7470

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
bm1549 merged 4 commits into from
Feb 10, 2026
Merged

fix(startup-log): emit immediately after init and send to stderr #7470

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
4 commits
Select commit Hold shift + click to select a range
59568e5
fix(startup-log): emit immediately after init and send to stderr
bm1549 Feb 9, 2026
93b78df
fix(tests): update data_streams_enabled tests to use console.error
bm1549 Feb 9, 2026
f833be3
fix(startup-log): separate initialization and agent diagnostic logs
bm1549 Feb 10, 2026
cd4e0ea
fix(startup-log): use warn for both startup log and agent diagnostic
bm1549 Feb 10, 2026
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
8 changes: 5 additions & 3 deletions packages/dd-trace/src/exporters/agent/writer.js
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand All @@ -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)
Expand Down
4 changes: 3 additions & 1 deletion packages/dd-trace/src/proxy.js
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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')
Expand Down Expand Up @@ -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()
Copy link
Copy Markdown
Member

@BridgeAR BridgeAR Feb 10, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This removes the error handling. I am fine with that, while it a) removes information that the customer might want and b) if we remove it, we also have to remove the agentError part. I believe that was actually spected somewhere.

Copy link
Copy Markdown
Contributor Author

@bm1549 bm1549 Feb 10, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Can you elaborate? I had expected that this would just front-load information we were already providing, not remove information

Is there a different place you'd recommend that this go to accomplish both goals?

Copy link
Copy Markdown
Member

@BridgeAR BridgeAR Feb 10, 2026 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

agentError came from the information being passed through to the method when being called https://github.com/DataDog/dd-trace-js/pull/7470/changes#diff-a3fcd7c24d4ec8042528afc821a9e9541c66809f4f79d2371274bef28f955342L34

I would have considered this to be part of the initialization of the tracer (the first payload to the agent is during startup because it checks for the agent to be available or not and what the agent supports. Without that, the tracer might not know how to work).

Thus, I would have expected the former placement to be correct.

Are you certain the agent support is not checked in other tracers during startup for the startup log?

Copy link
Copy Markdown
Contributor Author

@bm1549 bm1549 Feb 10, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is something other tracers have, but it's de-coupled from the initialization. I'll re-work slightly to have two separate log lines as other tracers do

Copy link
Copy Markdown
Member

@BridgeAR BridgeAR Feb 10, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

If we decouple it, we should probably log to stdout, not err (due to not having an error anymore)

Copy link
Copy Markdown
Contributor Author

@bm1549 bm1549 Feb 10, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'll have it as warn instead since that also goes to stderr, but strongly believe it should not go to stdout. Reason being that going to stdout, especially by default, can mess with any tooling that may be processing the logs

For example, imagine someone uses SSI, which instruments everything running Node.js. If they were to run a small Node.js script and depend on the stdout of that script for further processing, this may break their tool

Copy link
Copy Markdown
Contributor Author

@bm1549 bm1549 Feb 10, 2026 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Discussed offline with @BridgeAR

  1. stderr is the convention for diagnostic logs coming from outside of the primary application. We will follow it here
  2. agent error was re-introduced and will be logged separately, in the same conditions as before

Copy link
Copy Markdown
Member

@rochdev rochdev Feb 10, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Isn't this too early? We weren't waiting just for the errors, we were also waiting to give time to the app to load any dependencies it's going to use, otherwise we lose the information about loaded integrations (which is one of the most important aspects of startup logs). Unless I'm misunderstanding the PR, I think this is broken now.

}
}

Expand Down
38 changes: 23 additions & 15 deletions packages/dd-trace/src/startup-log.js
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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}`,
}
}

Expand Down Expand Up @@ -104,6 +111,7 @@ function setSamplingRules (theRules) {

module.exports = {
startupLog,
logAgentError,
setStartupLogConfig,
setStartupLogPluginManager,
setSamplingRules,
Expand Down
46 changes: 22 additions & 24 deletions packages/dd-trace/test/startup-log.spec.js
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -17,14 +17,14 @@ describe('startup logging', () => {
let tracerInfoMethod

before(() => {
sinon.stub(console, 'info')
sinon.stub(console, 'warn')
delete require.cache[require.resolve('../src/startup-log')]
const {
setStartupLogConfig,
setStartupLogPluginManager,
setSamplingRules,
startupLog,
logAgentError,
tracerInfo,
} = require('../src/startup-log')
tracerInfoMethod = tracerInfo
Expand Down Expand Up @@ -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()
})

Expand Down Expand Up @@ -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')
})
})
Expand All @@ -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,
Expand All @@ -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,
Expand All @@ -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,
Expand All @@ -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)
})
})
Expand All @@ -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,
Expand All @@ -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)
})
})
Expand Down
Loading