Skip to content

telemetry: add transmit:false flag for logs, reduce log cardinality #5871

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.

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

Draft
wants to merge 5 commits into
base: master
Choose a base branch
from
Draft
Show file tree
Hide file tree
Changes from all commits
Commits
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
2 changes: 1 addition & 1 deletion packages/dd-trace/src/exporters/agent/writer.js
Original file line number Diff line number Diff line change
Expand Up @@ -42,7 +42,7 @@ class Writer extends BaseWriter {
startupLog({ agentError: err })

if (err) {
log.error('Error sending payload to the agent (status code: %s)', err.status, err)
log.error('Error sending payload to the agent (status code: %s)', err.status, err, log.NO_TELEMETRY)
Copy link
Contributor

Choose a reason for hiding this comment

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

Awesome thanks!

done()
return
}
Expand Down
11 changes: 7 additions & 4 deletions packages/dd-trace/src/exporters/common/request.js
Original file line number Diff line number Diff line change
Expand Up @@ -96,22 +96,25 @@
callback(null, buffer.toString(), res.statusCode)
}
} else {
let errorMessage = ''
let logArgs = [''] // use with log.error(...logArgs), it's a sprintf string with placeholder args

Check failure on line 99 in packages/dd-trace/src/exporters/common/request.js

View workflow job for this annotation

GitHub Actions / lint

'logArgs' is never reassigned. Use 'const' instead
try {
const fullUrl = new URL(
options.path,
options.url || options.hostname || `http://localhost:${options.port}`
).href
errorMessage = `Error from ${fullUrl}: ${res.statusCode} ${http.STATUS_CODES[res.statusCode]}.`
logArgs[0] += 'Error from agent, url=%s, status=%s %s'
logArgs.push(fullUrl, res.statusCode, http.STATUS_CODES[res.statusCode])
} catch {
// ignore error
}
const responseData = buffer.toString()
if (responseData) {
errorMessage += ` Response from the endpoint: "${responseData}"`
logArgs[0] += ', response=%s'
logArgs.push(responseData.substring(0, 100).replaceAll(/[\r\n]/g, ' ')) // can be a 1MB HTML document from an nginx proxy

Check failure on line 113 in packages/dd-trace/src/exporters/common/request.js

View workflow job for this annotation

GitHub Actions / lint

Prefer `String#slice()` over `String#substring()`
}
const error = new Error(errorMessage)
const error = new Error('error from agent. DO NOT PASS TO log.error() INSTEAD USE log.error(...error.logArgs)') // TODO DON'T MERGE THIS

Check failure on line 115 in packages/dd-trace/src/exporters/common/request.js

View workflow job for this annotation

GitHub Actions / lint

This line has a length of 144. Maximum allowed is 120
error.status = res.statusCode
error.logArgs = logArgs

callback(error, null, res.statusCode)
}
Expand Down
8 changes: 7 additions & 1 deletion packages/dd-trace/src/log/index.js
Original file line number Diff line number Diff line change
Expand Up @@ -5,7 +5,7 @@
const { isTrue } = require('../util')
const { traceChannel, debugChannel, infoChannel, warnChannel, errorChannel } = require('./channels')
const logWriter = require('./writer')
const { Log } = require('./log')
const { Log, LogConfig } = require('./log')
const { memoize } = require('./utils')
const { getEnvironmentVariable } = require('../config-helper')

Expand All @@ -15,7 +15,12 @@
logLevel: 'debug'
}

const NO_TRANSMIT = new LogConfig(false)

const log = {
LogConfig,
NO_TRANSMIT,

/**
* @returns Read-only version of logging config. To modify config, call `log.use` and `log.toggle`
*/
Expand Down Expand Up @@ -86,6 +91,7 @@
},

