From 3296eb8e18908846c6cf53e1ac23f98ee808fa9d Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Juan=20Antonio=20Fern=C3=A1ndez=20de=20Alba?= Date: Tue, 3 Dec 2024 10:26:01 +0100 Subject: [PATCH] [test optimization] Add dynamic instrumentation support for cucumber (#4956) --- integration-tests/ci-visibility-intake.js | 7 +- .../features-di/support/steps.js | 24 +++ .../ci-visibility/features-di/support/sum.js | 10 + .../features-di/test-hit-breakpoint.feature | 6 + .../test-not-hit-breakpoint.feature | 6 + integration-tests/cucumber/cucumber.spec.js | 194 +++++++++++++++++- .../datadog-instrumentations/src/cucumber.js | 32 ++- packages/datadog-plugin-cucumber/src/index.js | 43 +++- 8 files changed, 311 insertions(+), 11 deletions(-) create mode 100644 integration-tests/ci-visibility/features-di/support/steps.js create mode 100644 integration-tests/ci-visibility/features-di/support/sum.js create mode 100644 integration-tests/ci-visibility/features-di/test-hit-breakpoint.feature create mode 100644 integration-tests/ci-visibility/features-di/test-not-hit-breakpoint.feature diff --git a/integration-tests/ci-visibility-intake.js b/integration-tests/ci-visibility-intake.js index c133a7a31fe..f08f1a24ecd 100644 --- a/integration-tests/ci-visibility-intake.js +++ b/integration-tests/ci-visibility-intake.js @@ -25,7 +25,7 @@ const DEFAULT_SUITES_TO_SKIP = [] const DEFAULT_GIT_UPLOAD_STATUS = 200 const DEFAULT_KNOWN_TESTS_UPLOAD_STATUS = 200 const DEFAULT_INFO_RESPONSE = { - endpoints: ['/evp_proxy/v2'] + endpoints: ['/evp_proxy/v2', '/debugger/v1/input'] } const DEFAULT_CORRELATION_ID = '1234' const DEFAULT_KNOWN_TESTS = ['test-suite1.js.test-name1', 'test-suite2.js.test-name2'] @@ -208,7 +208,10 @@ class FakeCiVisIntake extends FakeAgent { }) }) - app.post('/api/v2/logs', express.json(), (req, res) => { + app.post([ + '/api/v2/logs', + '/debugger/v1/input' + ], express.json(), (req, res) => { res.status(200).send('OK') this.emit('message', { headers: req.headers, diff --git a/integration-tests/ci-visibility/features-di/support/steps.js b/integration-tests/ci-visibility/features-di/support/steps.js new file mode 100644 index 00000000000..00880f83467 --- /dev/null +++ b/integration-tests/ci-visibility/features-di/support/steps.js @@ -0,0 +1,24 @@ +const assert = require('assert') +const { When, Then } = require('@cucumber/cucumber') +const sum = require('./sum') + +let count = 0 + +When('the greeter says hello', function () { + this.whatIHeard = 'hello' +}) + +Then('I should have heard {string}', function (expectedResponse) { + sum(11, 3) + assert.equal(this.whatIHeard, expectedResponse) +}) + +Then('I should have flakily heard {string}', function (expectedResponse) { + const shouldFail = count++ < 1 + if (shouldFail) { + sum(11, 3) + } else { + sum(1, 3) // does not hit the breakpoint the second time + } + assert.equal(this.whatIHeard, expectedResponse) +}) diff --git a/integration-tests/ci-visibility/features-di/support/sum.js b/integration-tests/ci-visibility/features-di/support/sum.js new file mode 100644 index 00000000000..cb1d7adb951 --- /dev/null +++ b/integration-tests/ci-visibility/features-di/support/sum.js @@ -0,0 +1,10 @@ +function funSum (a, b) { + const localVariable = 2 + if (a > 10) { + throw new Error('the number is too big') + } + + return a + b + localVariable +} + +module.exports = funSum diff --git a/integration-tests/ci-visibility/features-di/test-hit-breakpoint.feature b/integration-tests/ci-visibility/features-di/test-hit-breakpoint.feature new file mode 100644 index 00000000000..06ef560af61 --- /dev/null +++ b/integration-tests/ci-visibility/features-di/test-hit-breakpoint.feature @@ -0,0 +1,6 @@ + +Feature: Greeting + + Scenario: Say hello + When the greeter says hello + Then I should have heard "hello" diff --git a/integration-tests/ci-visibility/features-di/test-not-hit-breakpoint.feature b/integration-tests/ci-visibility/features-di/test-not-hit-breakpoint.feature new file mode 100644 index 00000000000..ca5562b55c0 --- /dev/null +++ b/integration-tests/ci-visibility/features-di/test-not-hit-breakpoint.feature @@ -0,0 +1,6 @@ + +Feature: Greeting + + Scenario: Say hello + When the greeter says hello + Then I should have flakily heard "hello" diff --git a/integration-tests/cucumber/cucumber.spec.js b/integration-tests/cucumber/cucumber.spec.js index d7fd132caf7..8f21b3a688f 100644 --- a/integration-tests/cucumber/cucumber.spec.js +++ b/integration-tests/cucumber/cucumber.spec.js @@ -37,7 +37,11 @@ const { TEST_SUITE, TEST_CODE_OWNERS, TEST_SESSION_NAME, - TEST_LEVEL_EVENT_TYPES + TEST_LEVEL_EVENT_TYPES, + DI_ERROR_DEBUG_INFO_CAPTURED, + DI_DEBUG_ERROR_FILE, + DI_DEBUG_ERROR_SNAPSHOT_ID, + DI_DEBUG_ERROR_LINE } = require('../../packages/dd-trace/src/plugins/util/test') const { DD_HOST_CPU_COUNT } = require('../../packages/dd-trace/src/plugins/util/env') @@ -86,10 +90,11 @@ versions.forEach(version => { reportMethods.forEach((reportMethod) => { context(`reporting via ${reportMethod}`, () => { - let envVars, isAgentless + let envVars, isAgentless, logsEndpoint beforeEach(() => { isAgentless = reportMethod === 'agentless' envVars = isAgentless ? getCiVisAgentlessConfig(receiver.port) : getCiVisEvpProxyConfig(receiver.port) + logsEndpoint = isAgentless ? '/api/v2/logs' : '/debugger/v1/input' }) const runModes = ['serial'] @@ -1536,6 +1541,191 @@ versions.forEach(version => { }) }) }) + // Dynamic instrumentation only supported from >=8.0.0 + context('dynamic instrumentation', () => { + it('does not activate if DD_TEST_DYNAMIC_INSTRUMENTATION_ENABLED is not set', (done) => { + const eventsPromise = receiver + .gatherPayloadsMaxTimeout(({ url }) => url.endsWith('/api/v2/citestcycle'), (payloads) => { + const events = payloads.flatMap(({ payload }) => payload.events) + + const tests = events.filter(event => event.type === 'test').map(event => event.content) + const retriedTests = tests.filter(test => test.meta[TEST_IS_RETRY] === 'true') + + assert.equal(retriedTests.length, 1) + const [retriedTest] = retriedTests + + assert.notProperty(retriedTest.meta, DI_ERROR_DEBUG_INFO_CAPTURED) + assert.notProperty(retriedTest.meta, DI_DEBUG_ERROR_FILE) + assert.notProperty(retriedTest.metrics, DI_DEBUG_ERROR_LINE) + assert.notProperty(retriedTest.meta, DI_DEBUG_ERROR_SNAPSHOT_ID) + }) + const logsPromise = receiver + .gatherPayloadsMaxTimeout(({ url }) => url === logsEndpoint, (payloads) => { + if (payloads.length > 0) { + throw new Error('Unexpected logs') + } + }, 5000) + + childProcess = exec( + './node_modules/.bin/cucumber-js ci-visibility/features-di/test-hit-breakpoint.feature --retry 1', + { + cwd, + env: envVars, + stdio: 'pipe' + } + ) + + childProcess.on('exit', () => { + Promise.all([eventsPromise, logsPromise]).then(() => { + done() + }).catch(done) + }) + }) + + it('runs retries with dynamic instrumentation', (done) => { + receiver.setSettings({ + itr_enabled: false, + code_coverage: false, + tests_skipping: false, + early_flake_detection: { + enabled: false + }, + flaky_test_retries_enabled: false + }) + let snapshotIdByTest, snapshotIdByLog + let spanIdByTest, spanIdByLog, traceIdByTest, traceIdByLog + + const eventsPromise = receiver + .gatherPayloadsMaxTimeout(({ url }) => url.endsWith('/api/v2/citestcycle'), payloads => { + const events = payloads.flatMap(({ payload }) => payload.events) + + const tests = events.filter(event => event.type === 'test').map(event => event.content) + + const retriedTests = tests.filter(test => test.meta[TEST_IS_RETRY] === 'true') + + assert.equal(retriedTests.length, 1) + const [retriedTest] = retriedTests + + assert.propertyVal(retriedTest.meta, DI_ERROR_DEBUG_INFO_CAPTURED, 'true') + assert.propertyVal( + retriedTest.meta, + DI_DEBUG_ERROR_FILE, + 'ci-visibility/features-di/support/sum.js' + ) + assert.equal(retriedTest.metrics[DI_DEBUG_ERROR_LINE], 4) + assert.exists(retriedTest.meta[DI_DEBUG_ERROR_SNAPSHOT_ID]) + + snapshotIdByTest = retriedTest.meta[DI_DEBUG_ERROR_SNAPSHOT_ID] + spanIdByTest = retriedTest.span_id.toString() + traceIdByTest = retriedTest.trace_id.toString() + }) + + const logsPromise = receiver + .gatherPayloadsMaxTimeout(({ url }) => url === logsEndpoint, (payloads) => { + const [{ logMessage: [diLog] }] = payloads + assert.deepInclude(diLog, { + ddsource: 'dd_debugger', + level: 'error' + }) + assert.equal(diLog.debugger.snapshot.language, 'javascript') + assert.deepInclude(diLog.debugger.snapshot.captures.lines['4'].locals, { + a: { + type: 'number', + value: '11' + }, + b: { + type: 'number', + value: '3' + }, + localVariable: { + type: 'number', + value: '2' + } + }) + spanIdByLog = diLog.dd.span_id + traceIdByLog = diLog.dd.trace_id + snapshotIdByLog = diLog.debugger.snapshot.id + }) + + childProcess = exec( + './node_modules/.bin/cucumber-js ci-visibility/features-di/test-hit-breakpoint.feature --retry 1', + { + cwd, + env: { + ...envVars, + DD_TEST_DYNAMIC_INSTRUMENTATION_ENABLED: 'true' + }, + stdio: 'pipe' + } + ) + + childProcess.on('exit', () => { + Promise.all([eventsPromise, logsPromise]).then(() => { + assert.equal(snapshotIdByTest, snapshotIdByLog) + assert.equal(spanIdByTest, spanIdByLog) + assert.equal(traceIdByTest, traceIdByLog) + done() + }).catch(done) + }) + }) + + it('does not crash if the retry does not hit the breakpoint', (done) => { + receiver.setSettings({ + itr_enabled: false, + code_coverage: false, + tests_skipping: false, + early_flake_detection: { + enabled: false + }, + flaky_test_retries_enabled: false + }) + + const eventsPromise = receiver + .gatherPayloadsMaxTimeout(({ url }) => url.endsWith('/api/v2/citestcycle'), (payloads) => { + const events = payloads.flatMap(({ payload }) => payload.events) + + const tests = events.filter(event => event.type === 'test').map(event => event.content) + const retriedTests = tests.filter(test => test.meta[TEST_IS_RETRY] === 'true') + + assert.equal(retriedTests.length, 1) + const [retriedTest] = retriedTests + + assert.propertyVal(retriedTest.meta, DI_ERROR_DEBUG_INFO_CAPTURED, 'true') + assert.propertyVal( + retriedTest.meta, + DI_DEBUG_ERROR_FILE, + 'ci-visibility/features-di/support/sum.js' + ) + assert.equal(retriedTest.metrics[DI_DEBUG_ERROR_LINE], 4) + assert.exists(retriedTest.meta[DI_DEBUG_ERROR_SNAPSHOT_ID]) + }) + const logsPromise = receiver + .gatherPayloadsMaxTimeout(({ url }) => url.endsWith('/api/v2/logs'), (payloads) => { + if (payloads.length > 0) { + throw new Error('Unexpected logs') + } + }, 5000) + + childProcess = exec( + './node_modules/.bin/cucumber-js ci-visibility/features-di/test-not-hit-breakpoint.feature --retry 1', + { + cwd, + env: { + ...envVars, + DD_TEST_DYNAMIC_INSTRUMENTATION_ENABLED: 'true' + }, + stdio: 'pipe' + } + ) + + childProcess.on('exit', (exitCode) => { + Promise.all([eventsPromise, logsPromise]).then(() => { + assert.equal(exitCode, 0) + done() + }).catch(done) + }) + }) + }) } }) }) diff --git a/packages/datadog-instrumentations/src/cucumber.js b/packages/datadog-instrumentations/src/cucumber.js index 0f84d717381..7b9a2db5a02 100644 --- a/packages/datadog-instrumentations/src/cucumber.js +++ b/packages/datadog-instrumentations/src/cucumber.js @@ -126,6 +126,20 @@ function getTestStatusFromRetries (testStatuses) { return 'pass' } +function getErrorFromCucumberResult (cucumberResult) { + if (!cucumberResult.message) { + return + } + + const [message] = cucumberResult.message.split('\n') + const error = new Error(message) + if (cucumberResult.exception) { + error.type = cucumberResult.exception.type + } + error.stack = cucumberResult.message + return error +} + function getChannelPromise (channelToPublishTo) { return new Promise(resolve => { sessionAsyncResource.runInAsyncScope(() => { @@ -230,9 +244,19 @@ function wrapRun (pl, isLatestVersion) { if (testCase?.testCaseFinished) { const { testCaseFinished: { willBeRetried } } = testCase if (willBeRetried) { // test case failed and will be retried + let error + try { + const cucumberResult = this.getWorstStepResult() + error = getErrorFromCucumberResult(cucumberResult) + } catch (e) { + // ignore error + } + const failedAttemptAsyncResource = numAttemptToAsyncResource.get(numAttempt) + const isRetry = numAttempt++ > 0 failedAttemptAsyncResource.runInAsyncScope(() => { - testRetryCh.publish(numAttempt++ > 0) // the current span will be finished and a new one will be created + // the current span will be finished and a new one will be created + testRetryCh.publish({ isRetry, error }) }) const newAsyncResource = new AsyncResource('bound-anonymous-fn') @@ -251,7 +275,7 @@ function wrapRun (pl, isLatestVersion) { }) promise.finally(() => { const result = this.getWorstStepResult() - const { status, skipReason, errorMessage } = isLatestVersion + const { status, skipReason } = isLatestVersion ? getStatusFromResultLatest(result) : getStatusFromResult(result) @@ -270,8 +294,10 @@ function wrapRun (pl, isLatestVersion) { } const attemptAsyncResource = numAttemptToAsyncResource.get(numAttempt) + const error = getErrorFromCucumberResult(result) + attemptAsyncResource.runInAsyncScope(() => { - testFinishCh.publish({ status, skipReason, errorMessage, isNew, isEfdRetry, isFlakyRetry: numAttempt > 0 }) + testFinishCh.publish({ status, skipReason, error, isNew, isEfdRetry, isFlakyRetry: numAttempt > 0 }) }) }) return promise diff --git a/packages/datadog-plugin-cucumber/src/index.js b/packages/datadog-plugin-cucumber/src/index.js index d24f97c33e6..e674131d639 100644 --- a/packages/datadog-plugin-cucumber/src/index.js +++ b/packages/datadog-plugin-cucumber/src/index.js @@ -26,7 +26,12 @@ const { TEST_MODULE, TEST_MODULE_ID, TEST_SUITE, - CUCUMBER_IS_PARALLEL + CUCUMBER_IS_PARALLEL, + TEST_NAME, + DI_ERROR_DEBUG_INFO_CAPTURED, + DI_DEBUG_ERROR_SNAPSHOT_ID, + DI_DEBUG_ERROR_FILE, + DI_DEBUG_ERROR_LINE } = require('../../dd-trace/src/plugins/util/test') const { RESOURCE_NAME } = require('../../../ext/tags') const { COMPONENT, ERROR_MESSAGE } = require('../../dd-trace/src/constants') @@ -46,6 +51,7 @@ const { const id = require('../../dd-trace/src/id') const isCucumberWorker = !!process.env.CUCUMBER_WORKER_ID +const debuggerParameterPerTest = new Map() function getTestSuiteTags (testSuiteSpan) { const suiteTags = { @@ -220,14 +226,40 @@ class CucumberPlugin extends CiPlugin { const testSpan = this.startTestSpan(testName, testSuite, extraTags) this.enter(testSpan, store) + + const debuggerParameters = debuggerParameterPerTest.get(testName) + + if (debuggerParameters) { + const spanContext = testSpan.context() + + // TODO: handle race conditions with this.retriedTestIds + this.retriedTestIds = { + spanId: spanContext.toSpanId(), + traceId: spanContext.toTraceId() + } + const { snapshotId, file, line } = debuggerParameters + + // TODO: should these be added on test:end if and only if the probe is hit? + // Sync issues: `hitProbePromise` might be resolved after the test ends + testSpan.setTag(DI_ERROR_DEBUG_INFO_CAPTURED, 'true') + testSpan.setTag(DI_DEBUG_ERROR_SNAPSHOT_ID, snapshotId) + testSpan.setTag(DI_DEBUG_ERROR_FILE, file) + testSpan.setTag(DI_DEBUG_ERROR_LINE, line) + } }) - this.addSub('ci:cucumber:test:retry', (isFlakyRetry) => { + this.addSub('ci:cucumber:test:retry', ({ isRetry, error }) => { const store = storage.getStore() const span = store.span - if (isFlakyRetry) { + if (isRetry) { span.setTag(TEST_IS_RETRY, 'true') } + span.setTag('error', error) + if (this.di && error) { + const testName = span.context()._tags[TEST_NAME] + const debuggerParameters = this.addDiProbe(error) + debuggerParameterPerTest.set(testName, debuggerParameters) + } span.setTag(TEST_STATUS, 'fail') span.finish() finishAllTraceSpans(span) @@ -281,6 +313,7 @@ class CucumberPlugin extends CiPlugin { isStep, status, skipReason, + error, errorMessage, isNew, isEfdRetry, @@ -302,7 +335,9 @@ class CucumberPlugin extends CiPlugin { span.setTag(TEST_SKIP_REASON, skipReason) } - if (errorMessage) { + if (error) { + span.setTag('error', error) + } else if (errorMessage) { // we can't get a full error in cucumber steps span.setTag(ERROR_MESSAGE, errorMessage) }