diff --git a/integration-tests/automatic-log-submission.spec.js b/integration-tests/automatic-log-submission.spec.js new file mode 100644 index 00000000000..eade717dcf1 --- /dev/null +++ b/integration-tests/automatic-log-submission.spec.js @@ -0,0 +1,207 @@ +'use strict' + +const { exec } = require('child_process') + +const { assert } = require('chai') +const getPort = require('get-port') + +const { + createSandbox, + getCiVisAgentlessConfig, + getCiVisEvpProxyConfig +} = require('./helpers') +const { FakeCiVisIntake } = require('./ci-visibility-intake') +const webAppServer = require('./ci-visibility/web-app-server') +const { NODE_MAJOR } = require('../version') + +const cucumberVersion = NODE_MAJOR <= 16 ? '9' : 'latest' + +describe('test visibility automatic log submission', () => { + let sandbox, cwd, receiver, childProcess, webAppPort + let testOutput = '' + + before(async () => { + sandbox = await createSandbox([ + 'mocha', + `@cucumber/cucumber@${cucumberVersion}`, + 'jest', + 'winston', + 'chai@4' + ], true) + cwd = sandbox.folder + webAppPort = await getPort() + webAppServer.listen(webAppPort) + }) + + after(async () => { + await sandbox.remove() + await new Promise(resolve => webAppServer.close(resolve)) + }) + + beforeEach(async function () { + const port = await getPort() + receiver = await new FakeCiVisIntake(port).start() + }) + + afterEach(async () => { + testOutput = '' + childProcess.kill() + await receiver.stop() + }) + + const testFrameworks = [ + { + name: 'mocha', + command: 'mocha ./ci-visibility/automatic-log-submission/automatic-log-submission-test.js' + }, + { + name: 'jest', + command: 'node ./node_modules/jest/bin/jest --config ./ci-visibility/automatic-log-submission/config-jest.js' + }, + { + name: 'cucumber', + command: './node_modules/.bin/cucumber-js ci-visibility/automatic-log-submission-cucumber/*.feature' + } + ] + + testFrameworks.forEach(({ name, command }) => { + context(`with ${name}`, () => { + it('can automatically submit logs', (done) => { + let logIds, testIds + + const logsPromise = receiver + .gatherPayloadsMaxTimeout(({ url }) => url.includes('/api/v2/logs'), payloads => { + payloads.forEach(({ headers }) => { + assert.equal(headers['dd-api-key'], '1') + }) + const logMessages = payloads.flatMap(({ logMessage }) => logMessage) + const [url] = payloads.flatMap(({ url }) => url) + + assert.equal(url, '/api/v2/logs?ddsource=winston&service=my-service') + assert.equal(logMessages.length, 2) + + logMessages.forEach(({ dd, level }) => { + assert.equal(level, 'info') + assert.equal(dd.service, 'my-service') + assert.hasAllKeys(dd, ['trace_id', 'span_id', 'service']) + }) + + assert.includeMembers(logMessages.map(({ message }) => message), [ + 'Hello simple log!', + 'sum function being called' + ]) + + logIds = { + logSpanId: logMessages[0].dd.span_id, + logTraceId: logMessages[0].dd.trace_id + } + }) + + const eventsPromise = receiver + .gatherPayloadsMaxTimeout(({ url }) => url.endsWith('/api/v2/citestcycle'), (payloads) => { + const events = payloads.flatMap(({ payload }) => payload.events) + const testEventContent = events.find(event => event.type === 'test').content + + testIds = { + testSpanId: testEventContent.span_id.toString(), + testTraceId: testEventContent.trace_id.toString() + } + }) + + childProcess = exec(command, + { + cwd, + env: { + ...getCiVisAgentlessConfig(receiver.port), + DD_AGENTLESS_LOG_SUBMISSION_ENABLED: '1', + DD_AGENTLESS_LOG_SUBMISSION_URL: `http://localhost:${receiver.port}`, + DD_API_KEY: '1', + DD_SERVICE: 'my-service' + }, + stdio: 'pipe' + } + ) + childProcess.on('exit', () => { + Promise.all([logsPromise, eventsPromise]).then(() => { + const { logSpanId, logTraceId } = logIds + const { testSpanId, testTraceId } = testIds + assert.include(testOutput, 'Hello simple log!') + assert.include(testOutput, 'sum function being called') + // cucumber has `cucumber.step`, and that's the active span, not the test. + // logs are queried by trace id, so it should be OK + if (name !== 'cucumber') { + assert.include(testOutput, `"span_id":"${testSpanId}"`) + assert.equal(logSpanId, testSpanId) + } + assert.include(testOutput, `"trace_id":"${testTraceId}"`) + assert.equal(logTraceId, testTraceId) + done() + }).catch(done) + }) + + childProcess.stdout.on('data', (chunk) => { + testOutput += chunk.toString() + }) + childProcess.stderr.on('data', (chunk) => { + testOutput += chunk.toString() + }) + }) + + it('does not submit logs when DD_AGENTLESS_LOG_SUBMISSION_ENABLED is not set', (done) => { + childProcess = exec(command, + { + cwd, + env: { + ...getCiVisAgentlessConfig(receiver.port), + DD_AGENTLESS_LOG_SUBMISSION_URL: `http://localhost:${receiver.port}`, + DD_SERVICE: 'my-service' + }, + stdio: 'pipe' + } + ) + childProcess.on('exit', () => { + assert.include(testOutput, 'Hello simple log!') + assert.notInclude(testOutput, 'span_id') + done() + }) + + childProcess.stdout.on('data', (chunk) => { + testOutput += chunk.toString() + }) + childProcess.stderr.on('data', (chunk) => { + testOutput += chunk.toString() + }) + }) + + it('does not submit logs when DD_AGENTLESS_LOG_SUBMISSION_ENABLED is set but DD_API_KEY is not', (done) => { + childProcess = exec(command, + { + cwd, + env: { + ...getCiVisEvpProxyConfig(receiver.port), + DD_AGENTLESS_LOG_SUBMISSION_ENABLED: '1', + DD_AGENTLESS_LOG_SUBMISSION_URL: `http://localhost:${receiver.port}`, + DD_SERVICE: 'my-service', + DD_TRACE_DEBUG: '1', + DD_TRACE_LOG_LEVEL: 'warn', + DD_API_KEY: '' + }, + stdio: 'pipe' + } + ) + childProcess.on('exit', () => { + assert.include(testOutput, 'Hello simple log!') + assert.include(testOutput, 'no automatic log submission will be performed') + done() + }) + + childProcess.stdout.on('data', (chunk) => { + testOutput += chunk.toString() + }) + childProcess.stderr.on('data', (chunk) => { + testOutput += chunk.toString() + }) + }) + }) + }) +}) diff --git a/integration-tests/ci-visibility-intake.js b/integration-tests/ci-visibility-intake.js index 5096efaba42..c133a7a31fe 100644 --- a/integration-tests/ci-visibility-intake.js +++ b/integration-tests/ci-visibility-intake.js @@ -208,6 +208,15 @@ class FakeCiVisIntake extends FakeAgent { }) }) + app.post('/api/v2/logs', express.json(), (req, res) => { + res.status(200).send('OK') + this.emit('message', { + headers: req.headers, + url: req.url, + logMessage: req.body + }) + }) + return new Promise((resolve, reject) => { const timeoutObj = setTimeout(() => { reject(new Error('Intake timed out starting up')) diff --git a/integration-tests/ci-visibility/automatic-log-submission-cucumber/automatic-log-submission.feature b/integration-tests/ci-visibility/automatic-log-submission-cucumber/automatic-log-submission.feature new file mode 100644 index 00000000000..bcce6b75bea --- /dev/null +++ b/integration-tests/ci-visibility/automatic-log-submission-cucumber/automatic-log-submission.feature @@ -0,0 +1,4 @@ +Feature: Automatic Log Submission + Scenario: Run Automatic Log Submission + When we run a test + Then I should have made a log diff --git a/integration-tests/ci-visibility/automatic-log-submission-cucumber/support/logger.js b/integration-tests/ci-visibility/automatic-log-submission-cucumber/support/logger.js new file mode 100644 index 00000000000..5480f1ee574 --- /dev/null +++ b/integration-tests/ci-visibility/automatic-log-submission-cucumber/support/logger.js @@ -0,0 +1,10 @@ +const { createLogger, format, transports } = require('winston') + +module.exports = createLogger({ + level: 'info', + exitOnError: false, + format: format.json(), + transports: [ + new transports.Console() + ] +}) diff --git a/integration-tests/ci-visibility/automatic-log-submission-cucumber/support/steps.js b/integration-tests/ci-visibility/automatic-log-submission-cucumber/support/steps.js new file mode 100644 index 00000000000..2d1bdb4e906 --- /dev/null +++ b/integration-tests/ci-visibility/automatic-log-submission-cucumber/support/steps.js @@ -0,0 +1,14 @@ +const { expect } = require('chai') +const { When, Then } = require('@cucumber/cucumber') + +const logger = require('./logger') +const sum = require('./sum') + +Then('I should have made a log', async function () { + expect(true).to.equal(true) + expect(sum(1, 2)).to.equal(3) +}) + +When('we run a test', async function () { + logger.log('info', 'Hello simple log!') +}) diff --git a/integration-tests/ci-visibility/automatic-log-submission-cucumber/support/sum.js b/integration-tests/ci-visibility/automatic-log-submission-cucumber/support/sum.js new file mode 100644 index 00000000000..cce61142972 --- /dev/null +++ b/integration-tests/ci-visibility/automatic-log-submission-cucumber/support/sum.js @@ -0,0 +1,6 @@ +const logger = require('./logger') + +module.exports = function (a, b) { + logger.log('info', 'sum function being called') + return a + b +} diff --git a/integration-tests/ci-visibility/automatic-log-submission/automatic-log-submission-test.js b/integration-tests/ci-visibility/automatic-log-submission/automatic-log-submission-test.js new file mode 100644 index 00000000000..cfc60b8d3b0 --- /dev/null +++ b/integration-tests/ci-visibility/automatic-log-submission/automatic-log-submission-test.js @@ -0,0 +1,13 @@ +const { expect } = require('chai') + +const logger = require('./logger') +const sum = require('./sum') + +describe('test', () => { + it('should return true', () => { + logger.log('info', 'Hello simple log!') + + expect(true).to.be.true + expect(sum(1, 2)).to.equal(3) + }) +}) diff --git a/integration-tests/ci-visibility/automatic-log-submission/config-jest.js b/integration-tests/ci-visibility/automatic-log-submission/config-jest.js new file mode 100644 index 00000000000..56afa0d36db --- /dev/null +++ b/integration-tests/ci-visibility/automatic-log-submission/config-jest.js @@ -0,0 +1,8 @@ +module.exports = { + projects: [], + testPathIgnorePatterns: ['/node_modules/'], + cache: false, + testMatch: [ + '**/ci-visibility/automatic-log-submission/automatic-log-submission-*' + ] +} diff --git a/integration-tests/ci-visibility/automatic-log-submission/logger.js b/integration-tests/ci-visibility/automatic-log-submission/logger.js new file mode 100644 index 00000000000..5480f1ee574 --- /dev/null +++ b/integration-tests/ci-visibility/automatic-log-submission/logger.js @@ -0,0 +1,10 @@ +const { createLogger, format, transports } = require('winston') + +module.exports = createLogger({ + level: 'info', + exitOnError: false, + format: format.json(), + transports: [ + new transports.Console() + ] +}) diff --git a/integration-tests/ci-visibility/automatic-log-submission/sum.js b/integration-tests/ci-visibility/automatic-log-submission/sum.js new file mode 100644 index 00000000000..cce61142972 --- /dev/null +++ b/integration-tests/ci-visibility/automatic-log-submission/sum.js @@ -0,0 +1,6 @@ +const logger = require('./logger') + +module.exports = function (a, b) { + logger.log('info', 'sum function being called') + return a + b +} diff --git a/integration-tests/selenium/selenium.spec.js b/integration-tests/selenium/selenium.spec.js index a95acb6aaa2..50fc9d19568 100644 --- a/integration-tests/selenium/selenium.spec.js +++ b/integration-tests/selenium/selenium.spec.js @@ -18,7 +18,7 @@ const { } = require('../../packages/dd-trace/src/plugins/util/test') const { NODE_MAJOR } = require('../../version') -const cucumberVersion = NODE_MAJOR <= 16 ? '9' : '10' +const cucumberVersion = NODE_MAJOR <= 16 ? '9' : 'latest' const webAppServer = require('../ci-visibility/web-app-server') diff --git a/packages/datadog-instrumentations/src/jest.js b/packages/datadog-instrumentations/src/jest.js index e2baf3f9d42..e006f311dc3 100644 --- a/packages/datadog-instrumentations/src/jest.js +++ b/packages/datadog-instrumentations/src/jest.js @@ -850,7 +850,8 @@ addHook({ }, jestConfigSyncWrapper) const LIBRARIES_BYPASSING_JEST_REQUIRE_ENGINE = [ - 'selenium-webdriver' + 'selenium-webdriver', + 'winston' ] function shouldBypassJestRequireEngine (moduleName) { diff --git a/packages/datadog-instrumentations/src/winston.js b/packages/datadog-instrumentations/src/winston.js index dbd91026bf2..9b9c4e811aa 100644 --- a/packages/datadog-instrumentations/src/winston.js +++ b/packages/datadog-instrumentations/src/winston.js @@ -8,6 +8,18 @@ const shimmer = require('../../datadog-shimmer') const patched = new WeakSet() +// Test Visibility log submission channels +const configureCh = channel('ci:log-submission:winston:configure') +const addTransport = channel('ci:log-submission:winston:add-transport') + +addHook({ name: 'winston', file: 'lib/winston/transports/index.js', versions: ['>=3'] }, transportsPackage => { + if (configureCh.hasSubscribers) { + configureCh.publish(transportsPackage.Http) + } + + return transportsPackage +}) + addHook({ name: 'winston', file: 'lib/winston/logger.js', versions: ['>=3'] }, Logger => { const logCh = channel('apm:winston:log') shimmer.wrap(Logger.prototype, 'write', write => { @@ -20,6 +32,16 @@ addHook({ name: 'winston', file: 'lib/winston/logger.js', versions: ['>=3'] }, L return write.apply(this, arguments) } }) + + shimmer.wrap(Logger.prototype, 'configure', configure => function () { + const configureResponse = configure.apply(this, arguments) + // After the original `configure`, because it resets transports + if (addTransport.hasSubscribers) { + addTransport.publish(this) + } + return configureResponse + }) + return Logger }) diff --git a/packages/dd-trace/src/ci-visibility/log-submission/log-submission-plugin.js b/packages/dd-trace/src/ci-visibility/log-submission/log-submission-plugin.js new file mode 100644 index 00000000000..aa437f4cd87 --- /dev/null +++ b/packages/dd-trace/src/ci-visibility/log-submission/log-submission-plugin.js @@ -0,0 +1,53 @@ +const Plugin = require('../../plugins/plugin') +const log = require('../../log') + +function getWinstonLogSubmissionParameters (config) { + const { site, service } = config + + const defaultParameters = { + host: `http-intake.logs.${site}`, + path: `/api/v2/logs?ddsource=winston&service=${service}`, + ssl: true, + headers: { + 'DD-API-KEY': process.env.DD_API_KEY + } + } + + if (!process.env.DD_AGENTLESS_LOG_SUBMISSION_URL) { + return defaultParameters + } + + try { + const url = new URL(process.env.DD_AGENTLESS_LOG_SUBMISSION_URL) + return { + host: url.hostname, + port: url.port, + ssl: url.protocol === 'https:', + path: defaultParameters.path, + headers: defaultParameters.headers + } + } catch (e) { + log.error('Could not parse DD_AGENTLESS_LOG_SUBMISSION_URL') + return defaultParameters + } +} + +class LogSubmissionPlugin extends Plugin { + static get id () { + return 'log-submission' + } + + constructor (...args) { + super(...args) + + this.addSub('ci:log-submission:winston:configure', (httpClass) => { + this.HttpClass = httpClass + }) + + this.addSub('ci:log-submission:winston:add-transport', (logger) => { + logger.add(new this.HttpClass(getWinstonLogSubmissionParameters(this.config))) + }) + } +} + +module.exports = LogSubmissionPlugin diff --git a/packages/dd-trace/src/config.js b/packages/dd-trace/src/config.js index dc5bb524d1a..69005edd369 100644 --- a/packages/dd-trace/src/config.js +++ b/packages/dd-trace/src/config.js @@ -498,6 +498,7 @@ class Config { this._setValue(defaults, 'isIntelligentTestRunnerEnabled', false) this._setValue(defaults, 'isManualApiEnabled', false) this._setValue(defaults, 'ciVisibilityTestSessionName', '') + this._setValue(defaults, 'ciVisAgentlessLogSubmissionEnabled', false) this._setValue(defaults, 'logInjection', false) this._setValue(defaults, 'lookup', undefined) this._setValue(defaults, 'memcachedCommandEnabled', false) @@ -1035,7 +1036,8 @@ class Config { DD_CIVISIBILITY_EARLY_FLAKE_DETECTION_ENABLED, DD_CIVISIBILITY_FLAKY_RETRY_ENABLED, DD_CIVISIBILITY_FLAKY_RETRY_COUNT, - DD_TEST_SESSION_NAME + DD_TEST_SESSION_NAME, + DD_AGENTLESS_LOG_SUBMISSION_ENABLED } = process.env if (DD_CIVISIBILITY_AGENTLESS_URL) { @@ -1052,6 +1054,7 @@ class Config { this._setBoolean(calc, 'isIntelligentTestRunnerEnabled', isTrue(this._isCiVisibilityItrEnabled())) this._setBoolean(calc, 'isManualApiEnabled', !isFalse(this._isCiVisibilityManualApiEnabled())) this._setString(calc, 'ciVisibilityTestSessionName', DD_TEST_SESSION_NAME) + this._setBoolean(calc, 'ciVisAgentlessLogSubmissionEnabled', isTrue(DD_AGENTLESS_LOG_SUBMISSION_ENABLED)) } this._setString(calc, 'dogstatsd.hostname', this._getHostname()) this._setBoolean(calc, 'isGitUploadEnabled', diff --git a/packages/dd-trace/src/plugin_manager.js b/packages/dd-trace/src/plugin_manager.js index 80e87ce545e..e9daea9b60b 100644 --- a/packages/dd-trace/src/plugin_manager.js +++ b/packages/dd-trace/src/plugin_manager.js @@ -137,7 +137,8 @@ module.exports = class PluginManager { dsmEnabled, clientIpEnabled, memcachedCommandEnabled, - ciVisibilityTestSessionName + ciVisibilityTestSessionName, + ciVisAgentlessLogSubmissionEnabled } = this._tracerConfig const sharedConfig = { @@ -147,7 +148,8 @@ module.exports = class PluginManager { site, url, headers: headerTags || [], - ciVisibilityTestSessionName + ciVisibilityTestSessionName, + ciVisAgentlessLogSubmissionEnabled } if (logInjection !== undefined) { diff --git a/packages/dd-trace/src/plugins/ci_plugin.js b/packages/dd-trace/src/plugins/ci_plugin.js index b86d20d5760..d4c9f32bc68 100644 --- a/packages/dd-trace/src/plugins/ci_plugin.js +++ b/packages/dd-trace/src/plugins/ci_plugin.js @@ -100,7 +100,9 @@ module.exports = class CiPlugin extends Plugin { ...testSessionSpanMetadata } }) + // TODO: add telemetry tag when we can add `is_agentless_log_submission_enabled` for agentless log submission this.telemetry.ciVisEvent(TELEMETRY_EVENT_CREATED, 'session') + this.testModuleSpan = this.tracer.startSpan(`${this.constructor.id}.test_module`, { childOf: this.testSessionSpan, tags: { diff --git a/packages/dd-trace/src/plugins/log_plugin.js b/packages/dd-trace/src/plugins/log_plugin.js index 353008a9e02..b0812ea46d3 100644 --- a/packages/dd-trace/src/plugins/log_plugin.js +++ b/packages/dd-trace/src/plugins/log_plugin.js @@ -54,7 +54,7 @@ module.exports = class LogPlugin extends Plugin { configure (config) { return super.configure({ ...config, - enabled: config.enabled && config.logInjection + enabled: config.enabled && (config.logInjection || config.ciVisAgentlessLogSubmissionEnabled) }) } } diff --git a/packages/dd-trace/src/proxy.js b/packages/dd-trace/src/proxy.js index d7ce0538f39..b8916b205d4 100644 --- a/packages/dd-trace/src/proxy.js +++ b/packages/dd-trace/src/proxy.js @@ -162,6 +162,18 @@ class Tracer extends NoopProxy { this._testApiManualPlugin.configure({ ...config, enabled: true }) } } + if (config.ciVisAgentlessLogSubmissionEnabled) { + if (process.env.DD_API_KEY) { + const LogSubmissionPlugin = require('./ci-visibility/log-submission/log-submission-plugin') + const automaticLogPlugin = new LogSubmissionPlugin(this) + automaticLogPlugin.configure({ ...config, enabled: true }) + } else { + log.warn( + 'DD_AGENTLESS_LOG_SUBMISSION_ENABLED is set, ' + + 'but DD_API_KEY is undefined, so no automatic log submission will be performed.' + ) + } + } } catch (e) { log.error(e) }