error (...args) {
console.log('log.error', ...args)

Check failure on line 94 in packages/dd-trace/src/log/index.js

View workflow job for this annotation

GitHub Actions / lint

Unexpected console statement
if (errorChannel.hasSubscribers) {
errorChannel.publish(Log.parse(...args))
}
Expand Down
35 changes: 29 additions & 6 deletions packages/dd-trace/src/log/log.js
Original file line number Diff line number Diff line change
Expand Up @@ -3,11 +3,12 @@
const { format } = require('util')

class Log {
constructor (message, args, cause, delegate) {
constructor (message, args, cause, delegate, sendViaTelemetry = true) {
this.message = message
this.args = args
this.cause = cause
this.delegate = delegate
this.sendViaTelemetry = sendViaTelemetry
}

get formatted () {
Expand All @@ -22,10 +23,21 @@ class Log {

static parse (...args) {
let message, cause, delegate
let sendViaTelemetry = true

const lastArg = args.at(-1)
if (lastArg && typeof lastArg === 'object' && lastArg.stack) { // lastArg instanceof Error?
cause = args.pop()
{
const lastArg = args.at(-1)
if (lastArg instanceof LogConfig) {
args.pop()
sendViaTelemetry = lastArg.transmit
}
}

{
const lastArg = args.at(-1)
if (lastArg && typeof lastArg === 'object' && lastArg.stack) { // lastArg instanceof Error?
cause = args.pop()
}
}

const firstArg = args.shift()
Expand All @@ -43,10 +55,21 @@ class Log {
message = String(firstArg)
}

return new Log(message, args, cause, delegate)
return new Log(message, args, cause, delegate, sendViaTelemetry)
}
}

/**
* Pass instances of this class to logger methods when fine-grain control is needed
* @property {boolean} transmit - Whether to send the log via telemetry.
*/
class LogConfig {
constructor (transmit = true) {
this.transmit = transmit
}
}

module.exports = {
Log
Log,
LogConfig
}
2 changes: 1 addition & 1 deletion packages/dd-trace/src/remote_config/manager.js
Original file line number Diff line number Diff line change
Expand Up @@ -153,7 +153,7 @@ class RemoteConfigManager extends EventEmitter {
if (statusCode === 404) return cb()

if (err) {
log.error('[RC] Error in request', err)
log.error('[RC] Error in request', err, log.NO_TELEMETRY)
return cb()
}

Expand Down
3 changes: 2 additions & 1 deletion packages/dd-trace/src/telemetry/logs/log-collector.js
Original file line number Diff line number Diff line change
Expand Up @@ -27,7 +27,8 @@
}

function isValid (logEntry) {
return logEntry?.level && logEntry.message
console.log('isValid', logEntry)

Check failure on line 30 in packages/dd-trace/src/telemetry/logs/log-collector.js

View workflow job for this annotation

GitHub Actions / lint

Unexpected console statement
return logEntry?.level && logEntry.message && logEntry.transmit !== false
Copy link
Collaborator

Choose a reason for hiding this comment

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

Maybe I'm reading the code wrong, but isn't transmit only a property of the LogConfig instance? A Log instance would have sendViaTelemetry set instead, right?

Suggested change
return logEntry?.level && logEntry.message && logEntry.transmit !== false
return logEntry?.level && logEntry.message && logEntry.sendViaTelemetry !== false

}

const EOL = '\n'
Expand Down
3 changes: 2 additions & 1 deletion packages/dd-trace/test/exporters/agent/writer.spec.js
Original file line number Diff line number Diff line change
Expand Up @@ -158,7 +158,8 @@ function describeWriter (protocolVersion) {

setTimeout(() => {
expect(log.error)
.to.have.been.calledWith('Error sending payload to the agent (status code: %s)', error.status, error)
.to.have.been.calledWith('Error sending payload to the agent (status code: %s)',
error.status, error, log.NO_TELEMETRY)
done()
})
})
Expand Down
10 changes: 10 additions & 0 deletions packages/dd-trace/test/log.spec.js
Original file line number Diff line number Diff line change
Expand Up @@ -245,6 +245,16 @@ describe('log', () => {
expect(console.error.secondCall.args[0]).to.be.instanceof(Error)
expect(console.error.secondCall.args[0]).to.have.property('message', 'cause')
})

it('should work with a log config object', () => {
log.error('this is an error', new Error('cause'), log.NO_TELEMETRY)

expect(console.error).to.have.been.called
expect(console.error.firstCall.args[0]).to.be.instanceof(Error)
expect(console.error.firstCall.args[0]).to.have.property('message', 'this is an error')
expect(console.error.secondCall.args[0]).to.be.instanceof(Error)
expect(console.error.secondCall.args[0]).to.have.property('message', 'cause')
})
})

describe('toggle', () => {
Expand Down
6 changes: 6 additions & 0 deletions packages/dd-trace/test/telemetry/logs/log-collector.spec.js
Original file line number Diff line number Diff line change
Expand Up @@ -49,6 +49,12 @@ describe('telemetry log collector', () => {
).to.be.false
})

it('should not store logs with transmit flag set to false', () => {
expect(logCollector.add({ message: 'Error 1', level: 'ERROR' })).to.be.true
expect(logCollector.add({ message: 'Error 2', level: 'ERROR', transmit: true })).to.be.true
expect(logCollector.add({ message: 'Error 3', level: 'ERROR', transmit: false })).to.be.false
Comment on lines +52 to +55
Copy link
Collaborator

Choose a reason for hiding this comment

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

If I'm correct about my question about transmit vs sendViaTelemetry above, this test is not actually testing what you think it is. In that case it would be more robust to not just set the flag manually like you do here, but to at least go through the Log constructor.

})

it('should include original message and dd frames', () => {
const ddFrame = `at T (${ddBasePath}path/to/dd/file.js:1:2)`
const stack = new TypeError('Error 1')
Expand Down
Loading