diff --git a/.github/workflows/integration_tests_local.yml b/.github/workflows/integration_tests_local.yml index 3eb84561..9e0b2bfc 100644 --- a/.github/workflows/integration_tests_local.yml +++ b/.github/workflows/integration_tests_local.yml @@ -59,8 +59,8 @@ jobs: with: node-version: ${{ matrix.node_version }} - - name: Test timeout trace assertions - run: node --test integration_tests_local/check-timeout-logs.test.js + - name: Test structural trace assertions + run: node --test integration_tests_local/check-*.test.js - name: Run local container integration tests (nodejs${{ matrix.node_major }}.x, ${{ matrix.architecture }}) run: PLATFORM=${{ matrix.platform }} RUNTIME_PARAM=${{ matrix.node_major }} ./integration_tests_local/run.sh diff --git a/.gitignore b/.gitignore index 449c8ae5..ab300bf9 100644 --- a/.gitignore +++ b/.gitignore @@ -20,3 +20,4 @@ integration_tests/container/*/datadog-lambda-js-local.tgz # Local integration test harness binaries integration_tests_local/bin/ +integration_tests/container/layer/cold_start_fixture/ diff --git a/integration_tests/container/cjs/Dockerfile b/integration_tests/container/cjs/Dockerfile index fd9f9389..edbf61bd 100644 --- a/integration_tests/container/cjs/Dockerfile +++ b/integration_tests/container/cjs/Dockerfile @@ -10,6 +10,9 @@ ARG DD_TRACE_VERSION # AWS suite (throw-error, status-code-500s, send-metrics, process-input, # http-requests) plus extractor.js for the DD_TRACE_EXTRACTOR case. COPY package.json *.js ${LAMBDA_TASK_ROOT}/ +# Known real module loads at each path class; no runtime implementation is overwritten. +COPY cold-start-probe.js /opt/cold-start-probe.js +COPY cold-start-probe.js /var/runtime/cold-start-probe.js COPY datadog-lambda-js-local.tgz /tmp/datadog-lambda-js-local.tgz RUN cd ${LAMBDA_TASK_ROOT} \ && test -n "$DD_TRACE_VERSION" \ diff --git a/integration_tests/container/cjs/cold-start-parent.js b/integration_tests/container/cjs/cold-start-parent.js new file mode 100644 index 00000000..640e04b9 --- /dev/null +++ b/integration_tests/container/cjs/cold-start-parent.js @@ -0,0 +1,3 @@ +require("./cold-start-probe"); +require("./cold-start-skip"); +process.stdout.write(JSON.stringify({ coldStartFixture: __filename }) + "\n"); diff --git a/integration_tests/container/cjs/cold-start-probe.js b/integration_tests/container/cjs/cold-start-probe.js new file mode 100644 index 00000000..25f9e8ab --- /dev/null +++ b/integration_tests/container/cjs/cold-start-probe.js @@ -0,0 +1,4 @@ +// Deliberate fixture-only load cost, well above the 10ms tracing threshold. +// No busy loop or machine-speed-dependent module count. +Atomics.wait(new Int32Array(new SharedArrayBuffer(4)), 0, 0, 50); +process.stdout.write(JSON.stringify({ coldStartFixture: __filename }) + "\n"); diff --git a/integration_tests/container/cjs/cold-start-skip.js b/integration_tests/container/cjs/cold-start-skip.js new file mode 100644 index 00000000..a42c6d29 --- /dev/null +++ b/integration_tests/container/cjs/cold-start-skip.js @@ -0,0 +1,2 @@ +require("./cold-start-skipped-child"); +process.stdout.write(JSON.stringify({ coldStartFixture: __filename }) + "\n"); diff --git a/integration_tests/container/cjs/cold-start-skipped-child.js b/integration_tests/container/cjs/cold-start-skipped-child.js new file mode 100644 index 00000000..4268a983 --- /dev/null +++ b/integration_tests/container/cjs/cold-start-skipped-child.js @@ -0,0 +1,2 @@ +Atomics.wait(new Int32Array(new SharedArrayBuffer(4)), 0, 0, 50); +process.stdout.write(JSON.stringify({ coldStartFixture: __filename }) + "\n"); diff --git a/integration_tests/container/cjs/cold-start-warm.js b/integration_tests/container/cjs/cold-start-warm.js new file mode 100644 index 00000000..4268a983 --- /dev/null +++ b/integration_tests/container/cjs/cold-start-warm.js @@ -0,0 +1,2 @@ +Atomics.wait(new Int32Array(new SharedArrayBuffer(4)), 0, 0, 50); +process.stdout.write(JSON.stringify({ coldStartFixture: __filename }) + "\n"); diff --git a/integration_tests/container/cjs/cold-start.js b/integration_tests/container/cjs/cold-start.js new file mode 100644 index 00000000..edc946db --- /dev/null +++ b/integration_tests/container/cjs/cold-start.js @@ -0,0 +1,22 @@ +// Real synchronous module loads, observed through dd-trace's module-load channels. +require("./cold-start-parent"); +require("/opt/cold-start-probe"); +require("/var/runtime/cold-start-probe"); + +let invocation = 0; +exports.handle = (_event, context) => { + invocation++; + // Lazy loading on a warm invocation is supported: it must be traced once, + // parented to that invocation, and not replayed on subsequent invocations. + if (invocation === 2) require("./cold-start-warm"); + process.stdout.write( + JSON.stringify({ + coldStartInvocation: { + requestId: context.awsRequestId, + invocation, + initializationType: process.env.AWS_LAMBDA_INITIALIZATION_TYPE, + }, + }) + "\n", + ); + return { message: "hello, dog!" }; +}; diff --git a/integration_tests/container/layer/Dockerfile b/integration_tests/container/layer/Dockerfile index cefa0dcf..0c8d4bd1 100644 --- a/integration_tests/container/layer/Dockerfile +++ b/integration_tests/container/layer/Dockerfile @@ -31,5 +31,8 @@ COPY layer_pkg /opt/nodejs/node_modules/datadog-lambda-js/ # handler.js (CJS) and esm.mjs (top-level await) are plain unwrapped user # handlers; the layer's handler.mjs wraps them via DD_LAMBDA_HANDLER. COPY handler.js esm.mjs ${LAMBDA_TASK_ROOT}/ +COPY cold_start_fixture/ ${LAMBDA_TASK_ROOT}/ +COPY cold_start_fixture/cold-start-probe.js /opt/cold-start-probe.js +COPY cold_start_fixture/cold-start-probe.js /var/runtime/cold-start-probe.js CMD ["/opt/nodejs/node_modules/datadog-lambda-js/handler.handler"] diff --git a/integration_tests_local/README.md b/integration_tests_local/README.md index 2ed37009..c3472a25 100644 --- a/integration_tests_local/README.md +++ b/integration_tests_local/README.md @@ -82,6 +82,60 @@ The case names are: | `cjs-fetch-requests` | fetch variant of `cjs-http-requests`: the global fetch (undici) is instrumented by a different dd-trace plugin than http/https; mock echo pins the injected headers on that path | | `cjs-custom-extractor` | `DD_TRACE_EXTRACTOR=extractor.extract`; asserts `_dd.parent_source: event` on the inferred span | | `cjs-proactive-init` | eager-init managed-instances RIE path with a 15 s init→invoke gap; asserts proactive-initialization markers on the raw logs | +| `cjs-cold-start` / `layer-cold-start` | real init-time module loads through npm redirect and layer entrypoints; one load span, known require spans, parent/timing/classification checks, and warm-load cleanup | +| `cjs-cold-start-skip` | a known loaded library and its subtree are absent from traces; other fixture modules remain | +| `cjs-cold-start-threshold` | a high `DD_MIN_COLD_START_DURATION` suppresses require spans while retaining the first-invocation load span | +| `cjs-cold-start-disabled` | `DD_COLD_START_TRACING=false` suppresses load and require spans, while the handler still loads the same modules | +| `cjs-cold-start-provisioned` / `cjs-cold-start-managed` | initialization-mode suppression, including a check that the runtime actually applied the requested mode | + +### Cold-start tracing: structural oracle, not a log golden + +These seven cases run in the same five-runtime, two-architecture CI matrix. They +use the existing return-value golden and runtime-tag assertion, but intentionally +do **not** have byte-for-byte log goldens. Module timings determine which nodes +cross `DD_MIN_COLD_START_DURATION`, so the full tree changes with machine speed. +Existing cases still disable cold-start tracing and retain their strict goldens; +the shared normalizer is unchanged. + +`check-cold-start-logs.js` checks all raw trace chunks before normalization: + +- exactly one invocation span per request, and proof all requests used one warm environment; +- exactly one `aws.lambda.load`, in the first invocation's trace, parented to the + inferred span when present or the invocation otherwise; +- real known init-time modules under `/var/task`, `/opt`, and `/var/runtime`, with + correctly classified require spans ending before invocation start (2ms tolerance + for the millisecond module clock versus the tracer clock); +- connected, acyclic require trees, unique exported identities, and no replay of + fixture modules on later invocations; +- a lazy module loaded on invocation two, parented to that invocation, not another + cold-start load span. Warm require spans are legitimate; replaying init modules is not; +- skip-library/subtree, min-duration, disabled, and initialization-mode controls. + +The fixture uses a 50ms `Atomics.wait` during module evaluation, against a 10ms +threshold. This is intentional fixture-only load cost, not a busy loop or an +assertion about exact duration. File-load markers prove the modules actually ran +even when their spans must be suppressed. No synthetic module-load channel +messages or tracer internals are used to manufacture the integration output. +Core-module name classification also has a checker unit test; the fixture does +not require a core module to exceed a real-time threshold. + +```bash +node --test integration_tests_local/check-*.test.js +RIE_HTTP_TRANSPORT=container RUNTIME_PARAM=22 CASE_PARAM=cjs-cold-start ./integration_tests_local/run.sh +SKIP_PACK=true RIE_HTTP_TRANSPORT=container RUNTIME_PARAM=22 CASE_PARAM=layer-cold-start ./integration_tests_local/run.sh +``` + +The positive cases expose missing module spans with released dd-trace 6.15.0. +They depend on the failed-load event cleanup in +[dd-trace-js #10535](https://github.com/DataDog/dd-trace-js/pull/10535). +Before merging, update the affected tracer pin to a release containing that fix +and run the full matrix without a local overlay. CI deliberately uses released +dependencies, with no workaround or expected-failure exemption. Updating snapshots +cannot repair a structural failure; raw logs are saved under `/tmp/l2-raw-*.log`. + +The managed fixture explicitly sets +`AWS_LAMBDA_NODEJS_WORKER_COUNT=1`: concurrency one alone still allows a multi-worker +pool and cannot guarantee one module cache across invocations. Two legacy aliases remain for muscle memory: `VARIANT_PARAM=cjs|esm` maps to `container-cjs`/`container-esm`, and `SIMULATE_PROACTIVE_INIT=true` maps to diff --git a/integration_tests_local/check-cold-start-logs.js b/integration_tests_local/check-cold-start-logs.js new file mode 100644 index 00000000..e8dc7714 --- /dev/null +++ b/integration_tests_local/check-cold-start-logs.js @@ -0,0 +1,130 @@ +"use strict"; + +const assert = require("node:assert/strict"); +const fs = require("node:fs"); + +const [mode, count] = process.argv.slice(2); +const expected = Number(count); +assert.ok(["enabled", "skip", "threshold", "disabled", "provisioned", "managed"].includes(mode), "known mode"); +assert.ok(Number.isInteger(expected) && expected >= 3, "at least three invocations required"); +const spans = []; +const starts = []; +const reports = []; +const fixtures = []; +const calls = []; +// Inspect the unnormalized exports across every payload: a "some trace matches" +// check would miss duplicate invocation spans or replayed module spans. +for (const line of fs.readFileSync(0, "utf8").split("\n")) { + const start = /^START RequestId: (\S+)/.exec(line); + const report = /^REPORT RequestId: (\S+)/.exec(line); + if (start) starts.push(start[1]); + if (report) reports.push(report[1]); + let record; + try { + record = JSON.parse(line); + } catch { + continue; + } + if (Array.isArray(record.traces)) spans.push(...record.traces.flat()); + if (record.coldStartFixture) fixtures.push(record.coldStartFixture); + if (record.coldStartInvocation) calls.push(record.coldStartInvocation); +} +assert.equal(starts.length, expected, "START count"); +assert.equal(new Set(starts).size, expected, "unique invocation IDs"); +assert.deepEqual(reports, starts, "REPORT IDs match invocations"); +assert.deepEqual( + calls.map((c) => c.requestId), + starts, + "fixture ran for every invocation", +); +assert.deepEqual( + calls.map((c) => c.invocation), + starts.map((_, i) => i + 1), + "same warm environment reused", +); +const expectedFixtures = [ + "/var/task/cold-start-parent.js", + "/var/task/cold-start-probe.js", + "/var/task/cold-start-skip.js", + "/var/task/cold-start-skipped-child.js", + "/opt/cold-start-probe.js", + "/var/runtime/cold-start-probe.js", + "/var/task/cold-start-warm.js", +]; +// Load markers prove suppression/filter tests actually executed the same modules. +assert.deepEqual(fixtures.slice().sort(), expectedFixtures.slice().sort(), "known modules really loaded exactly once"); +const lambdas = spans.filter((s) => s.name === "aws.lambda"); +assert.equal(lambdas.length, expected, "exactly one Lambda span per invocation across all payloads"); +const invocations = starts.map((id) => { + const matches = lambdas.filter((s) => s.meta?.request_id === id); + assert.equal(matches.length, 1, "one Lambda span for request ID"); + assert.equal(matches[0].error, 0, "successful invocation"); + return matches[0]; +}); +const cold = spans.filter((s) => s.name === "aws.lambda.load" || s.name.startsWith("aws.lambda.require")); +const suppressed = ["disabled", "provisioned", "managed"].includes(mode); +if (mode === "provisioned" || mode === "managed") { + const value = mode === "managed" ? "lambda-managed-instances" : "provisioned-concurrency"; + assert.ok( + calls.every((c) => c.initializationType === value), + "runtime actually used the requested initialization mode", + ); +} +if (suppressed) { + assert.equal(cold.length, 0, "cold-start tracing suppressed, including warm module loads"); +} else { + const [first, second] = invocations; + const loads = cold.filter((s) => s.name === "aws.lambda.load"); + assert.equal(loads.length, 1, "exactly one load span; none on warm invocations"); + const load = loads[0]; + const key = (s) => `${s.trace_id}/${s.span_id}`; + const byId = new Map(spans.map((s) => [key(s), s])); + assert.equal(byId.size, spans.length, "no duplicated exported span identities"); + const parent = (s) => byId.get(`${s.trace_id}/${s.parent_id}`); + assert.equal(load.trace_id, first.trace_id, "load belongs to first invocation trace"); + assert.equal(load.parent_id, parent(first)?.span_id || first.span_id, "load parent is inferred span or invocation"); + assert.ok(load.duration >= 0 && load.start + load.duration <= first.start + 2e6, "load ends before invocation start"); + const requires = cold.filter((s) => s.name.startsWith("aws.lambda.require")); + if (mode === "threshold") { + assert.equal(requires.length, 0, "high min-duration filters require spans but keeps the load span"); + } else { + // Only the deliberately slow fixture modules have fixed cardinality. Other + // modules can cross the duration threshold differently on each runtime/CPU. + assert.ok(requires.length > 0, "module-load capture is active"); + for (const span of requires) { + const filename = span.meta?.filename; + assert.equal(typeof filename, "string", "require span filename"); + const operation = filename.startsWith("/opt/") + ? "aws.lambda.require_layer" + : filename.startsWith("/var/runtime/") + ? "aws.lambda.require_runtime" + : filename.includes("/") + ? "aws.lambda.require" + : "aws.lambda.require_core_module"; + assert.equal(span.name, operation, "operation matches module path classification"); + assert.ok(Number.isFinite(span.duration) && span.duration >= 0, "valid require duration"); + let ancestor = span; + const seen = new Set(); + while (ancestor && ancestor !== load && !invocations.includes(ancestor)) { + assert.ok(!seen.has(key(ancestor)), "acyclic load tree"); + seen.add(key(ancestor)); + ancestor = parent(ancestor); + } + assert.ok(ancestor === load || invocations.includes(ancestor), "require linked to load or invocation"); + } + for (const filename of expectedFixtures) { + const matches = requires.filter((s) => s.meta.filename === filename); + const skipped = mode === "skip" && /cold-start-skip(?:ped-child)?\.js$/.test(filename); + assert.equal(matches.length, skipped ? 0 : 1, `fixture span cardinality: ${filename}`); + if (skipped) continue; + const span = matches[0]; + const warm = filename.endsWith("cold-start-warm.js"); + let ancestor = span; + while (ancestor && ancestor !== load && !invocations.includes(ancestor)) ancestor = parent(ancestor); + assert.equal(ancestor, warm ? second : load, "cold/warm fixture parent and no replay on later invocations"); + if (!warm) assert.ok(span.start + span.duration <= first.start + 2e6, "init module finishes before invocation"); + else assert.ok(span.start >= second.start - 2e6, "lazy module loads during second invocation"); + } + } +} +console.log(`Ok: cold-start ${mode} structure across ${expected} invocations`); diff --git a/integration_tests_local/check-cold-start-logs.test.js b/integration_tests_local/check-cold-start-logs.test.js new file mode 100644 index 00000000..6b292cfc --- /dev/null +++ b/integration_tests_local/check-cold-start-logs.test.js @@ -0,0 +1,275 @@ +"use strict"; + +const assert = require("node:assert/strict"); +const { spawnSync } = require("node:child_process"); +const path = require("node:path"); +const { test } = require("node:test"); + +function fixture(mode = "enabled") { + const filenames = [ + "/var/task/cold-start-parent.js", + "/var/task/cold-start-probe.js", + "/var/task/cold-start-skip.js", + "/var/task/cold-start-skipped-child.js", + "/opt/cold-start-probe.js", + "/var/runtime/cold-start-probe.js", + "/var/task/cold-start-warm.js", + ]; + const invocations = [1, 2, 3].map((i) => ({ + name: "aws.lambda", + trace_id: `trace-${i}`, + span_id: `lambda-${i}`, + parent_id: i === 1 ? "inferred" : "0", + start: i * 1e9, + duration: 3e8, + error: 0, + meta: { request_id: `request-${i}` }, + })); + const inferred = { name: "aws.apigateway", trace_id: "trace-1", span_id: "inferred", parent_id: "0" }; + const load = { + name: "aws.lambda.load", + trace_id: "trace-1", + span_id: "load", + parent_id: "inferred", + start: 1e8, + duration: 8e8, + }; + const modules = filenames.map((filename, i) => ({ + name: filename.startsWith("/opt/") + ? "aws.lambda.require_layer" + : filename.startsWith("/var/runtime/") + ? "aws.lambda.require_runtime" + : "aws.lambda.require", + trace_id: i === 6 ? "trace-2" : "trace-1", + span_id: `module-${i}`, + parent_id: i === 6 ? "lambda-2" : "load", + start: i === 6 ? 2.1e9 : 2e8, + duration: 5e7, + meta: { filename }, + })); + const calls = [1, 2, 3].map((i) => ({ + requestId: `request-${i}`, + invocation: i, + initializationType: + mode === "managed" + ? "lambda-managed-instances" + : mode === "provisioned" + ? "provisioned-concurrency" + : "on-demand", + })); + const spans = [...invocations, inferred]; + if (!["disabled", "provisioned", "managed"].includes(mode)) { + spans.push(load); + if (mode !== "threshold") { + spans.push( + ...modules.filter((s) => mode !== "skip" || !/cold-start-skip(?:ped-child)?\.js$/.test(s.meta.filename)), + ); + } + } + return { filenames, invocations, calls, spans, modules, load }; +} + +function check(data, mode = "enabled") { + const input = [ + ...data.filenames.map((coldStartFixture) => JSON.stringify({ coldStartFixture })), + ...data.calls.flatMap((c) => [ + `START RequestId: ${c.requestId} Version: $LATEST`, + JSON.stringify({ coldStartInvocation: c }), + `REPORT RequestId: ${c.requestId}`, + ]), + // Each span in a separate export: identities must work across all chunks. + ...data.spans.map((s) => JSON.stringify({ traces: [[s]] })), + ].join("\n"); + return spawnSync(process.execPath, [path.join(__dirname, "check-cold-start-logs.js"), mode, "3"], { + input, + encoding: "utf8", + }); +} + +for (const mode of ["enabled", "skip", "threshold", "disabled", "provisioned", "managed"]) { + test(`accepts ${mode} with cold and warm evidence`, () => { + const result = check(fixture(mode), mode); + assert.equal(result.status, 0, result.stderr); + }); +} + +test("accepts invocation parenting when no inferred span exists", () => { + const data = fixture(); + data.spans = data.spans.filter((s) => s.name !== "aws.apigateway"); + data.invocations[0].parent_id = "remote-parent"; + data.load.parent_id = data.invocations[0].span_id; + const result = check(data); + assert.equal(result.status, 0, result.stderr); +}); + +test("accepts core-module classification", () => { + const data = fixture(); + data.spans.push({ + ...data.modules[0], + name: "aws.lambda.require_core_module", + span_id: "core", + meta: { filename: "fs" }, + }); + const result = check(data); + assert.equal(result.status, 0, result.stderr); +}); + +const regressions = [ + [ + "missing capture", + (d) => { + d.spans = d.spans.filter((s) => !s.name.startsWith("aws.lambda.require")); + }, + /module-load capture/, + ], + [ + "missing load span", + (d) => { + d.spans = d.spans.filter((s) => s !== d.load); + }, + /exactly one load/, + ], + [ + "duplicate root in another trace", + (d) => { + d.spans.push({ ...d.invocations[0], trace_id: "other", span_id: "duplicate" }); + }, + /exactly one Lambda/, + ], + [ + "cold load on warm invocation", + (d) => { + d.spans.push({ ...d.load, span_id: "warm-load", trace_id: "trace-2" }); + }, + /none on warm/, + ], + [ + "wrong load parent", + (d) => { + d.load.parent_id = "lambda-1"; + }, + /load parent/, + ], + [ + "cross-trace load", + (d) => { + d.load.trace_id = "other"; + }, + /first invocation trace/, + ], + [ + "load ends too late", + (d) => { + d.load.duration = 2e9; + }, + /load ends/, + ], + [ + "init module ends too late", + (d) => { + d.modules[0].start = 1.1e9; + }, + /init module finishes/, + ], + [ + "incorrect classification", + (d) => { + d.modules[4].name = "aws.lambda.require"; + }, + /classification/, + ], + [ + "missing known module", + (d) => { + d.spans = d.spans.filter((s) => s !== d.modules[4]); + }, + /fixture span cardinality/, + ], + [ + "orphaned require", + (d) => { + d.modules[0].parent_id = "missing"; + }, + /require linked/, + ], + [ + "cyclic load tree", + (d) => { + d.modules[0].parent_id = d.modules[0].span_id; + }, + /acyclic/, + ], + [ + "duplicate export", + (d) => { + d.spans.push({ ...d.modules[0] }); + }, + /duplicated exported/, + ], + [ + "warm module attached to first invocation", + (d) => { + d.modules[6].trace_id = "trace-1"; + d.modules[6].parent_id = "load"; + }, + /cold\/warm fixture parent/, + ], + [ + "stale module replay on third invocation", + (d) => { + d.spans.push({ ...d.modules[0], trace_id: "trace-3", span_id: "stale", parent_id: "lambda-3" }); + }, + /fixture span cardinality/, + ], + [ + "fresh environment per invocation", + (d) => { + d.calls[1].invocation = 1; + }, + /warm environment reused/, + ], + [ + "fixture never executed", + (d) => { + d.filenames.pop(); + }, + /really loaded/, + ], +]; +for (const [name, mutate, message] of regressions) { + test(`rejects ${name}`, () => { + const data = fixture(); + mutate(data); + const result = check(data); + assert.equal(result.status, 1); + assert.match(result.stderr, message); + }); +} + +for (const mode of ["disabled", "provisioned", "managed", "threshold"]) { + test(`rejects require spans in ${mode} mode`, () => { + const data = fixture(mode); + data.spans.push(data.modules[0]); + const result = check(data, mode); + assert.equal(result.status, 1); + assert.match(result.stderr, /suppressed|high min-duration/); + }); +} + +for (const index of [2, 3]) { + test(`rejects an ignored ${index === 2 ? "library" : "subtree"} span`, () => { + const data = fixture("skip"); + data.spans.push(data.modules[index]); + const result = check(data, "skip"); + assert.equal(result.status, 1); + assert.match(result.stderr, /fixture span cardinality/); + }); +} + +test("rejects a requested mode that the runtime did not apply", () => { + const data = fixture("managed"); + data.calls[0].initializationType = "on-demand"; + const result = check(data, "managed"); + assert.equal(result.status, 1); + assert.match(result.stderr, /requested initialization mode/); +}); diff --git a/integration_tests_local/run.sh b/integration_tests_local/run.sh index d65207e5..5597ecae 100755 --- a/integration_tests_local/run.sh +++ b/integration_tests_local/run.sh @@ -33,6 +33,8 @@ # cjs-proactive-init | cjs | node_modules/datadog-lambda-js/dist/handler.handler | proactive-initialization markers (raw-log assertions) # manual-metrics-only | cjs | send-metrics.handle | DD_TRACE_ENABLED=false: metrics flush, no spans, no log correlation # cjs-capture-payload | cjs | node_modules/datadog-lambda-js/dist/handler.handler | DD_CAPTURE_LAMBDA_PAYLOAD=true: function.request/response span tags +# cjs-cold-start / layer-cold-start | cjs/layer | redirect handler | structural cold/warm module-load tracing +# cjs-cold-start-{skip,threshold,disabled,provisioned,managed} | cjs | redirect handler | cold-start filtering and suppression # # Usage (from repo root or this directory): # ./integration_tests_local/run.sh # all runtimes, all cases @@ -135,6 +137,13 @@ ALL_CASES=( "cjs-proactive-init" "manual-metrics-only" "cjs-capture-payload" + "cjs-cold-start" + "layer-cold-start" + "cjs-cold-start-skip" + "cjs-cold-start-threshold" + "cjs-cold-start-disabled" + "cjs-cold-start-provisioned" + "cjs-cold-start-managed" ) function configure_case() { @@ -148,6 +157,9 @@ function configure_case() { case_needs_mock=false case_invoke_timeout=0 case_timeout=false + case_cold_mode="" + case_cold_tracing=false + case_managed=false case_return_extension=json # Return-value golden shape: # default - every event returns the shared default.json payload @@ -311,6 +323,42 @@ function configure_case() { case_entry_handler="node_modules/datadog-lambda-js/dist/handler.handler" case_extra_env=(-e DD_LAMBDA_HANDLER=handler.handle -e DD_TRACE_EXTRACTOR=extractor.extract) ;; + cjs-cold-start|layer-cold-start|cjs-cold-start-skip|cjs-cold-start-threshold|cjs-cold-start-disabled|cjs-cold-start-provisioned|cjs-cold-start-managed) + case_image=cjs + case_entry_handler="node_modules/datadog-lambda-js/dist/handler.handler" + case_cold_mode=enabled + case_cold_tracing=true + case_extra_env=(-e DD_LAMBDA_HANDLER=cold-start.handle -e DD_MIN_COLD_START_DURATION=10) + case "$case_name" in + layer-cold-start) + case_image=layer + case_entry_handler="/opt/nodejs/node_modules/datadog-lambda-js/handler.handler" + ;; + cjs-cold-start-skip) + case_cold_mode=skip + case_extra_env+=(-e DD_COLD_START_TRACE_SKIP_LIB=./cold-start-skip) + ;; + cjs-cold-start-threshold) + case_cold_mode=threshold + case_extra_env=(-e DD_LAMBDA_HANDLER=cold-start.handle -e DD_MIN_COLD_START_DURATION=1000000) + ;; + cjs-cold-start-disabled) + case_cold_mode=disabled + case_cold_tracing=false + ;; + cjs-cold-start-provisioned) + case_cold_mode=provisioned + case_extra_env+=(-e AWS_LAMBDA_INITIALIZATION_TYPE=provisioned-concurrency) + ;; + cjs-cold-start-managed) + case_cold_mode=managed + case_managed=true + # MC alone does not cap the runtime's default worker pool. One worker makes + # the warm-invocation/module-cache assertions deterministic in this fixture. + case_extra_env+=(-e AWS_LAMBDA_INITIALIZATION_TYPE=lambda-managed-instances -e AWS_LAMBDA_MAX_CONCURRENCY=1 -e AWS_LAMBDA_NODEJS_WORKER_COUNT=1 -e AWS_LAMBDA_LOG_FORMAT=text) + ;; + esac + ;; cjs-proactive-init) case_image=cjs case_entry_handler="node_modules/datadog-lambda-js/dist/handler.handler" @@ -362,6 +410,7 @@ if [ "$update_snapshots" = true ]; then fi mismatch_found=false +structural_failure=false container_ids=() rie_download="" mock_cid="" @@ -448,6 +497,10 @@ function prepare_layer_context() { if [ "$layer_context_prepared" = true ]; then return fi + # Keep one fixture body for both entrypoints. Refresh even with SKIP_PACK: + # that flag reuses the library artifact, not stale copies of edited fixtures. + mkdir -p "$integration_tests_dir/container/layer/cold_start_fixture" + cp "$integration_tests_dir/container/cjs"/cold-start*.js "$integration_tests_dir/container/layer/cold_start_fixture/" if [ -n "$SKIP_PACK" ] && [ -f "$integration_tests_dir/container/layer/deps.package.json" ]; then echo "SKIP_PACK: reusing existing container/layer context" else @@ -653,7 +706,7 @@ for node_version in "${RUNTIMES[@]}"; do -e DD_SITE=datadoghq.com \ -e DD_FLUSH_TO_LOG=true \ -e DD_INTEGRATION_TEST=true \ - -e DD_COLD_START_TRACING=false \ + -e DD_COLD_START_TRACING="$case_cold_tracing" \ -e DD_TRACE_STARTUP_LOGS=false \ -e DD_SERVICE_MAPPING="lambda_api_gateway:remappedApiGatewayServiceName,lambda_sns:remappedSnsServiceName,lambda_sqs:remappedSqsServiceName,lambda_s3:remappedS3ServiceName,lambda_eventbridge:remappedEventBridgeServiceName,lambda_kinesis:remappedKinesisServiceName,lambda_dynamodb:remappedDynamoDbServiceName,lambda_url:remappedUrlServiceName" \ -e AWS_LAMBDA_FUNCTION_NAME="$function_name" \ @@ -801,7 +854,7 @@ for node_version in "${RUNTIMES[@]}"; do # The managed-instances path used by the proactive-init case emits # REPORT but never RTDONE, so requiring it there would always time out. expected_invocation_count=${#input_event_files[@]} - if [ "$case_proactive" = true ] || [ "$case_timeout" = true ]; then + if [ "$case_proactive" = true ] || [ "$case_timeout" = true ] || [ "$case_managed" = true ]; then expected_rtdone_count=0 else expected_rtdone_count=$expected_invocation_count @@ -854,6 +907,15 @@ for node_version in "${RUNTIMES[@]}"; do fi snapshot_logs=$raw_logs + if [ -n "$case_cold_mode" ]; then + if ! printf '%s\n' "$raw_logs" | node "$local_dir/check-cold-start-logs.js" "$case_cold_mode" "$expected_invocation_count"; then + echo "FAILURE: cold-start trace assertions failed for $function_name" >&2 + structural_failure=true + printf '%s\n' "$raw_logs" > "/tmp/l2-raw-${case_name}-node${node_version}.log" + echo "Full raw logs written to /tmp/l2-raw-${case_name}-node${node_version}.log" >&2 + mismatch_found=true + fi + fi if [ "$case_timeout" = true ]; then snapshot_logs=$(printf '%s\n' "$raw_logs" | node "$local_dir/check-timeout-logs.js" "$expected_invocation_count") if [ "$?" -ne 0 ]; then @@ -905,6 +967,13 @@ for node_version in "${RUNTIMES[@]}"; do docker rm -f "$cid" >/dev/null 2>&1 container_ids=("${container_ids[@]/$cid}") + # Only these dedicated cases use a structural oracle instead of a byte log golden. + # Real module timings change the filtered tree; existing cases/normalization stay strict. + # Return-value goldens and runtime-tag assertions above still apply to every invocation. + if [ -n "$case_cold_mode" ]; then + continue + fi + # Shared per case, with a per-runtime override for real divergence. runtime_log_snapshot="$local_dir/snapshots/logs/${case_name}_node${node_version}.log" if [ -f "$runtime_log_snapshot" ]; then @@ -930,7 +999,11 @@ set -e if [ "$mismatch_found" = true ]; then echo "FAILURE: A mismatch between new data and a snapshot was found and printed above." - echo "If the change is expected, generate new snapshots by running 'UPDATE_SNAPSHOTS=true ./integration_tests_local/run.sh'" + if [ "$structural_failure" = true ]; then + echo "Cold-start structural assertions failed. Updating snapshots cannot repair these failures." + else + echo "If the change is expected, generate new snapshots by running 'UPDATE_SNAPSHOTS=true ./integration_tests_local/run.sh'" + fi exit 1 fi