From 3e74a643eafb8ce2b2b7c259393c3729202cc7d1 Mon Sep 17 00:00:00 2001 From: Ruben Bridgewater Date: Tue, 1 Sep 2026 16:42:15 +0200 Subject: [PATCH 1/4] ci(integration): stabilize Lambda log snapshots A successful log fetch could still contain fewer completions than were invoked, and AWS proactive initialization changes cold-start fields without a library behavior change. Both cases made the snapshots depend on platform timing. The AWS snapshots now wait for every completion and ignore only scheduler-owned fields. RIE and focused telemetry tests retain cold-start and proactive-initialization coverage. --- integration_tests_local/normalize.sh | 110 -------- integration_tests_local/run.sh | 2 +- scripts/normalize_integration_logs.sh | 90 ++++++ scripts/run_integration_tests.sh | 111 ++------ scripts/wait_for_complete_logs.sh | 63 +++++ src/integration-log-scripts.spec.ts | 391 ++++++++++++++++++++++++++ src/metrics/enhanced-metrics.spec.ts | 18 +- src/trace/listener.spec.ts | 17 ++ 8 files changed, 610 insertions(+), 192 deletions(-) delete mode 100755 integration_tests_local/normalize.sh create mode 100755 scripts/normalize_integration_logs.sh create mode 100644 scripts/wait_for_complete_logs.sh create mode 100644 src/integration-log-scripts.spec.ts diff --git a/integration_tests_local/normalize.sh b/integration_tests_local/normalize.sh deleted file mode 100755 index c7f1ff6d..00000000 --- a/integration_tests_local/normalize.sh +++ /dev/null @@ -1,110 +0,0 @@ -#!/bin/bash - -# Local log-normalization pipeline for integration test snapshots. -# -# This is based on the filter chain used by scripts/run_integration_tests.sh -# to replace invocation-specific data (timestamps, IDs, durations, ...) with -# XXXX before diffing logs against snapshots. Local-only RIE filters and -# deterministic cold-start assertions are documented below. -# -# Usage: -# some-log-producer | ./normalize.sh -# RUN_ID=abcdef12 ./normalize.sh < raw.log > normalized.log -# -# Reads from stdin, writes to stdout. -# Optional env: -# RUN_ID - random per-run ID embedded in deployed function names; stripped -# to XXXX when set (AWS suite only; the local harness uses static -# function names and leaves this unset). - -set -e - -script_path=${BASH_SOURCE[0]} -local_dir=$(dirname "$script_path") -repo_dir=$(dirname "$local_dir") - -# An empty Perl program is a pass-through when RUN_ID is unset. -run_id_filter='' -if [ -n "$RUN_ID" ]; then - run_id_filter="s/${RUN_ID}/XXXX/g" -fi - -node "$repo_dir/integration_tests/parse-json.js" | - # Filter serverless cli errors - sed '/Serverless: Recoverable error occurred/d' | - # Normalize Lambda runtime report logs - perl -p -e 's/(RequestId|TraceId|init|SegmentId|Duration|Memory Used|"e"):( )?[a-z0-9\.\-]+/\1:\2XXXX/g' | - # Node.js 26 preview and container-image runtimes emit extra platform noise. - sed '/preview runtime version and should not be used for production workloads/d' | - sed '/^INIT_REPORT /d' | - sed '/DEP0205.*module\.register()/d' | - sed '/node --trace-deprecation.*where the warning was created/d' | - # Normalize DD APM headers and AWS account ID - perl -p -e "s/(x-datadog-parent-id:|x-datadog-trace-id:|account_id:)[0-9]+/\1XXXX/g" | - # Same headers as echoed by the http-requests fixture's mock server — - # JSON.stringify output, i.e. quoted with no space after the colon — - # plus the W3C traceparent/tracestate pair it also echoes. - perl -p -e 's/"(x-datadog-trace-id|x-datadog-parent-id)":"[0-9]+"/"\1":"XXXX"/g' | - perl -p -e 's/"traceparent":"[0-9a-f-]+"/"traceparent":"XXXX"/g' | - perl -p -e 's/"tracestate":"[^"]*"/"tracestate":"XXXX"/g' | - # Strip API key from logged requests - perl -p -e "s/(api_key=|'api_key': ')[a-z0-9\.\-]+/\1XXXX/g" | - # Normalize log timestamps - perl -p -e "s/[0-9]{4}\-[0-9]{2}\-[0-9]{2} [0-9]{2}:[0-9]{2}:[0-9]{2}\.[0-9]+( \(\-?\+?[0-9:]+\))?/XXXX-XX-XX XX:XX:XX.XXX/" | - # Same for the ISO8601-with-T format the RIC uses on ERROR lines under RIE - # (e.g. "2026-08-28T04:00:26.774Z\t\tERROR\tInvoke Error ...") - perl -p -e "s/[0-9]{4}\-[0-9]{2}\-[0-9]{2}T[0-9]{2}:[0-9]{2}:[0-9]{2}\.[0-9]+Z/XXXX-XX-XXTXX:XX:XX.XXXZ/" | - # Managed-instances (proactive-init case) structured logs: per-invocation - # request ids, and the overflow value in Node's TimeoutOverflowWarning, - # which is derived from a wall-clock deadline and varies run to run. - perl -p -e 's/"requestId": "[0-9a-f-]+"/"requestId": "XXXX"/g' | - # Same id in the compact JSON the preview RIC uses on Invoke Error lines. - perl -p -e 's/"requestId":"[0-9a-f-]+"/"requestId":"XXXX"/g' | - perl -p -e 's/TimeoutOverflowWarning: [0-9]+/TimeoutOverflowWarning: XXXX/g' | - # Node appends its once-per-process "trace-warnings" hint to whichever - # warning happens to be emitted first — which one is racy (and differs - # between amd64 CI and arm64 local runs). Drop the hint in both its - # JSON-embedded (\n literal) and standalone-line forms. - perl -p -e 's/\\n\(Use `node --trace-warnings \.\.\.` to show where the warning was created\)//g' | - sed '/^(Use `node --trace-warnings \.\.\.` to show where the warning was created)$/d' | - # Pid in Node's "(node:NN)" warning prefix varies with process layout. - perl -p -e 's/\(node:[0-9]+\)/(node:XX)/g' | - # Normalize DD trace ID injection - perl -p -e "s/(dd\.trace_id=)[0-9]+ (dd\.span_id=)[0-9]+/\1XXXX \2XXXX/" | - # Normalize execution ID in logs prefix - perl -p -e $'s/[0-9a-z]+\-[0-9a-z]+\-[0-9a-z]+\-[0-9a-z]+\-[0-9a-z]+\t/XXXX-XXXX-XXXX-XXXX-XXXX\t/' | - # Normalize minor package version tag so that these snapshots aren't broken on version bumps - perl -p -e "s/(dd_lambda_layer:datadog-nodev[0-9]+\.)[0-9]+\.[0-9]+/\1XX\.X/g" | - perl -p -e 's/"(span_id|apiid|runtime-id|record_ids|parent_id|trace_id|start|duration|tcp\.local\.address|tcp\.local\.port|dns\.address|request_id|function_arn|x-datadog-trace-id|x-datadog-parent-id|datadog_lambda|dd_trace|process_id)":\ ("?)[a-zA-Z0-9\.:\-]+("?)/"\1":\2XXXX\3/g' | - # Resolved IP of the mock-http container: varies with whichever /16 Docker's address pool hands the per-run network. - perl -p -e 's/"dns\.addresses": "[^"]*"/"dns.addresses": "XXXX"/g' | - # Strip out run ID (from function name, resource, etc.) - perl -p -e "$run_id_filter" | - # Normalize line numbers in stack traces - perl -p -e 's/(.js:)[0-9]*:[0-9]*/\1XXX:XXX/g' | - # Preserve stable span meta and metrics; volatile values are normalized above. - # Normalize enhanced metric datadog_lambda tag - perl -p -e "s/(datadog_lambda:v)[0-9\.]+/\1X.X.X/g" | - # Normalize lookup resource - perl -p -e "s/(\"resource\":\"169.)[0-9\.]+/\1X.X.X/g" | - # Normalize Axios version - perl -p -e "s/User-Agent:axios\/\d+\.\d+\.\d+/User-Agent:axios\/X\.X\.X/g" | - # Remove init start line - perl -p -e "s/INIT_START.*//g" | - # Proactive initialization is platform scheduling, not code behavior. - # Keep cold_start to cover the deterministic local cold-to-warm transition. - sed '/proactive_initialization/d' | - perl -p -e 's/ \(init: [^)]*\)//g' | - # Normalize RIE platform log lines (local harness only; no-op on AWS logs): - # "28 Jul 2026 19:42:34,536 [INFO] (rapid) ..." timestamps, request ids, - # and init/invoke durations vary run to run - perl -p -e 's/^[0-9]{2} \w{3} [0-9]{4} [0-9]{2}:[0-9]{2}:[0-9]{2},[0-9]{3} (\[INFO\] \(rapid\))/XXXX \1/' | - # Managed-instances supervisor line embeds a container pid: pid=NN. - perl -p -e 's/(LocalProcessSupervisor\.Exec pid=)[0-9]+/\1XX/g' | - perl -p -e 's/(requestId: )[0-9a-f-]+/\1XXXX/g' | - perl -p -e 's/(duration(Ms)?: )[0-9.]+/\1XXXX/g' | - sed -E "s/(tracestate\:)([A-Za-z0-9\-\=\:\;].+)/\1XXX/g" | - sed -E "s/(\"_dd.p.tid\"\: \")[a-z0-9\.\-]+/\1XXXX/g" | - sed -E "s/(_dd.p.tid=)[a-z0-9\.\-]+/\1XXXX/g" | - # Remove RIE's trailing REPORT tab without changing application output. - sed -E '/^REPORT RequestId:/s/[[:blank:]]+$//' diff --git a/integration_tests_local/run.sh b/integration_tests_local/run.sh index c9ea51e3..60aef96b 100755 --- a/integration_tests_local/run.sh +++ b/integration_tests_local/run.sh @@ -739,7 +739,7 @@ for node_version in "${RUNTIMES[@]}"; do done fi - logs=$(printf '%s\n' "$raw_logs" | "$local_dir/normalize.sh") + logs=$(printf '%s\n' "$raw_logs" | "$repo_dir/scripts/normalize_integration_logs.sh" rie) # `runtime:nodejsNN.x` is the only genuinely runtime-specific line in # the whole log — everything else is identical across 18/20/22/24/26. diff --git a/scripts/normalize_integration_logs.sh b/scripts/normalize_integration_logs.sh new file mode 100755 index 00000000..a42e4ce3 --- /dev/null +++ b/scripts/normalize_integration_logs.sh @@ -0,0 +1,90 @@ +#!/bin/bash + +set -eo pipefail + +if [ "$#" -lt 1 ] || [ "$#" -gt 2 ]; then + echo "Usage: $0 [raw|formatted]" >&2 + exit 2 +fi + +platform=$1 +case "$platform" in + aws) + cold_start_filter="s/(\"cold_start\":[[:space:]]*)\"(?:true|false)\"/\$1\"XXXX\"/g" + cold_start_filter+="; s/cold_start:(?:true|false)/cold_start:XXXX/g" + ;; + rie) + cold_start_filter='' + ;; + *) + echo "Unsupported integration-test platform: $platform" >&2 + exit 2 + ;; +esac + +input_format=${2:-raw} +case "$input_format" in + raw|formatted) ;; + *) + echo "Unsupported integration-test log format: $input_format" >&2 + exit 2 + ;; +esac + +timestamp_filter="s/[0-9]{4}\\-[0-9]{2}\\-[0-9]{2} [0-9]{2}:[0-9]{2}:[0-9]{2}\\.[0-9]+" +timestamp_filter+="( \\(\\-?\\+?[0-9:]+\\))?/XXXX-XX-XX XX:XX:XX.XXX/" +volatile_value_filter="s/\"(span_id|apiid|runtime-id|record_ids|parent_id|trace_id|start|duration" +volatile_value_filter+="|tcp\\.local\\.address|tcp\\.local\\.port|dns\\.address|request_id|function_arn" +volatile_value_filter+="|x-datadog-trace-id|x-datadog-parent-id|datadog_lambda|dd_trace|process_id)\"" +volatile_value_filter+=": (\"?)[a-zA-Z0-9\\.:\\-]+(\"?)/\"\$1\":\$2XXXX\$3/g" + +script_path=${BASH_SOURCE[0]} +scripts_dir=$(dirname "$script_path") +repo_dir=$(dirname "$scripts_dir") + +if [ "$input_format" = formatted ]; then + cat +else + node "$repo_dir/integration_tests/parse-json.js" +fi | + sed '/Serverless: Recoverable error occurred/d' | + perl -p -e 's/(RequestId|TraceId|init|SegmentId|Duration|Memory Used|"e"):( )?[a-z0-9\.\-]+/\1:\2XXXX/g' | + sed '/preview runtime version and should not be used for production workloads/d' | + sed '/^INIT_REPORT /d' | + sed '/DEP0205.*module\.register()/d' | + sed '/node --trace-deprecation.*where the warning was created/d' | + perl -p -e 's/(x-datadog-parent-id:|x-datadog-trace-id:|account_id:)[0-9]+/$1XXXX/g' | + perl -p -e 's/"(x-datadog-trace-id|x-datadog-parent-id)":"[0-9]+"/"$1":"XXXX"/g' | + perl -p -e 's/"traceparent":"[0-9a-f-]+"/"traceparent":"XXXX"/g' | + perl -p -e 's/"tracestate":"[^"]*"/"tracestate":"XXXX"/g' | + perl -p -e "s/(api_key=|'api_key': ')[a-z0-9\.\-]+/\1XXXX/g" | + perl -p -e "$timestamp_filter" | + perl -p -e 's/[0-9]{4}\-[0-9]{2}\-[0-9]{2}T[0-9]{2}:[0-9]{2}:[0-9]{2}\.[0-9]+Z/XXXX-XX-XXTXX:XX:XX.XXXZ/' | + perl -p -e 's/"requestId": "[0-9a-f-]+"/"requestId": "XXXX"/g' | + perl -p -e 's/"requestId":"[0-9a-f-]+"/"requestId":"XXXX"/g' | + perl -p -e 's/TimeoutOverflowWarning: [0-9]+/TimeoutOverflowWarning: XXXX/g' | + perl -p -e 's/\\n\(Use `node --trace-warnings \.\.\.` to show where the warning was created\)//g' | + sed '/^(Use `node --trace-warnings \.\.\.` to show where the warning was created)$/d' | + perl -p -e 's/\(node:[0-9]+\)/(node:XX)/g' | + perl -p -e 's/(dd\.trace_id=)[0-9]+ (dd\.span_id=)[0-9]+/$1XXXX $2XXXX/' | + perl -p -e $'s/[0-9a-z]+\-[0-9a-z]+\-[0-9a-z]+\-[0-9a-z]+\-[0-9a-z]+\t/XXXX-XXXX-XXXX-XXXX-XXXX\t/' | + perl -p -e 's/(dd_lambda_layer:datadog-nodev[0-9]+\.)[0-9]+\.[0-9]+/$1XX.X/g' | + perl -p -e "$volatile_value_filter" | + perl -p -e 's/"dns\.addresses": "[^"]*"/"dns.addresses": "XXXX"/g' | + RUN_ID="${RUN_ID:-}" perl -p -e 's/\Q$ENV{RUN_ID}\E/XXXX/g if length $ENV{RUN_ID}' | + perl -p -e 's/(.js:)[0-9]*:[0-9]*/$1XXX:XXX/g' | + perl -p -e 's/(datadog_lambda:v)[0-9\.]+/$1X.X.X/g' | + perl -p -e 's/("resource":"169.)[0-9\.]+/$1X.X.X/g' | + perl -p -e 's/User-Agent:axios\/\d+\.\d+\.\d+/User-Agent:axios\/X.X.X/g' | + sed '/INIT_START Runtime Version:/d' | + sed -E '/^[[:space:]]*"proactive_initialization(" *:|:true")/d' | + perl -p -e "$cold_start_filter" | + perl -p -e 's/ \(init: [^)]*\)//g' | + perl -p -e 's/^[0-9]{2} \w{3} [0-9]{4} [0-9]{2}:[0-9]{2}:[0-9]{2},[0-9]{3} (\[INFO\] \(rapid\))/XXXX $1/' | + perl -p -e 's/(LocalProcessSupervisor\.Exec pid=)[0-9]+/$1XX/g' | + perl -p -e 's/(requestId: )[0-9a-f-]+/$1XXXX/g' | + perl -p -e 's/(duration(Ms)?: )[0-9.]+/$1XXXX/g' | + sed -E 's/(tracestate\:)([A-Za-z0-9\-\=\:\;].+)/\1XXX/g' | + sed -E 's/("_dd.p.tid"\: ")[a-z0-9\.\-]+/\1XXXX/g' | + sed -E 's/(_dd.p.tid=)[a-z0-9\.\-]+/\1XXXX/g' | + sed -E '/^REPORT RequestId:/s/[[:blank:]]+$//' diff --git a/scripts/run_integration_tests.sh b/scripts/run_integration_tests.sh index f052060b..5fc96960 100755 --- a/scripts/run_integration_tests.sh +++ b/scripts/run_integration_tests.sh @@ -27,15 +27,19 @@ export BUILDX_NO_DEFAULT_ATTESTATIONS=1 ALL_LAMBDA_HANDLERS=("async-metrics" "esm" "sync-metrics" "http-requests" "process-input-traced" "throw-error-traced" "status-code-500s" "container-cjs" "container-esm") ZIP_LAMBDA_HANDLERS=("async-metrics" "esm" "sync-metrics" "http-requests" "process-input-traced" "throw-error-traced" "status-code-500s") -LOGS_WAIT_SECONDS=20 +LOG_FETCH_ATTEMPTS=10 +LOG_FETCH_INTERVAL_SECONDS=10 script_path=${BASH_SOURCE[0]} -scripts_dir=$(dirname $script_path) -repo_dir=$(dirname $scripts_dir) +scripts_dir=$(dirname "$script_path") +repo_dir=$(dirname "$scripts_dir") cwd=$(pwd) integration_tests_dir="$repo_dir/integration_tests" +# shellcheck source=scripts/wait_for_complete_logs.sh +source "$scripts_dir/wait_for_complete_logs.sh" + script_utc_start_time=$(date -u +"%Y%m%dT%H%M%S") mismatch_found=false @@ -197,103 +201,50 @@ nodejs version : ${!nodejs_version} and run id : ${!run_id}" done done done -set -e - -echo "Sleeping $LOGS_WAIT_SECONDS seconds to wait for logs to appear in CloudWatch..." -sleep $LOGS_WAIT_SECONDS - set +e # Don't exit this script if there is a diff or the logs endpoint fails echo "Fetching logs for invocations and comparing to snapshots" +expected_completion_count=${#input_event_files[@]} for handler_name in "${LAMBDA_HANDLERS[@]}"; do for parameters_set in "${PARAMETERS_SETS[@]}"; do function_name="${handler_name}_node" function_snapshot_path="./snapshots/logs/${handler_name}_${parameters_set}.log" - unstripped_path="./snapshots/logs/${handler_name}_${parameters_set}.log.unstripped" serverless_runtime=$parameters_set[0] nodejs_version=$parameters_set[1] run_id=$parameters_set[2] - # Fetch logs with serverless cli, retrying to avoid AWS account-wide rate limit error - retry_counter=0 - while [ $retry_counter -lt 10 ]; do - raw_logs=$(run_serverless logs --stage ${!run_id} -f $function_name --startTime $script_utc_start_time) - fetch_logs_exit_code=$? - if [ $fetch_logs_exit_code -eq 1 ]; then - echo "Retrying fetch logs for $function_name..." - retry_counter=$(($retry_counter + 1)) - sleep 10 - continue - fi - break - done - - if [ $retry_counter -eq 9 ]; then - echo "FAILURE: Could not retrieve logs for $function_name" - echo "Error from final attempt to retrieve logs:" - echo $raw_logs - - exit 1 + if ! raw_logs=$(wait_for_complete_logs \ + "$expected_completion_count" \ + "$LOG_FETCH_ATTEMPTS" \ + "$LOG_FETCH_INTERVAL_SECONDS" \ + run_serverless logs --stage "${!run_id}" -f "$function_name" --startTime "$script_utc_start_time"); then + mismatch_found=true + continue fi + if ! logs=$(printf '%s\n' "$raw_logs" | \ + RUN_ID="${!run_id}" "$scripts_dir/normalize_integration_logs.sh" aws); then + echo "FAILURE: Could not normalize logs for $function_name" >&2 + mismatch_found=true + continue + fi - # Replace invocation-specific data like timestamps and IDs with XXXX to normalize logs across executions - logs=$( - echo "$raw_logs" | - node parse-json.js | - # Filter serverless cli errors - sed '/Serverless: Recoverable error occurred/d' | - # Normalize Lambda runtime report logs - perl -p -e 's/(RequestId|TraceId|init|SegmentId|Duration|Memory Used|"e"):( )?[a-z0-9\.\-]+/\1:\2XXXX/g' | - # Drop init duration from END lines; cold starts sometimes include it, warm starts do not. - perl -p -e 's/ \(init: XXXX ms\)//g' | - # Node.js 26 preview and container-image runtimes emit extra platform noise. - sed '/preview runtime version and should not be used for production workloads/d' | - sed '/^INIT_REPORT /d' | - sed '/DEP0205.*module\.register()/d' | - sed '/node --trace-deprecation.*where the warning was created/d' | - # Normalize DD APM headers and AWS account ID - perl -p -e "s/(x-datadog-parent-id:|x-datadog-trace-id:|account_id:)[0-9]+/\1XXXX/g" | - # Strip API key from logged requests - perl -p -e "s/(api_key=|'api_key': ')[a-z0-9\.\-]+/\1XXXX/g" | - # Normalize log timestamps - perl -p -e "s/[0-9]{4}\-[0-9]{2}\-[0-9]{2} [0-9]{2}:[0-9]{2}:[0-9]{2}\.[0-9]+( \(\-?\+?[0-9:]+\))?/XXXX-XX-XX XX:XX:XX.XXX/" | - # Normalize DD trace ID injection - perl -p -e "s/(dd\.trace_id=)[0-9]+ (dd\.span_id=)[0-9]+/\1XXXX \2XXXX/" | - # Normalize execution ID in logs prefix - perl -p -e $'s/[0-9a-z]+\-[0-9a-z]+\-[0-9a-z]+\-[0-9a-z]+\-[0-9a-z]+\t/XXXX-XXXX-XXXX-XXXX-XXXX\t/' | - # Normalize minor package version tag so that these snapshots aren't broken on version bumps - perl -p -e "s/(dd_lambda_layer:datadog-nodev[0-9]+\.)[0-9]+\.[0-9]+/\1XX\.X/g" | - perl -p -e 's/"(span_id|apiid|runtime-id|record_ids|parent_id|trace_id|start|duration|tcp\.local\.address|tcp\.local\.port|dns\.address|request_id|function_arn|x-datadog-trace-id|x-datadog-parent-id|datadog_lambda|dd_trace|process_id)":\ ("?)[a-zA-Z0-9\.:\-]+("?)/"\1":\2XXXX\3/g' | - # Strip out run ID (from function name, resource, etc.) - perl -p -e "s/${!run_id}/XXXX/g" | - # Normalize line numbers in stack traces - perl -p -e 's/(.js:)[0-9]*:[0-9]*/\1XXX:XXX/g' | - # Remove metrics and metas in logged traces (their order is inconsistent) - perl -p -e 's/"(meta|metrics)":{(.*?)}/"\1":{"XXXX": "XXXX"}/g' | - # Normalize enhanced metric datadog_lambda tag - perl -p -e "s/(datadog_lambda:v)[0-9\.]+/\1X.X.X/g" | - # Normalize lookup resource - perl -p -e "s/(\"resource\":\"169.)[0-9\.]+/\1X.X.X/g" | - # Normalize Axios version - perl -p -e "s/User-Agent:axios\/\d+\.\d+\.\d+/User-Agent:axios\/X\.X\.X/g" | - # Remove init start line - perl -p -e "s/INIT_START.*//g" | - sed -E "s/(tracestate\:)([A-Za-z0-9\-\=\:\;].+)/\1XXX/g" | - sed -E "s/(\"_dd.p.tid\"\: \")[a-z0-9\.\-]+/\1XXXX/g" | - sed -E "s/(_dd.p.tid=)[a-z0-9\.\-]+/\1XXXX/g" - ) - - if [ ! -f $function_snapshot_path ]; then + if [ ! -f "$function_snapshot_path" ]; then # If no snapshot file exists yet, we create one echo "Writing logs to $function_snapshot_path because no snapshot exists yet" - echo "$logs" >$function_snapshot_path + printf '%s\n' "$logs" > "$function_snapshot_path" else + if ! normalized_snapshot=$(RUN_ID="${!run_id}" \ + "$scripts_dir/normalize_integration_logs.sh" aws formatted < "$function_snapshot_path"); then + echo "FAILURE: Could not normalize snapshot for $function_name" >&2 + mismatch_found=true + continue + fi # Compare new logs to snapshots - diff_output=$(echo "$logs" | sort | diff -w - <(sort $function_snapshot_path)) + diff_output=$(printf '%s\n' "$logs" | sort | diff -w - <(printf '%s\n' "$normalized_snapshot" | sort)) if [ $? -eq 1 ]; then if [ -n "$UPDATE_SNAPSHOTS" ]; then # If $UPDATE_SNAPSHOTS is set to true write the new logs over the current snapshot echo "Overwriting log snapshot for $function_snapshot_path" - echo "$logs" >$function_snapshot_path + printf '%s\n' "$logs" > "$function_snapshot_path" else echo "Failed: Mismatch found between new $function_name logs (first) and snapshot (second):" echo "$diff_output" diff --git a/scripts/wait_for_complete_logs.sh b/scripts/wait_for_complete_logs.sh new file mode 100644 index 00000000..4ed2157f --- /dev/null +++ b/scripts/wait_for_complete_logs.sh @@ -0,0 +1,63 @@ +#!/bin/bash + +function wait_for_complete_logs() { + if [ "$#" -lt 4 ]; then + echo "wait_for_complete_logs requires an expected count, attempts, interval, and command" >&2 + return 2 + fi + + local expected_completion_count=$1 + local max_attempts=$2 + local interval_seconds=$3 + shift 3 + + case "$expected_completion_count" in + ''|*[!0-9]*|0) + echo "Expected completion count must be a positive integer" >&2 + return 2 + ;; + esac + case "$max_attempts" in + ''|*[!0-9]*|0) + echo "Maximum attempts must be a positive integer" >&2 + return 2 + ;; + esac + case "$interval_seconds" in + ''|*[!0-9]*) + echo "Retry interval must be a non-negative integer" >&2 + return 2 + ;; + esac + + local attempt=1 + local command_status=0 + local raw_logs='' + local completion_count=0 + + while [ "$attempt" -le "$max_attempts" ]; do + completion_count=0 + if raw_logs=$("$@" 2>&1); then + completion_count=$(printf '%s\n' "$raw_logs" | grep -c '^END Duration:' || true) + if [ "$completion_count" -ge "$expected_completion_count" ]; then + printf '%s\n' "$raw_logs" + return 0 + fi + echo "Waiting for complete logs: attempt $attempt/$max_attempts found $completion_count of" \ + "$expected_completion_count completion records" >&2 + else + command_status=$? + echo "Log command attempt $attempt/$max_attempts failed with exit code $command_status" >&2 + fi + + if [ "$attempt" -lt "$max_attempts" ]; then + sleep "$interval_seconds" + fi + attempt=$((attempt + 1)) + done + + echo "FAILURE: Logs remained incomplete after $max_attempts attempts; found $completion_count of" \ + "$expected_completion_count completion records" >&2 + printf '%s\n' "$raw_logs" | tail -30 >&2 + return 1 +} diff --git a/src/integration-log-scripts.spec.ts b/src/integration-log-scripts.spec.ts new file mode 100644 index 00000000..efe5ba67 --- /dev/null +++ b/src/integration-log-scripts.spec.ts @@ -0,0 +1,391 @@ +import { spawnSync, SpawnSyncReturns } from "node:child_process"; +import { chmodSync, cpSync, mkdirSync, mkdtempSync, readFileSync, rmSync, writeFileSync } from "node:fs"; +import { tmpdir } from "node:os"; +import { join } from "node:path"; + +const repoPath = join(__dirname, ".."); +const normalizerPath = join(repoPath, "scripts", "normalize_integration_logs.sh"); +const readinessPath = join(repoPath, "scripts", "wait_for_complete_logs.sh"); +const runnerPath = join(repoPath, "scripts", "run_integration_tests.sh"); +const waitInvocation = 'source "$1"; shift; wait_for_complete_logs "$@"'; + +const standardLogs = [ + JSON.stringify({ + meta: { + cold_start: "true", + service: "checkout", + }, + metrics: { + stable: 1, + }, + tags: ["cold_start:true"], + }), + "END Duration: 12.34 ms Memory Used: 128 MB", +].join("\n"); + +const proactiveLogs = [ + "INIT_START Runtime Version: nodejs:22.v1", + JSON.stringify({ + meta: { + cold_start: "false", + proactive_initialization: 1, + service: "checkout", + }, + metrics: { + proactive_initialization: 1, + stable: 1, + }, + tags: ["proactive_initialization:true", "cold_start:false"], + }), + "END Duration: 12.34 ms Memory Used: 128 MB (init: 42.1 ms)", +].join("\n"); + +const rieVolatileLogs = [ + 'mock-http saw headers: {"x-datadog-trace-id":"123","x-datadog-parent-id":"456","traceparent":"00-abc-def-01","tracestate":"dd=s:1"}', + '2026-09-02T01:30:00.000Z\trequest-id\tERROR\t(node:123) TimeoutOverflowWarning: 2147483648', + JSON.stringify({ requestId: "12345678-1234-1234-1234-123456789abc", "dns.addresses": "172.18.0.4" }), + "LocalProcessSupervisor.Exec pid=123", + "(Use `node --trace-warnings ...` to show where the warning was created)", +].join("\n"); + +/** + * @param input raw Lambda logs + * @param platform integration-test platform + * @param runId optional deployment run ID + * @param inputFormat raw logs or formatted snapshot input + */ +function normalize( + input: string, + platform: "aws" | "rie", + runId?: string, + inputFormat: "raw" | "formatted" = "raw", +): string { + const result = spawnSync(normalizerPath, [platform, inputFormat], { + encoding: "utf8", + env: { + ...process.env, + RUN_ID: runId ?? "", + }, + input, + }); + + expect(result.status).toBe(0); + return result.stdout; +} + +/** + * @param expectedCompletionCount required Serverless completion records + * @param maxAttempts maximum command attempts + * @param retryIntervalSeconds delay between attempts + * @param command command and arguments that fetch logs + */ +function waitForCompleteLogs( + expectedCompletionCount: number, + maxAttempts: number, + retryIntervalSeconds: number, + command: string[], +): SpawnSyncReturns { + return spawnSync( + "bash", + [ + "-c", + waitInvocation, + "wait-for-complete-logs", + readinessPath, + String(expectedCompletionCount), + String(maxAttempts), + String(retryIntervalSeconds), + ...command, + ], + { encoding: "utf8" }, + ); +} + +describe("integration log normalization", () => { + it("normalizes AWS scheduling differences", () => { + const normalizedProactiveLogs = normalize(proactiveLogs, "aws"); + + expect(normalizedProactiveLogs).not.toContain("INIT_START"); + expect(normalizedProactiveLogs).not.toContain("proactive_initialization"); + expect(normalizedProactiveLogs).not.toContain("cold_start:false"); + expect(normalizedProactiveLogs).toContain('"cold_start": "XXXX"'); + expect(normalizedProactiveLogs).toContain("cold_start:XXXX"); + expect(normalizedProactiveLogs).toBe(normalize(standardLogs, "aws")); + expect(normalize(`\n${standardLogs}`, "aws")).toBe(normalize(standardLogs, "aws")); + }); + + it("preserves deterministic RIE cold-start output", () => { + const normalizedProactiveLogs = normalize(proactiveLogs, "rie"); + + expect(normalizedProactiveLogs).not.toContain("proactive_initialization"); + expect(normalizedProactiveLogs).toContain('"cold_start": "false"'); + expect(normalizedProactiveLogs).toContain("cold_start:false"); + expect(normalizedProactiveLogs).not.toBe(normalize(standardLogs, "rie")); + }); + + it("preserves stable telemetry differences", () => { + const changedLogs = standardLogs.replace("checkout", "payments"); + + expect(normalize(changedLogs, "aws")).not.toBe(normalize(standardLogs, "aws")); + }); + + it("does not reformat formatted snapshots", () => { + const normalizedLogs = normalize(JSON.stringify({ tags: ["runtime:nodejs18.x"] }), "aws"); + + expect(normalize(normalizedLogs, "aws", undefined, "formatted")).toBe(normalizedLogs); + }); + + it("normalizes RIE-specific volatile values", () => { + const normalizedLogs = normalize(rieVolatileLogs, "rie"); + + expect(normalizedLogs).toContain('"x-datadog-trace-id":"XXXX"'); + expect(normalizedLogs).toContain('"x-datadog-parent-id":"XXXX"'); + expect(normalizedLogs).toContain('"traceparent":"XXXX"'); + expect(normalizedLogs).toContain('"tracestate":"XXXX"'); + expect(normalizedLogs).toContain("XXXX-XX-XXTXX:XX:XX.XXXZ"); + expect(normalizedLogs).toContain("(node:XX) TimeoutOverflowWarning: XXXX"); + expect(normalizedLogs).toContain('"requestId": "XXXX"'); + expect(normalizedLogs).toContain('"dns.addresses": "XXXX"'); + expect(normalizedLogs).toContain("LocalProcessSupervisor.Exec pid=XX"); + expect(normalizedLogs).not.toContain("trace-warnings"); + }); + + it("strips a literal run ID", () => { + const runId = "id.with+characters"; + + expect(normalize("function-" + runId, "aws", runId)).toContain("function-XXXX"); + }); + + it("rejects an unsupported platform", () => { + const result = spawnSync(normalizerPath, ["azure"], { + encoding: "utf8", + input: standardLogs, + }); + + expect(result.status).toBe(2); + expect(result.stderr).toContain("Unsupported integration-test platform: azure"); + }); + + it("requires a platform", () => { + const result = spawnSync(normalizerPath, [], { + encoding: "utf8", + input: standardLogs, + }); + + expect(result.status).toBe(2); + expect(result.stderr).toContain("Usage:"); + }); + + it("rejects an unsupported log format", () => { + const result = spawnSync(normalizerPath, ["aws", "compact"], { + encoding: "utf8", + input: standardLogs, + }); + + expect(result.status).toBe(2); + expect(result.stderr).toContain("Unsupported integration-test log format: compact"); + }); +}); + +describe("integration log readiness", () => { + it("keeps successful command diagnostics out of returned logs", () => { + const producer = ["bash", "-c", "printf 'serverless warning\\n' >&2; printf 'END Duration: 1 ms\\n'"]; + const result = waitForCompleteLogs(1, 1, 0, producer); + + expect(result.status).toBe(0); + expect(result.stdout).toBe("END Duration: 1 ms\n"); + expect(result.stderr).toContain("serverless warning"); + }); + + it("retries command failures and incomplete results", () => { + const temporaryDirectory = mkdtempSync(join(tmpdir(), "lambda-log-wait-")); + const attemptPath = join(temporaryDirectory, "attempt"); + const producerScript = [ + "attempt=0", + 'if [ -f "$1" ]; then', + ' read -r attempt < "$1"', + "fi", + "attempt=$((attempt + 1))", + 'printf \'%s\\n\' "$attempt" > "$1"', + 'if [ "$attempt" -eq 1 ]; then', + " printf 'temporary failure\\n' >&2", + " exit 7", + "fi", + "printf 'END Duration: 1 ms\\n'", + 'if [ "$attempt" -ge 3 ]; then', + " printf 'END Duration: 1 ms\\n'", + "fi", + ].join("\n"); + const producer = ["bash", "-c", producerScript, "log-producer", attemptPath]; + + try { + const result = waitForCompleteLogs(2, 3, 0, producer); + + expect(result.status).toBe(0); + expect(result.stdout).toBe("END Duration: 1 ms\nEND Duration: 1 ms\n"); + expect(result.stderr).toContain("attempt 1/3 failed with exit code 7"); + expect(result.stderr).toContain("attempt 2/3 found 1 of 2 completion records"); + } finally { + rmSync(temporaryDirectory, { force: true, recursive: true }); + } + }); + + it("fails after the final command error", () => { + const result = waitForCompleteLogs(1, 2, 0, ["bash", "-c", "printf 'no logs\\n' >&2; exit 4"]); + + expect(result.status).toBe(1); + expect(result.stderr).toContain("attempt 2/2 failed with exit code 4"); + expect(result.stderr).toContain("Logs remained incomplete after 2 attempts"); + }); + + it("fails after the final incomplete result", () => { + const result = waitForCompleteLogs(2, 1, 0, ["printf", "END Duration: 1 ms\n"]); + + expect(result.status).toBe(1); + expect(result.stderr).toContain("found 1 of 2 completion records"); + }); + + it("rejects a zero expected completion count", () => { + const result = waitForCompleteLogs(0, 1, 0, ["true"]); + + expect(result.status).toBe(2); + expect(result.stderr).toContain("Expected completion count must be a positive integer"); + }); + + it("rejects a zero maximum attempt count", () => { + const result = waitForCompleteLogs(1, 0, 0, ["true"]); + + expect(result.status).toBe(2); + expect(result.stderr).toContain("Maximum attempts must be a positive integer"); + }); + + it("rejects a negative retry interval", () => { + const result = waitForCompleteLogs(1, 1, -1, ["true"]); + + expect(result.status).toBe(2); + expect(result.stderr).toContain("Retry interval must be a non-negative integer"); + }); + + it("requires a log command", () => { + const result = waitForCompleteLogs(1, 1, 0, []); + + expect(result.status).toBe(2); + expect(result.stderr).toContain("requires an expected count, attempts, interval, and command"); + }); +}); + +describe("integration test runner", () => { + it("keeps script paths valid after changing directories", () => { + const temporaryDirectory = mkdtempSync(join(tmpdir(), "lambda-integration-runner-")); + const temporaryRepo = join(temporaryDirectory, "repo"); + const temporaryScripts = join(temporaryRepo, "scripts"); + const temporaryIntegrationTests = join(temporaryRepo, "integration_tests"); + const temporaryBin = join(temporaryDirectory, "bin"); + const normalizerArgumentsPath = join(temporaryDirectory, "normalizer-arguments"); + const handlerNames = [ + "async-metrics", + "esm", + "sync-metrics", + "http-requests", + "process-input-traced", + "throw-error-traced", + "status-code-500s", + "container-cjs", + "container-esm", + ]; + + mkdirSync(temporaryScripts, { recursive: true }); + mkdirSync(join(temporaryIntegrationTests, "input_events"), { recursive: true }); + mkdirSync(join(temporaryIntegrationTests, "snapshots", "logs"), { recursive: true }); + mkdirSync(join(temporaryIntegrationTests, "snapshots", "return_values"), { recursive: true }); + mkdirSync(temporaryBin); + cpSync(runnerPath, join(temporaryScripts, "run_integration_tests.sh")); + cpSync(readinessPath, join(temporaryScripts, "wait_for_complete_logs.sh")); + cpSync( + join(repoPath, "integration_tests", "input_events", "api-gateway-get.json"), + join(temporaryIntegrationTests, "input_events", "api-gateway-get.json"), + ); + cpSync(join(repoPath, "integration_tests", "parse-json.js"), join(temporaryIntegrationTests, "parse-json.js")); + mkdirSync(join(temporaryIntegrationTests, "container", "cjs"), { recursive: true }); + mkdirSync(join(temporaryIntegrationTests, "container", "esm"), { recursive: true }); + for (const handlerName of handlerNames) { + cpSync( + join(repoPath, "integration_tests", "snapshots", "logs", `${handlerName}_node18.log`), + join(temporaryIntegrationTests, "snapshots", "logs", `${handlerName}_node18.log`), + ); + cpSync( + join(repoPath, "integration_tests", "snapshots", "return_values", `${handlerName}_node18_api-gateway-get.json`), + join(temporaryIntegrationTests, "snapshots", "return_values", `${handlerName}_node18_api-gateway-get.json`), + ); + } + + const commandStub = ["#!/bin/bash", "exit 0", ""].join("\n"); + const normalizerStub = ["#!/bin/bash", 'printf "%s\\n" "$*" >> "$NORMALIZER_ARGUMENTS"', "cat", ""].join("\n"); + const npmStub = ["#!/bin/bash", "touch datadog-lambda-js-test.tgz", ""].join("\n"); + const xxdStub = ["#!/bin/bash", 'printf "01234567\\n"', ""].join("\n"); + const serverlessStub = [ + "#!/bin/bash", + 'command="$1"', + "shift", + 'if [ "$command" = "deploy" ] || [ "$command" = "remove" ]; then', + " exit 0", + "fi", + 'while [ "$#" -gt 0 ]; do', + ' case "$1" in', + " -f)", + ' function_name="$2"', + " shift 2", + " ;;", + " --path)", + ' input_path="$2"', + " shift 2", + " ;;", + " *)", + " shift", + " ;;", + " esac", + "done", + 'handler_name="${function_name%_node}"', + 'if [ "$command" = "invoke" ]; then', + ' input_name="$(basename "${input_path%.json}")"', + ' cat "./snapshots/return_values/${handler_name}_${RUNTIME}_${input_name}.json"', + "else", + ' cat "./snapshots/logs/${handler_name}_${RUNTIME}.log"', + "fi", + "", + ].join("\n"); + + writeFileSync(join(temporaryScripts, "normalize_integration_logs.sh"), normalizerStub); + writeFileSync(join(temporaryBin, "yarn"), commandStub); + writeFileSync(join(temporaryBin, "npm"), npmStub); + writeFileSync(join(temporaryBin, "serverless"), serverlessStub); + writeFileSync(join(temporaryBin, "xxd"), xxdStub); + chmodSync(join(temporaryBin, "yarn"), 0o755); + chmodSync(join(temporaryBin, "npm"), 0o755); + chmodSync(join(temporaryBin, "serverless"), 0o755); + chmodSync(join(temporaryBin, "xxd"), 0o755); + chmodSync(join(temporaryScripts, "normalize_integration_logs.sh"), 0o755); + + try { + const result = spawnSync("./scripts/run_integration_tests.sh", [], { + cwd: temporaryRepo, + encoding: "utf8", + env: { + ...process.env, + AWS_SECRET_ACCESS_KEY: "test", + DD_API_KEY: "test", + NORMALIZER_ARGUMENTS: normalizerArgumentsPath, + PATH: `${temporaryBin}:${process.env.PATH}`, + RUNTIME_PARAM: "18", + }, + }); + + expect(result.status).toBe(0); + expect(result.stderr).toBe(""); + expect(result.stdout).toContain("SUCCESS: No difference found between snapshots and new return values or logs"); + expect(readFileSync(normalizerArgumentsPath, "utf8")).toContain("aws formatted\n"); + } finally { + rmSync(temporaryDirectory, { force: true, recursive: true }); + } + }); +}); diff --git a/src/metrics/enhanced-metrics.spec.ts b/src/metrics/enhanced-metrics.spec.ts index f8ac9ddc..cbf87214 100644 --- a/src/metrics/enhanced-metrics.spec.ts +++ b/src/metrics/enhanced-metrics.spec.ts @@ -1,5 +1,5 @@ import { Context } from "aws-lambda"; -import { _resetColdStart } from "../utils/cold-start"; +import { _resetColdStart, setSandboxInit } from "../utils/cold-start"; import { getProcessVersion } from "../utils/process-version"; import { getEnhancedMetricTags, getRuntimeTag } from "./enhanced-metrics"; @@ -83,6 +83,22 @@ describe("getEnhancedMetricTags", () => { ]); }); + it("generates tag list for proactive initialization", () => { + setSandboxInit(0, 10_001); + mockedGetProcessVersion.mockReturnValue("v20.19.0"); + expect(getEnhancedMetricTags(mockContext)).toStrictEqual([ + "region:us-east-1", + "account_id:123497598159", + "functionname:my-test-lambda", + "resource:my-test-lambda", + "memorysize:128", + "cold_start:false", + "proactive_initialization:true", + "datadog_lambda:vX.X.X", + "runtime:nodejs20.x", + ]); + }); + it("doesn't add runtime tag if version is unrecognized", () => { mockedGetProcessVersion.mockReturnValue("v6.3.2"); expect(getEnhancedMetricTags(mockContext)).toStrictEqual([ diff --git a/src/trace/listener.spec.ts b/src/trace/listener.spec.ts index 9cede1f8..42572b77 100644 --- a/src/trace/listener.spec.ts +++ b/src/trace/listener.spec.ts @@ -12,6 +12,7 @@ import { DATADOG_TRACE_ID_HEADER, } from "./context/extractor"; import { TracerWrapper } from "./tracer-wrapper"; +import { _resetColdStart, setSandboxInit } from "../utils/cold-start"; const mockProcessAppsecRequest = jest.fn(); const mockProcessAppsecResponse = jest.fn(); @@ -96,6 +97,7 @@ describe("TraceListener", () => { invokedFunctionArn: "arn:aws:lambda:us-east-1:123456789101:function:my-lambda:1", }; beforeEach(() => { + _resetColdStart(); wrapSpy.mockClear(); mockProcessAppsecRequest.mockClear(); mockProcessAppsecResponse.mockClear(); @@ -108,6 +110,7 @@ describe("TraceListener", () => { }); afterEach(() => { + _resetColdStart(); process.env = oldEnv; }); @@ -141,6 +144,20 @@ describe("TraceListener", () => { ); }); + it("tags proactive initialization on the wrapped span", async () => { + setSandboxInit(0, 10_001); + const listener = new TraceListener(defaultConfig); + await listener.onStartInvocation({}, context as any); + const unwrappedFunc = () => {}; + const wrappedFunc = listener.onWrap(unwrappedFunc); + wrappedFunc(); + await listener.onCompleteInvocation(); + + const options = wrapSpy.mock.calls[0][1]; + expect(options.tags?.cold_start).toBe("false"); + expect(options.tags?.proactive_initialization).toBe(true); + }); + it("wraps dd-trace span around invocation, with trace context from event", async () => { const listener = new TraceListener(defaultConfig); mockController.mockTraceSource = TraceSource.Event; From 8145ef116f3de670325071a677e65c65cc76333b Mon Sep 17 00:00:00 2001 From: Ruben Bridgewater Date: Tue, 1 Sep 2026 17:48:59 +0200 Subject: [PATCH 2/4] ci(integration): fix runner helper resolution 1. A relative runner invocation leaves its helper directory relative, so later directory changes make every log normalization call miss the executable. 2. Successful Serverless diagnostics entered the log payload and could produce false snapshot mismatches. --- scripts/run_integration_tests.sh | 3 +-- scripts/wait_for_complete_logs.sh | 2 +- 2 files changed, 2 insertions(+), 3 deletions(-) diff --git a/scripts/run_integration_tests.sh b/scripts/run_integration_tests.sh index 5fc96960..fe35b564 100755 --- a/scripts/run_integration_tests.sh +++ b/scripts/run_integration_tests.sh @@ -30,8 +30,7 @@ ZIP_LAMBDA_HANDLERS=("async-metrics" "esm" "sync-metrics" "http-requests" "proce LOG_FETCH_ATTEMPTS=10 LOG_FETCH_INTERVAL_SECONDS=10 -script_path=${BASH_SOURCE[0]} -scripts_dir=$(dirname "$script_path") +scripts_dir=$(cd "$(dirname "${BASH_SOURCE[0]}")" && pwd) repo_dir=$(dirname "$scripts_dir") cwd=$(pwd) diff --git a/scripts/wait_for_complete_logs.sh b/scripts/wait_for_complete_logs.sh index 4ed2157f..9f364eff 100644 --- a/scripts/wait_for_complete_logs.sh +++ b/scripts/wait_for_complete_logs.sh @@ -37,7 +37,7 @@ function wait_for_complete_logs() { while [ "$attempt" -le "$max_attempts" ]; do completion_count=0 - if raw_logs=$("$@" 2>&1); then + if raw_logs=$("$@"); then completion_count=$(printf '%s\n' "$raw_logs" | grep -c '^END Duration:' || true) if [ "$completion_count" -ge "$expected_completion_count" ]; then printf '%s\n' "$raw_logs" From f6cfa6bae1e37d18dadbd8529697d6a062219923 Mon Sep 17 00:00:00 2001 From: Ruben Bridgewater Date: Tue, 1 Sep 2026 18:16:37 +0200 Subject: [PATCH 3/4] ci(integration): normalize historical snapshot padding The former `INIT_START` substitution left an empty line in stored zip snapshots, so current output that deletes the whole line failed every zip-handler comparison. --- scripts/normalize_integration_logs.sh | 3 +++ 1 file changed, 3 insertions(+) diff --git a/scripts/normalize_integration_logs.sh b/scripts/normalize_integration_logs.sh index a42e4ce3..5128ff83 100755 --- a/scripts/normalize_integration_logs.sh +++ b/scripts/normalize_integration_logs.sh @@ -12,9 +12,11 @@ case "$platform" in aws) cold_start_filter="s/(\"cold_start\":[[:space:]]*)\"(?:true|false)\"/\$1\"XXXX\"/g" cold_start_filter+="; s/cold_start:(?:true|false)/cold_start:XXXX/g" + leading_blank_filter='/./,$!d' ;; rie) cold_start_filter='' + leading_blank_filter='' ;; *) echo "Unsupported integration-test platform: $platform" >&2 @@ -77,6 +79,7 @@ fi | perl -p -e 's/("resource":"169.)[0-9\.]+/$1X.X.X/g' | perl -p -e 's/User-Agent:axios\/\d+\.\d+\.\d+/User-Agent:axios\/X.X.X/g' | sed '/INIT_START Runtime Version:/d' | + sed "$leading_blank_filter" | sed -E '/^[[:space:]]*"proactive_initialization(" *:|:true")/d' | perl -p -e "$cold_start_filter" | perl -p -e 's/ \(init: [^)]*\)//g' | From b5045c6f66dda0bb0db19a480b3b917ea61964f1 Mon Sep 17 00:00:00 2001 From: Ruben Bridgewater Date: Wed, 2 Sep 2026 18:10:53 +0200 Subject: [PATCH 4/4] ci(integration): fix normalizer references and formatting --- integration_tests_local/README.md | 17 ++++++++--------- integration_tests_local/run.sh | 8 ++++---- src/integration-log-scripts.spec.ts | 2 +- 3 files changed, 13 insertions(+), 14 deletions(-) diff --git a/integration_tests_local/README.md b/integration_tests_local/README.md index 08e25dc9..026baa9c 100644 --- a/integration_tests_local/README.md +++ b/integration_tests_local/README.md @@ -6,9 +6,9 @@ manual-wrap handlers, plus targeted feature cases (HTTP header injection, custom trace extractors, proactive initialization) — inside Docker against the [AWS Lambda Runtime Interface Emulator (RIE)](https://github.com/aws/aws-lambda-runtime-interface-emulator), invokes them with the same input events as the AWS-based suite, captures -logs from `docker logs`, normalizes them with `./normalize.sh` — the AWS -suite's filter chain plus documented RIE-specific handling, not an identical -copy — and diffs them against **local** snapshots in `./snapshots/`. +logs from `docker logs`, normalizes them with the `rie` mode of +`../scripts/normalize_integration_logs.sh`, and diffs them against **local** +snapshots in `./snapshots/`. The case set is deliberately at least as wide as the AWS-based suite (`integration_tests/serverless.yml`): every behavior the old suite pinned @@ -220,16 +220,15 @@ genuinely diverges (error stack frames, warning emission) it carries When AWS publishes the bare Node 26 GA image, swap the pinned tag and re-run. If GA output diverges further, add `*_node26` overrides captured from the -pinned pre-migration ref rather than absorbing the difference into -`normalize.sh` — the oracle is tied to the implementation under test, and a -base-image change must be reviewed, not hidden by normalization. +pinned pre-migration ref. Do not absorb the difference into the shared +integration-log normalizer because the oracle is tied to the implementation +under test. A base-image change must be reviewed, not hidden by normalization. ## Files - `run.sh` — the runner (build images, run under RIE, invoke, diff snapshots) -- `normalize.sh` — the local log-normalization pipeline, based on the AWS - suite's filters with documented RIE-specific handling. Reads stdin, writes - stdout; honors `RUN_ID` for optional per-run ID stripping. +- `../scripts/normalize_integration_logs.sh` — the shared AWS/RIE log normalizer. + Reads stdin, writes stdout; honors `RUN_ID` for optional per-run ID stripping. - `prepare-layer.js` — assembles the layer fixture's build context from the repo build, mirroring the release Dockerfile's `/opt` layout - `bin/` — downloaded RIE binary (gitignored) diff --git a/integration_tests_local/run.sh b/integration_tests_local/run.sh index 60aef96b..038e9a35 100755 --- a/integration_tests_local/run.sh +++ b/integration_tests_local/run.sh @@ -4,7 +4,7 @@ # # Runs the test cases below against the AWS Runtime Interface Emulator (RIE) # — no AWS account needed. Logs are captured from `docker logs`, normalized -# with ./normalize.sh, and diffed against LOCAL snapshots in ./snapshots/ +# with the `rie` mode of scripts/normalize_integration_logs.sh, and diffed against LOCAL snapshots in ./snapshots/ # (not integration_tests/snapshots/). # # The case set is deliberately at least as wide as the AWS-based suite in @@ -432,7 +432,7 @@ function compare_snapshot() { local diff_status if [ "$sort_lines" = true ]; then - # Preserve normalized whitespace; normalize.sh removes RIE's REPORT tab. + # Preserve normalized whitespace; the shared normalizer removes RIE's REPORT tab. diff_output=$(printf '%s\n' "$actual" | LC_ALL=C sort | diff - <(LC_ALL=C sort "$snapshot_path")) else diff_output=$(printf '%s\n' "$actual" | diff - "$snapshot_path") @@ -724,7 +724,7 @@ for node_version in "${RUNTIMES[@]}"; do continue fi - # Proactive initialization is platform scheduling, so normalize.sh + # Proactive initialization is platform scheduling, so the shared normalizer # drops the markers. For the dedicated case we assert them against the # raw log before normalization, which keeps the coverage without # weakening the shared pipeline. @@ -762,7 +762,7 @@ for node_version in "${RUNTIMES[@]}"; do # Same assert-then-collapse for the dd_lambda_layer tag (emitted by the # manual-wrap cases): the node major in the tag must match the runtime - # under test. normalize.sh already collapses minor/patch to XX.X; + # under test. The shared normalizer already collapses minor/patch to XX.X; # after this guard passes, the major collapses to XX as well, so the # shared golden reads datadog-nodevXX.XX.X. layer_majors=$(printf '%s\n' "$logs" | grep -o 'dd_lambda_layer:datadog-nodev[0-9]*' | sed 's/.*datadog-nodev//' | sort -u || true) diff --git a/src/integration-log-scripts.spec.ts b/src/integration-log-scripts.spec.ts index efe5ba67..83e96c65 100644 --- a/src/integration-log-scripts.spec.ts +++ b/src/integration-log-scripts.spec.ts @@ -42,7 +42,7 @@ const proactiveLogs = [ const rieVolatileLogs = [ 'mock-http saw headers: {"x-datadog-trace-id":"123","x-datadog-parent-id":"456","traceparent":"00-abc-def-01","tracestate":"dd=s:1"}', - '2026-09-02T01:30:00.000Z\trequest-id\tERROR\t(node:123) TimeoutOverflowWarning: 2147483648', + "2026-09-02T01:30:00.000Z\trequest-id\tERROR\t(node:123) TimeoutOverflowWarning: 2147483648", JSON.stringify({ requestId: "12345678-1234-1234-1234-123456789abc", "dns.addresses": "172.18.0.4" }), "LocalProcessSupervisor.Exec pid=123", "(Use `node --trace-warnings ...` to show where the warning was created)",