diff --git a/.github/workflows/pr-checks.yml b/.github/workflows/pr-checks.yml index 69bc0e37..6a13381f 100644 --- a/.github/workflows/pr-checks.yml +++ b/.github/workflows/pr-checks.yml @@ -19,6 +19,8 @@ jobs: runs-on: ubuntu-24.04 steps: - uses: actions/checkout@v4 + with: + submodules: true # catalog-tracing-sh — the tracing SDK the tests exercise - name: Install dependencies run: sudo apt-get update && sudo apt-get install -y bats jq diff --git a/.gitmodules b/.gitmodules new file mode 100644 index 00000000..7c2e3258 --- /dev/null +++ b/.gitmodules @@ -0,0 +1,4 @@ +[submodule "vendor/catalog-tracing-sh"] + path = vendor/catalog-tracing-sh + url = https://github.com/nullplatform/catalog-tracing-sh.git + branch = main diff --git a/azure-aro/values.yaml b/azure-aro/values.yaml index 7ff585b6..84d62b20 100644 --- a/azure-aro/values.yaml +++ b/azure-aro/values.yaml @@ -1,5 +1,6 @@ configuration: DNS_TYPE: azure + K8S_FLAVOR: aro USE_ACCOUNT_SLUG: false IMAGE_PULL_SECRETS: ENABLED: false diff --git a/azure/values.yaml b/azure/values.yaml index 0c3d54b9..52a58c4c 100644 --- a/azure/values.yaml +++ b/azure/values.yaml @@ -1,5 +1,6 @@ configuration: DNS_TYPE: azure + K8S_FLAVOR: aks USE_ACCOUNT_SLUG: false IMAGE_PULL_SECRETS: ENABLED: false diff --git a/k8s/apply_templates b/k8s/apply_templates index 3a5dfaa4..3508b9da 100644 --- a/k8s/apply_templates +++ b/k8s/apply_templates @@ -31,9 +31,39 @@ while IFS= read -r TEMPLATE_FILE; do IGNORE_NOT_FOUND="--ignore-not-found=true" fi - if ! kubectl "$ACTION" -f "$TEMPLATE_FILE" $IGNORE_NOT_FOUND; then - log error " ❌ Failed to apply" + TRACE_STEP_KEY="" + if [[ "$ACTION" == "apply" ]] && command -v np_scope_step_begin >/dev/null 2>&1; then + case "$FILENAME" in + deployment-*) TRACE_STEP_KEY="create-deployment" ;; + secret-*) TRACE_STEP_KEY="create-secret" ;; + scaling-*) TRACE_STEP_KEY="create-hpa" ;; + service-*) TRACE_STEP_KEY="create-service" ;; + pdb-*) TRACE_STEP_KEY="create-pod-disruption-budget" ;; + ingress-*) + if [[ -n "${DEPLOYMENT_ID:-}" ]]; then + TRACE_STEP_KEY="configure-ingress" + else + TRACE_STEP_KEY="create-ingress" + fi ;; + esac + [[ -n "$TRACE_STEP_KEY" ]] && np_scope_step_begin "$TRACE_STEP_KEY" fi + + if KUBECTL_OUT=$(kubectl "$ACTION" -f "$TEMPLATE_FILE" $IGNORE_NOT_FOUND 2>&1); then + [[ -n "$KUBECTL_OUT" ]] && echo "$KUBECTL_OUT" + [[ -n "$TRACE_STEP_KEY" ]] && command -v np_scope_step_end >/dev/null 2>&1 && np_scope_step_end 0 + if [[ "$ACTION" == "apply" ]] && command -v np_scope_k8s_applied >/dev/null 2>&1; then + np_scope_k8s_applied "${K8S_NAMESPACE:-}" "$KUBECTL_OUT" + fi + if [[ "$ACTION" == "delete" ]] && command -v np_scope_k8s_deleted >/dev/null 2>&1; then + np_scope_k8s_deleted "${K8S_NAMESPACE:-}" "$KUBECTL_OUT" + fi + else + [[ -n "$KUBECTL_OUT" ]] && echo "$KUBECTL_OUT" >&2 + log error " ❌ Failed to apply $FILENAME${KUBECTL_OUT:+: $KUBECTL_OUT}" + [[ -n "$TRACE_STEP_KEY" ]] && command -v np_scope_step_end >/dev/null 2>&1 && np_scope_step_end 1 + fi + TRACE_STEP_KEY="" fi DEST_DIR="${BASE_DIR}/$ACTION" @@ -52,4 +82,23 @@ if [[ "$DRY_RUN" == "true" ]]; then exit 1 fi +if [[ "${TRACE_TRAFFIC_SWITCH:-false}" == "true" ]] && [[ -n "${CONTEXT:-}" ]] \ + && command -v np_scope_explain >/dev/null 2>&1; then + TRAFFIC_TO=$(echo "$CONTEXT" | jq -r '.deployment.strategy_data.desired_switched_traffic // 100') + TRAFFIC_FROM=$(echo "$CONTEXT" | jq -r '.deployment.strategy_data.switched_traffic // 0') + if [[ "$TRAFFIC_TO" =~ ^[0-9]+$ ]] && [[ "$TRAFFIC_FROM" =~ ^[0-9]+$ ]]; then + np_scope_labels "deployment.id=${DEPLOYMENT_ID:-}" "scope.id=${SCOPE_ID:-}" "action=traffic-switch" + np_scope_explain --title "Switch traffic for deployment ${DEPLOYMENT_ID:-}" \ + --what "Switching blue/green traffic for deployment ${DEPLOYMENT_ID:-} from ${TRAFFIC_FROM}% to ${TRAFFIC_TO}%" + np_scope_affordance "{\"kind\":\"traffic-switch\",\"deployment_id\":\"${DEPLOYMENT_ID:-}\",\"current_traffic\":$TRAFFIC_TO,\"new_traffic\":$TRAFFIC_TO,\"old_traffic\":$((100 - TRAFFIC_TO)),\"target_traffic\":100}" + np_scope_input traffic "{\"from\":$TRAFFIC_FROM,\"desired\":$TRAFFIC_TO}" + np_scope_output traffic "{\"switched\":$TRAFFIC_TO}" + np_scope_progress "$TRAFFIC_TO" 100 percent + fi +fi + +if command -v np_trace_flush >/dev/null 2>&1; then + NP_TRACE_FLUSH_TIMEOUT=5 np_trace_flush +fi + source "$SERVICE_PATH/backup/backup_templates" --action="$ACTION" --files "${APPLIED_FILES[@]}" diff --git a/k8s/deployment/print_failed_deployment_hints b/k8s/deployment/print_failed_deployment_hints index 33b08ff8..9527f37d 100644 --- a/k8s/deployment/print_failed_deployment_hints +++ b/k8s/deployment/print_failed_deployment_hints @@ -124,7 +124,12 @@ diagnose_failure() { if [[ -n "$pods_json" ]] && echo "$pods_json" | jq -e . >/dev/null 2>&1; then FAILURE_REASON=$(echo "$pods_json" | jq -r ' [.items[].status.containerStatuses[]? - | (.state.waiting.reason // .lastState.terminated.reason // empty) + | (.state.waiting.reason // "") as $w + | (.lastState.terminated.reason // "") as $t0 + | (if $t0 == "Completed" then "" else $t0 end) as $t + | (if ($w == "CrashLoopBackOff" or $w == "BackOff") and $t != "" then $t + elif $w != "" then $w + else $t end) ] | map(select(. != "" and . != "Completed")) | group_by(.) | max_by(length) | .[0] // empty' 2>/dev/null) @@ -181,13 +186,20 @@ diagnose_failure() { CrashLoopBackOff|BackOff) HUMAN_MESSAGE="The container started and crashed repeatedly." SUGGESTED_FIX="Review application logs for startup errors (failed dependencies, bad config, panics)." ;; + Error|ContainerStatusUnknown) + if [[ -n "$FAILURE_EXIT_CODE" ]]; then + HUMAN_MESSAGE="The container started and exited with code ${FAILURE_EXIT_CODE}." + else + HUMAN_MESSAGE="The container started and crashed repeatedly." + fi + SUGGESTED_FIX="Review application logs for startup errors (failed dependencies, bad config, panics)." ;; OOMKilled) if [[ -n "$req_memory" ]]; then HUMAN_MESSAGE="The container exceeded its memory limit (${req_memory}Mi) and was terminated." else HUMAN_MESSAGE="The container exceeded its memory limit and was terminated." fi - SUGGESTED_FIX="Increase ram_memory for scope '$scope_name' or reduce application memory usage." ;; + SUGGESTED_FIX="Raise the RAM Memory of scope '$scope_name', or reduce how much memory the application uses." ;; CreateContainerConfigError) HUMAN_MESSAGE="The container configuration is invalid." SUGGESTED_FIX="Check for missing secrets or configmaps referenced by the deployment." ;; @@ -223,18 +235,28 @@ diagnose_failure() { elif [[ "$UNHEALTHY_MESSAGE" =~ statuscode:[[:space:]]*([0-9]+) ]]; then SUGGESTED_FIX="The app responded with HTTP ${BASH_REMATCH[1]} on $health_check_path — inspect application logs for startup errors; the process is running but $health_check_path is not returning 2xx." elif [[ "$UNHEALTHY_MESSAGE" == *"context deadline exceeded"* || "$UNHEALTHY_MESSAGE" == *"Client.Timeout"* || "$UNHEALTHY_MESSAGE" == *"i/o timeout"* ]]; then - SUGGESTED_FIX="The probe timed out — the app may be slow to start or $health_check_path is blocking. Consider increasing startup probe initialDelaySeconds/timeoutSeconds, or making $health_check_path lighter." + SUGGESTED_FIX="The probe timed out — the app may be slow to start, or $health_check_path is blocking. Raise the health check's Initial Delay or Timeout on scope '$scope_name', or make $health_check_path lighter." else SUGGESTED_FIX="Ensure the app listens on port 8080 and returns 2xx on $health_check_path within the readiness window." fi ;; FailedCreate|FailedCreatePodSandBox) HUMAN_MESSAGE="Kubernetes could not create the pod sandbox." SUGGESTED_FIX="Check node health, CNI configuration, and pod security policies." ;; + Evicted) + HUMAN_MESSAGE="The pod was evicted from its node." + SUGGESTED_FIX="The node ran out of memory or disk. Lower the scope's resource requests, or free capacity on the cluster." ;; + Unschedulable) + HUMAN_MESSAGE="No node can accept the pod." + SUGGESTED_FIX="Reduce requested resources, free cluster capacity, or review nodeSelector/affinity rules." ;; + DeadlineExceeded) + HUMAN_MESSAGE="The pod ran past its active deadline and was stopped." + SUGGESTED_FIX="Find why the workload runs longer than the deadline it was given, or allow it more time." ;; "") HUMAN_MESSAGE="" SUGGESTED_FIX="" ;; *) HUMAN_MESSAGE="Pods are failing with reason: $FAILURE_REASON" + # Empty on purpose: an empty fix routes the reader to the generic checklist below. SUGGESTED_FIX="" ;; esac } diff --git a/k8s/deployment/scale_deployments b/k8s/deployment/scale_deployments index 9e703eed..8ff15df3 100755 --- a/k8s/deployment/scale_deployments +++ b/k8s/deployment/scale_deployments @@ -7,6 +7,12 @@ GREEN_DEPLOYMENT_ID=$DEPLOYMENT_ID BLUE_REPLICAS=$(echo "$CONTEXT" | jq -r .blue_replicas) BLUE_DEPLOYMENT_ID=$(echo "$CONTEXT" | jq .scope.current_active_deployment -r) +if [ "$DEPLOY_STRATEGY" != "rolling" ]; then + if command -v np_step_skip >/dev/null 2>&1; then + np_step_skip "instance counts are set by the manifests for the $DEPLOY_STRATEGY strategy — nothing to scale" + fi +fi + if [ "$DEPLOY_STRATEGY" = "rolling" ]; then GREEN_DEPLOYMENT_NAME="d-$SCOPE_ID-$GREEN_DEPLOYMENT_ID" BLUE_DEPLOYMENT_NAME="d-$SCOPE_ID-$BLUE_DEPLOYMENT_ID" @@ -41,6 +47,10 @@ if [ "$DEPLOY_STRATEGY" = "rolling" ]; then unset TIMEOUT unset SKIP_DEPLOYMENT_STATUS_CHECK + if command -v np_scope_output >/dev/null 2>&1; then + np_scope_output replicas "{\"green\": $GREEN_REPLICAS, \"previous\": $BLUE_REPLICAS}" + fi + log debug "" log info "✨ Deployments scaled successfully" fi diff --git a/k8s/deployment/tests/print_failed_deployment_hints.bats b/k8s/deployment/tests/print_failed_deployment_hints.bats index aae55005..aea603ce 100644 --- a/k8s/deployment/tests/print_failed_deployment_hints.bats +++ b/k8s/deployment/tests/print_failed_deployment_hints.bats @@ -83,7 +83,8 @@ assert_not_contains() { assert_contains "$output" "📋 Reason: The container exceeded its memory limit (512Mi)" assert_contains "$output" "📋 Detected: OOMKilled on container app (exit 137)" assert_contains "$output" "📋 Details: out of memory" - assert_contains "$output" "💡 Suggested fix: Increase ram_memory for scope 'my-app'" + assert_contains "$output" "💡 Suggested fix: Raise the RAM Memory of scope 'my-app'" + assert_not_contains "$output" "ram_memory" assert_not_contains "$output" "⚠️ Application Startup Issue Detected" } @@ -229,8 +230,9 @@ assert_not_contains() { run bash "$BATS_TEST_DIRNAME/../print_failed_deployment_hints" [ "$status" -eq 0 ] - assert_contains "$output" "did not pass its health check at /health" - assert_contains "$output" "💡 Suggested fix: Ensure the app listens on port 8080 and returns 2xx on /health" + assert_contains "$output" "📋 Reason: The application did not pass its health check at /health." + assert_contains "$output" "📋 Detected: Unhealthy on container api" + assert_contains "$output" "💡 Suggested fix: Ensure the app listens on port 8080 and returns 2xx on /health within the readiness window." assert_not_contains "$output" "⚠️ Application Startup Issue Detected" } @@ -250,13 +252,11 @@ assert_not_contains() { run bash "$BATS_TEST_DIRNAME/../print_failed_deployment_hints" [ "$status" -eq 0 ] - # HUMAN_MESSAGE retains the base sentence and appends the translated probe failure - assert_contains "$output" "did not pass its health check at /health" - assert_contains "$output" "Detected: Startup probe" - assert_contains "$output" "not yet listening" - # SUGGESTED_FIX is targeted: tells the user the app is not binding the port - assert_contains "$output" "not listening on port 8080" - # Generic fallback fix must NOT appear + assert_contains "$output" "📋 Reason: The application did not pass its health check at /health. Detected: Startup probe — app is not yet listening on /health." + assert_contains "$output" "📋 Detected: Unhealthy on container api" + assert_contains "$output" "📋 Recent warnings:" + assert_contains "$output" " • Unhealthy (×1)" + assert_contains "$output" "💡 Suggested fix: The container is not listening on port 8080 — verify the start command runs, the process binds to 0.0.0.0:8080, and nothing is crashing before it accepts connections." assert_not_contains "$output" "returns 2xx on /health within the readiness window" } @@ -276,11 +276,9 @@ assert_not_contains() { run bash "$BATS_TEST_DIRNAME/../print_failed_deployment_hints" [ "$status" -eq 0 ] - assert_contains "$output" "Detected: Startup probe" - assert_contains "$output" "HTTP 502" - # SUGGESTED_FIX cites the status code and points to app logs - assert_contains "$output" "responded with HTTP 502" - assert_contains "$output" "inspect application logs" + assert_contains "$output" "📋 Reason: The application did not pass its health check at /health. Detected: Startup probe — app responded with HTTP 502 (expected 2xx)." + assert_contains "$output" "📋 Detected: Unhealthy on container api" + assert_contains "$output" "💡 Suggested fix: The app responded with HTTP 502 on /health — inspect application logs for startup errors; the process is running but /health is not returning 2xx." } @test "print_failed_deployment_hints: enriches Unhealthy with timeout detail and targeted fix" { @@ -299,16 +297,14 @@ assert_not_contains() { run bash "$BATS_TEST_DIRNAME/../print_failed_deployment_hints" [ "$status" -eq 0 ] - assert_contains "$output" "Detected: Startup probe" - assert_contains "$output" "timed out" - # SUGGESTED_FIX mentions timing knobs - assert_contains "$output" "initialDelaySeconds" + assert_contains "$output" "📋 Reason: The application did not pass its health check at /health. Detected: Startup probe — request timed out on /health." + assert_contains "$output" "📋 Detected: Unhealthy on container api" + assert_contains "$output" "💡 Suggested fix: The probe timed out — the app may be slow to start, or /health is blocking. Raise the health check's Initial Delay or Timeout on scope 'my-app', or make /health lighter." + assert_not_contains "$output" "initialDelaySeconds" } @test "print_failed_deployment_hints: falls back to raw Unhealthy message when translation is impossible" { export K8S_NAMESPACE="ns" DEPLOYMENT_ID="d1" - # Message does not match any known probe pattern → translate_probe_message returns non-zero. - # The raw text must still be surfaced in the hint instead of being silently dropped. export ALL_EVENTS='{"items":[{"type":"Warning","reason":"Unhealthy","lastTimestamp":"2026-05-20T13:13:42Z","message":"completely unknown probe failure format from a future K8s"}]}' kubectl() { @@ -323,10 +319,8 @@ assert_not_contains() { run bash "$BATS_TEST_DIRNAME/../print_failed_deployment_hints" [ "$status" -eq 0 ] - # Raw message appears verbatim in the reason line - assert_contains "$output" "completely unknown probe failure format from a future K8s" - # Base sentence is still there - assert_contains "$output" "did not pass its health check at /health" + assert_contains "$output" "📋 Reason: The application did not pass its health check at /health. Detected: completely unknown probe failure format from a future K8s" + assert_contains "$output" "💡 Suggested fix: Ensure the app listens on port 8080 and returns 2xx on /health within the readiness window." } @test "print_failed_deployment_hints: Unhealthy picks the latest event when multiple are present" { @@ -399,8 +393,6 @@ assert_not_contains() { # health_check_path default "/" must apply when CONTEXT is unset. assert_contains "$output" "health check at /." assert_contains "$output" "returns 2xx on /" - # Guard against the previous escape bug: a literal backslash in the message - # would indicate jq received {\} instead of {} and silently failed. assert_not_contains "$output" "{\\" } @@ -488,3 +480,64 @@ assert_not_contains() { [ "$status" -eq 0 ] assert_contains "$output" "📊 Progress at failure: 1/3 ready, 2/3 available" } + +@test "print_failed_deployment_hints: an OOM kill inside a crash loop is diagnosed as the OOM" { + export K8S_NAMESPACE="ns" DEPLOYMENT_ID="d1" + kubectl() { + case "$*" in + "get pods"*) + echo '{"items":[{"status":{"containerStatuses":[{"name":"app","state":{"waiting":{"reason":"CrashLoopBackOff","message":"back-off 20s restarting failed container=app pod=d-1_ns(abc)"}},"lastState":{"terminated":{"reason":"OOMKilled","exitCode":137}}}]}}]}' + ;; + esac + } + export -f kubectl + + run bash "$BATS_TEST_DIRNAME/../print_failed_deployment_hints" + + [ "$status" -eq 0 ] + assert_contains "$output" "📋 Reason: The container exceeded its memory limit (512Mi) and was terminated." + assert_contains "$output" "📋 Detected: OOMKilled on container app (exit 137)" + assert_contains "$output" "📋 Details: back-off 20s restarting failed container=app pod=d-1_ns(abc)" + assert_contains "$output" "💡 Suggested fix: Raise the RAM Memory of scope 'my-app', or reduce how much memory the application uses." + assert_not_contains "$output" "The container started and crashed repeatedly." +} + +@test "print_failed_deployment_hints: a plain non-zero exit in a crash loop keeps its startup-log advice" { + export K8S_NAMESPACE="ns" DEPLOYMENT_ID="d1" + kubectl() { + case "$*" in + "get pods"*) + echo '{"items":[{"status":{"containerStatuses":[{"name":"app","state":{"waiting":{"reason":"CrashLoopBackOff","message":"back-off 20s restarting failed container=app"}},"lastState":{"terminated":{"reason":"Error","exitCode":1}}}]}}]}' + ;; + esac + } + export -f kubectl + + run bash "$BATS_TEST_DIRNAME/../print_failed_deployment_hints" + + [ "$status" -eq 0 ] + assert_contains "$output" "📋 Reason: The container started and exited with code 1." + assert_contains "$output" "📋 Detected: Error on container app (exit 1)" + assert_contains "$output" "📋 Details: back-off 20s restarting failed container=app" + assert_contains "$output" "💡 Suggested fix: Review application logs for startup errors (failed dependencies, bad config, panics)." + assert_not_contains "$output" "Pods are failing with reason: Error" +} + +@test "print_failed_deployment_hints: an evicted pod says why and what to do" { + export K8S_NAMESPACE="ns" DEPLOYMENT_ID="d1" + kubectl() { + case "$*" in + "get pods"*) + echo '{"items":[{"status":{"containerStatuses":[{"name":"app","state":{"waiting":{"reason":"Evicted"}}}]}}]}' + ;; + esac + } + export -f kubectl + + run bash "$BATS_TEST_DIRNAME/../print_failed_deployment_hints" + + [ "$status" -eq 0 ] + assert_contains "$output" "📋 Reason: The pod was evicted from its node." + assert_contains "$output" "📋 Detected: Evicted on container app" + assert_contains "$output" "💡 Suggested fix: The node ran out of memory or disk. Lower the scope's resource requests, or free capacity on the cluster." +} diff --git a/k8s/deployment/tests/wait_deployment_active.bats b/k8s/deployment/tests/wait_deployment_active.bats index 52c83d39..368c8ba8 100644 --- a/k8s/deployment/tests/wait_deployment_active.bats +++ b/k8s/deployment/tests/wait_deployment_active.bats @@ -149,7 +149,7 @@ teardown() { # The hint script must read pod state and surface the user-friendly reason assert_contains "$output" "📋 Reason: The container exceeded its memory limit" assert_contains "$output" "📋 Detected: OOMKilled on container app (exit 137)" - assert_contains "$output" "💡 Suggested fix: Increase ram_memory for scope 'my-app'" + assert_contains "$output" "💡 Suggested fix: Raise the RAM Memory of scope 'my-app'" } # ============================================================================= @@ -656,6 +656,64 @@ teardown() { assert_contains "$output" "HTTP 502" } +@test "wait_deployment_active: a multi-word reason survives the reason list whole" { + source "$BATS_TEST_DIRNAME/../wait_deployment_active" 2>/dev/null || true + run bash -c " + source '$BATS_TEST_DIRNAME/../print_failed_deployment_hints' 2>/dev/null || true + \$(declare -f humanize_k8s_reason humanize_k8s_reasons 2>/dev/null) + true + " + eval "$(sed -n '/^humanize_k8s_reason()/,/^}/p;/^humanize_k8s_reasons()/,/^}/p' "$BATS_TEST_DIRNAME/../wait_deployment_active")" + + [ "$(humanize_k8s_reasons 'Startup probe failing')" = "Startup probe failing" ] + [ "$(humanize_k8s_reasons 'OOMKilled, CrashLoopBackOff')" = "out of memory, crashing repeatedly" ] + [ "$(humanize_k8s_reasons 'Startup probe failing, OOMKilled')" = "Startup probe failing, out of memory" ] + [ "$(humanize_k8s_reasons 'ImagePullBackOff, ErrImagePull')" = "can't pull the container image" ] +} + +@test "wait_deployment_active: the trace carries WHY it is stuck and what to do, not just the counts" { + run bash -c " + sleep() { :; } + export -f sleep + + kubectl() { + case \"\$*\" in + \"get deployment\"*\"-o json\"*) + echo '{\"spec\":{\"replicas\":1},\"status\":{\"availableReplicas\":0,\"updatedReplicas\":0,\"readyReplicas\":0}}' + ;; + \"get pods -n test-namespace -l deployment_id=deploy-456 -o jsonpath\"*) + echo 'd-scope-123-deploy-456-abc' + ;; + \"get events\"*\"Pod\"*) + echo '{\"items\":[{\"lastTimestamp\":\"9999-12-31T23:59:59Z\",\"type\":\"Warning\",\"involvedObject\":{\"kind\":\"Pod\",\"name\":\"d-scope-123-deploy-456-abc\"},\"reason\":\"Unhealthy\",\"message\":\"Startup probe failed: HTTP probe failed with statuscode: 404\"}]}' + ;; + \"get events\"*) echo '{\"items\":[]}' ;; + esac + } + export -f kubectl + + np() { echo 'running'; } + export -f np + + np_scope_explain() { echo \"EXPLAIN \$*\"; } + np_scope_error() { echo \"ERROR \$*\"; } + np_scope_step_timeout() { echo \"TIMEOUT \$*\"; } + export -f np_scope_explain np_scope_error np_scope_step_timeout + + export CONTEXT='{\"scope\":{\"name\":\"Stage\",\"capabilities\":{\"health_check\":{\"path\":\"/health-bad\"}}}}' + export SERVICE_PATH='$SERVICE_PATH' K8S_NAMESPACE='$K8S_NAMESPACE' + export SCOPE_ID='$SCOPE_ID' DEPLOYMENT_ID='$DEPLOYMENT_ID' + export TIMEOUT=10 NP_API_KEY='$NP_API_KEY' SKIP_DEPLOYMENT_STATUS_CHECK='false' + bash '$BATS_TEST_DIRNAME/../wait_deployment_active' + " + + [ "$status" -eq 1 ] + assert_contains "$output" "did not pass its health check at /health-bad" + assert_contains "$output" "Detected: Startup probe" + assert_contains "$output" "HTTP 404" + assert_contains "$output" "--next" +} + # ============================================================================= # Latest Timestamp Initialization # ============================================================================= @@ -857,3 +915,80 @@ teardown() { assert_contains "$output" "Could not report instance counts" assert_contains "$output" "✅ All pods in deployment 'd-scope-123-deploy-456' are available and ready!" } + +@test "wait_deployment_active: an OOM kill in a restart loop is reported as out of memory, not as the loop" { + cat > "$BATS_TMPDIR/oom-pods.json" <<'JSON' +{"items":[{"metadata":{"name":"d-1-2-abc"}, +"status":{"containerStatuses":[{"name":"application", +"state":{"waiting":{"reason":"CrashLoopBackOff","message":"back-off 20s restarting failed container=application pod=d-1-2-abc_nullplatform(498dc0ab)"}}, +"lastState":{"terminated":{"reason":"OOMKilled","exitCode":137}}, +"restartCount":3}]}}]} +JSON + + run jq -r '[.items[] | .status.containerStatuses[]? + | .state.waiting.reason as $w + | (.lastState.terminated.reason // "") as $t0 + | (if $t0 == "Completed" then "" else $t0 end) as $t + | (if ($w == "CrashLoopBackOff" or $w == "BackOff") then $t else $w end)] + | unique | join(", ")' "$BATS_TMPDIR/oom-pods.json" + [ "$status" -eq 0 ] + [ "$output" = "OOMKilled" ] + + eval "$(sed -n '/^humanize_k8s_reason()/,/^}/p;/^humanize_k8s_reasons()/,/^}/p' "$BATS_TEST_DIRNAME/../wait_deployment_active")" + [ "$(humanize_k8s_reasons "$output")" = "out of memory" ] +} + +@test "wait_deployment_active: the mechanism stays on the io even though the narrative names the cause" { + cat > "$BATS_TMPDIR/oom-pods.json" <<'JSON' +{"items":[{"metadata":{"name":"d-1-2-abc"}, +"status":{"containerStatuses":[{"name":"application", +"state":{"waiting":{"reason":"CrashLoopBackOff","message":"back-off 20s restarting failed container=application"}}, +"lastState":{"terminated":{"reason":"OOMKilled"}}, +"restartCount":3}]}}]} +JSON + run jq -c '[.items[] | .metadata.name as $pod | .status.containerStatuses[]? + | .state.waiting.reason as $w + | (.lastState.terminated.reason // "") as $t0 + | (if $t0 == "Completed" then "" else $t0 end) as $t + | {pod: $pod, reason: $w, + cause: (if ($w == "CrashLoopBackOff" or $w == "BackOff") then $t else "" end)}]' \ + "$BATS_TMPDIR/oom-pods.json" + [ "$status" -eq 0 ] + echo "$output" | grep -q '"reason":"CrashLoopBackOff"' + echo "$output" | grep -q '"cause":"OOMKilled"' +} + +@test "wait_deployment_active: a real cause still wins over the termination reason" { + cat > "$BATS_TMPDIR/pull-pods.json" <<'JSON' +{"items":[{"metadata":{"name":"d-1-2-abc"}, +"status":{"containerStatuses":[{"name":"application", +"state":{"waiting":{"reason":"ImagePullBackOff","message":"manifest unknown"}}, +"lastState":{"terminated":{"reason":"Error"}}}]}}]} +JSON + run jq -r '[.items[] | .status.containerStatuses[]? + | .state.waiting.reason as $w + | (.lastState.terminated.reason // "") as $t + | (if ($w == "CrashLoopBackOff" or $w == "BackOff") and $t != "" then $t else $w end)] + | unique | join(", ")' "$BATS_TMPDIR/pull-pods.json" + [ "$status" -eq 0 ] + [ "$output" = "ImagePullBackOff" ] +} + +@test "wait_deployment_active: the back-off boilerplate never reaches the phase line" { + detail_of() { + local d="$1" + case "$d" in + "back-off "*"restarting failed container="*) d="" ;; + esac + if [ ${#d} -gt 140 ]; then d="${d:0:137}..."; fi + printf '%s' "$d" + } + + [ -z "$(detail_of 'back-off 20s restarting failed container=application pod=d-253247585-630235960_nullplatform(498dc0ab-d1f9)')" ] + [ "$(detail_of 'manifest unknown: manifest tagged v9 not found')" = 'manifest unknown: manifest tagged v9 not found' ] + + long=$(printf 'x%.0s' $(seq 1 200)) + capped=$(detail_of "$long") + [ "${#capped}" -eq 140 ] + case "$capped" in *"...") ;; *) return 1 ;; esac +} diff --git a/k8s/deployment/validate_alb_target_group_capacity b/k8s/deployment/validate_alb_target_group_capacity index 71d01d9e..2ec73134 100755 --- a/k8s/deployment/validate_alb_target_group_capacity +++ b/k8s/deployment/validate_alb_target_group_capacity @@ -184,3 +184,8 @@ if [[ "$LISTENER_COUNT" -ge "$ALB_MAX_LISTENERS" ]]; then fi log info "✅ ALB listener capacity validated: $LISTENER_COUNT/$ALB_MAX_LISTENERS" + +if command -v np_scope_explain >/dev/null 2>&1; then + np_scope_explain --title "Validate load balancer capacity" --what "Load balancer has room: $TARGET_GROUP_COUNT/$ALB_MAX_TARGET_GROUPS target groups, $LISTENER_COUNT/$ALB_MAX_LISTENERS listeners in use" + np_scope_output capacity "{\"target_groups\": {\"used\": $TARGET_GROUP_COUNT, \"max\": $ALB_MAX_TARGET_GROUPS}, \"listeners\": {\"used\": $LISTENER_COUNT, \"max\": $ALB_MAX_LISTENERS}}" +fi diff --git a/k8s/deployment/verify_http_route_reconciliation b/k8s/deployment/verify_http_route_reconciliation index 5e71e88c..01113dc3 100644 --- a/k8s/deployment/verify_http_route_reconciliation +++ b/k8s/deployment/verify_http_route_reconciliation @@ -11,6 +11,11 @@ elapsed=0 log debug "🔍 Verifying HTTPRoute reconciliation..." log debug "📋 HTTPRoute: $HTTPROUTE_NAME | Namespace: $K8S_NAMESPACE | Timeout: ${MAX_WAIT_SECONDS}s" +if command -v np_scope_step_begin >/dev/null 2>&1; then + np_scope_step_begin verify-httproute --title "Verify HTTPRoute reconciliation ($HTTPROUTE_NAME)" + np_scope_wait_heartbeat "httproute-reconciliation" 0 "$MAX_WAIT_SECONDS" "pending" +fi + while [ $elapsed -lt $MAX_WAIT_SECONDS ]; do sleep $CHECK_INTERVAL @@ -43,6 +48,10 @@ while [ $elapsed -lt $MAX_WAIT_SECONDS ]; do if [ "$accepted_status" == "True" ] && [ "$resolved_status" == "True" ]; then log info "✅ HTTPRoute successfully reconciled (Accepted: True, ResolvedRefs: True)" + if command -v np_scope_step_end >/dev/null 2>&1; then + np_scope_step_end 0 + np_scope_explain --title "Verify networking" --what "HTTPRoute $HTTPROUTE_NAME reconciled — DNS routing verified" + fi return 0 fi @@ -106,6 +115,9 @@ while [ $elapsed -lt $MAX_WAIT_SECONDS ]; do log debug "📝 HTTPRoute reconciling... (${elapsed}s/${MAX_WAIT_SECONDS}s)" echo "$conditions" | jq -r '.[] | " - \(.type): \(.status) (\(.reason))"' + if [ $((elapsed % 30)) -eq 0 ] && command -v np_scope_wait_heartbeat >/dev/null 2>&1; then + np_scope_wait_heartbeat "httproute-reconciliation" "$elapsed" "$MAX_WAIT_SECONDS" "reconciling" + fi elapsed=$((elapsed + CHECK_INTERVAL)) done @@ -120,4 +132,7 @@ echo "$httproute_json" | jq -r '.status.parents[0].conditions[] | " - \(.type) log error "🔧 How to fix:" log error " - Check Gateway controller logs" log error " - Verify Gateway and Istio configuration" +if command -v np_scope_step_timeout >/dev/null 2>&1; then + np_scope_step_timeout "HTTPRoute $HTTPROUTE_NAME not reconciled after ${MAX_WAIT_SECONDS}s" +fi exit 1 diff --git a/k8s/deployment/verify_ingress_reconciliation b/k8s/deployment/verify_ingress_reconciliation index 759767b5..af4f2d8a 100644 --- a/k8s/deployment/verify_ingress_reconciliation +++ b/k8s/deployment/verify_ingress_reconciliation @@ -18,6 +18,9 @@ DEPLOYMENT_STRATEGY=$(echo "$CONTEXT" | jq -r ".deployment.strategy") if [ "$ALB_RECONCILIATION_ENABLED" = "false" ] && [ "$DEPLOYMENT_STRATEGY" = "blue_green" ]; then log warn "⚠️ Skipping ALB verification (ALB access needed for blue-green traffic validation)" + if command -v np_step_skip >/dev/null 2>&1; then + np_step_skip "load balancer verification is disabled on this scope (ALB_RECONCILIATION_ENABLED=false)" + fi return 0 fi @@ -247,10 +250,19 @@ validate_alb_config() { fi } +if command -v np_scope_step_begin >/dev/null 2>&1; then + np_scope_step_begin verify-ingress --title "Verify ingress reconciliation ($INGRESS_NAME)" + np_scope_wait_heartbeat "ingress-reconciliation" 0 "$MAX_WAIT_SECONDS" "pending" +fi + while [ $elapsed -lt $MAX_WAIT_SECONDS ]; do if [ "$ALB_RECONCILIATION_ENABLED" = "true" ]; then if validate_alb_config; then log info "✅ ALB configuration validated successfully" + if command -v np_scope_step_end >/dev/null 2>&1; then + np_scope_step_end 0 + np_scope_explain --title "Verify networking" --what "Load-balancer routing verified for $INGRESS_NAME — rules and weights match the deployment" + fi return 0 fi log debug "📝 ALB validation incomplete, checking Kubernetes events..." @@ -281,6 +293,12 @@ while [ $elapsed -lt $MAX_WAIT_SECONDS ]; do log debug "📝 Ingress reported as reconciled, but ALB validation has not passed yet" else log info "✅ Ingress successfully reconciled" + if command -v np_scope_step_end >/dev/null 2>&1; then + np_scope_step_end 0 + fi + if command -v np_scope_explain >/dev/null 2>&1; then + np_scope_explain --title "Verify networking" --what "Ingress $INGRESS_NAME reconciled — the controller reported the routing applied" + fi return 0 fi fi @@ -311,6 +329,9 @@ while [ $elapsed -lt $MAX_WAIT_SECONDS ]; do fi log debug "📝 Waiting for ALB reconciliation... (${elapsed}s/${MAX_WAIT_SECONDS}s)" + if [ $((elapsed % 30)) -eq 0 ] && command -v np_scope_wait_heartbeat >/dev/null 2>&1; then + np_scope_wait_heartbeat "ingress-reconciliation" "$elapsed" "$MAX_WAIT_SECONDS" "reconciling" + fi sleep $CHECK_INTERVAL elapsed=$((elapsed + CHECK_INTERVAL)) done @@ -329,4 +350,7 @@ events_json=$(kubectl get events -n "$K8S_NAMESPACE" \ -o json) echo "$events_json" | jq -r '.items | sort_by(.lastTimestamp) | .[] | " [\(.type)] \(.reason): \(.message)"' | tail -10 +if command -v np_scope_step_timeout >/dev/null 2>&1; then + np_scope_step_timeout "ingress $INGRESS_NAME not reconciled after ${MAX_WAIT_SECONDS}s" +fi exit 1 diff --git a/k8s/deployment/verify_networking_reconciliation b/k8s/deployment/verify_networking_reconciliation index 506e57f5..ce3cab33 100644 --- a/k8s/deployment/verify_networking_reconciliation +++ b/k8s/deployment/verify_networking_reconciliation @@ -12,5 +12,8 @@ case "$DNS_TYPE" in ;; *) log warn "⚠️ Ingress reconciliation not available for DNS type: $DNS_TYPE, skipping" + if command -v np_step_skip >/dev/null 2>&1; then + np_step_skip "no networking verification for DNS type '$DNS_TYPE'" + fi ;; esac diff --git a/k8s/deployment/wait_deployment_active b/k8s/deployment/wait_deployment_active index 7575a603..e2e3c839 100755 --- a/k8s/deployment/wait_deployment_active +++ b/k8s/deployment/wait_deployment_active @@ -55,6 +55,183 @@ iteration=0 LATEST_TIMESTAMP=$(date -u +"%Y-%m-%dT%H:%M:%SZ") SKIP_DEPLOYMENT_STATUS_CHECK="${SKIP_DEPLOYMENT_STATUS_CHECK:=false}" LAST_REPORTED_COUNTS="" +UNHEALTHY_POD_COUNT=0 +UNHEALTHY_POD_REASONS="" +case "${NP_TRACE:-}" in + *~switch-instances-check@*) WAIT_TITLE="Verify scaled instances" ;; + *~finalize-instances-check@*) WAIT_TITLE="Verify final capacity" ;; + *) WAIT_TITLE="Instance health check" ;; +esac + +humanize_k8s_reason() { + case "$1" in + OOMKilled) echo "out of memory" ;; + CrashLoopBackOff) echo "crashing repeatedly" ;; + ImagePullBackOff|ErrImagePull|InvalidImageName) echo "can't pull the container image" ;; + CreateContainerConfigError|CreateContainerError|RunContainerError|ContainerCannotRun) echo "container failed to start" ;; + Error) echo "exited with an error" ;; + DeadlineExceeded) echo "timed out" ;; + Evicted) echo "evicted from its node" ;; + Unschedulable|FailedScheduling) echo "can't be scheduled onto a node" ;; + BackOff) echo "restarting after failures" ;; + FailedMount|FailedAttachVolume) echo "can't attach its storage" ;; + FailedCreate) echo "couldn't be created" ;; + Unhealthy) echo "failing health checks" ;; + *) echo "$1" ;; + esac +} + +humanize_k8s_reasons() { + local _hr_out="" _hr_word + IFS=',' read -ra _hr_parts <<< "$1" + for _hr_part in "${_hr_parts[@]}"; do + _hr_part="${_hr_part#"${_hr_part%%[![:space:]]*}"}" + _hr_part="${_hr_part%"${_hr_part##*[![:space:]]}"}" + [ -n "$_hr_part" ] || continue + _hr_word=$(humanize_k8s_reason "$_hr_part") + case ", $_hr_out," in + *", $_hr_word,"*) ;; + *) _hr_out="${_hr_out:+$_hr_out, }$_hr_word" ;; + esac + done + echo "$_hr_out" +} + +WAIT_WHY="" +WAIT_NEXT="" +classify_wait_failure() { + WAIT_WHY="" + WAIT_NEXT="" + command -v diagnose_failure >/dev/null 2>&1 || return 0 + diagnose_failure >/dev/null 2>&1 || true + WAIT_WHY="${HUMAN_MESSAGE:-}" + WAIT_NEXT="${SUGGESTED_FIX:-}" + return 0 +} + +report_wait_narrative() { + command -v np_scope_explain >/dev/null 2>&1 || return 0 + local ready_now="$1" desired_now="$2" launched_now="$3" all_healthy="${4:-false}" + + local pods_json restarted restart_total restart_reasons restart_clause + local problems problem_count problem_reasons real_detail + pods_json=$(kubectl get pods -n "$K8S_NAMESPACE" -l "deployment_id=${DEPLOYMENT_ID}" -o json 2>/dev/null) || pods_json="" + restarted=$(echo "$pods_json" \ + | jq -c '[.items[] | {name: .metadata.name, + restarts: ([.status.containerStatuses[]?.restartCount] | add // 0), + reason: ([.status.containerStatuses[]?.lastState.terminated.reason // empty] | first // empty)} + | select(.restarts > 0) | with_entries(select(.value != "" and .value != null))]' 2>/dev/null) || restarted="[]" + [ -n "$restarted" ] || restarted="[]" + restart_total=$(echo "$restarted" | jq 'map(.restarts) | add // 0' 2>/dev/null) || restart_total=0 + restart_reasons=$(echo "$restarted" | jq -r '[.[].reason // empty] | unique | join(", ")' 2>/dev/null) || restart_reasons="" + restart_words=$(humanize_k8s_reasons "${restart_reasons:-}") + restart_clause="${restart_words:+ ($restart_words)}" + problems=$(echo "$pods_json" \ + | jq -c '[.items[] | .metadata.name as $pod | .status.containerStatuses[]? + | select(.state.waiting.reason != null + and .state.waiting.reason != "ContainerCreating" + and .state.waiting.reason != "PodInitializing") + | .state.waiting.reason as $w + | (.lastState.terminated.reason // "") as $t0 + | (if $t0 == "Completed" then "" else $t0 end) as $t + | {pod: $pod, reason: $w, + cause: (if ($w == "CrashLoopBackOff" or $w == "BackOff") then $t else "" end), + message: ((.state.waiting.message // "") | .[0:300])} + | with_entries(select(.value != ""))]' 2>/dev/null) || problems="[]" + [ -n "$problems" ] || problems="[]" + problem_count=$(echo "$problems" | jq 'length' 2>/dev/null) || problem_count=0 + problem_reasons=$(echo "$problems" | jq -r '[.[] | (.cause // .reason)] | unique | join(", ")' 2>/dev/null) || problem_reasons="" + real_detail=$(echo "$problems" | jq -r '[.[].message // empty] | first // ""' 2>/dev/null \ + | tr '\n' ' ' | sed 's/[[:space:]]*$//') || real_detail="" + + if [ "${problem_count:-0}" -eq 0 ] && [ "$UNHEALTHY_POD_COUNT" -gt 0 ]; then + problem_count=$UNHEALTHY_POD_COUNT + problem_reasons=$UNHEALTHY_POD_REASONS + fi + WAIT_EFFECTIVE_REASONS="${problem_reasons:-$restart_reasons}" + WAIT_REAL_DETAIL="$real_detail" + + local crash_log="" + if [ "$restart_total" -gt 0 ]; then + local crash_pod + crash_pod=$(echo "$restarted" | jq -r '.[0].name // empty' 2>/dev/null) || crash_pod="" + if [ -n "$crash_pod" ]; then + crash_log=$(kubectl logs "$crash_pod" -n "$K8S_NAMESPACE" --previous --tail=15 2>/dev/null | tail -c 1500) || crash_log="" + fi + if [ -n "$crash_log" ] && [ -z "$real_detail" ]; then + WAIT_REAL_DETAIL=$(printf '%s' "$crash_log" | tail -1 | cut -c1-200) + fi + fi + + case "$WAIT_REAL_DETAIL" in + "back-off "*"restarting failed container="*) WAIT_REAL_DETAIL="" ;; + esac + if [ ${#WAIT_REAL_DETAIL} -gt 140 ]; then + WAIT_REAL_DETAIL="${WAIT_REAL_DETAIL:0:137}..." + fi + + local snapshot="$ready_now/$desired_now/$launched_now/$problem_count/$problem_reasons/$restart_total/$all_healthy" + if [ "$snapshot" = "${WAIT_NARRATIVE_SNAPSHOT:-}" ]; then + return 0 + fi + WAIT_NARRATIVE_SNAPSHOT="$snapshot" + + local instances meter + instances=$(jq -nc --argjson h "$ready_now" --argjson l "$launched_now" --argjson d "$desired_now" \ + --argjson p "$problems" --argjson r "$restarted" --arg crash "$crash_log" \ + '{healthy: $h, launched: $l, desired: $d} + + (if ($p | length) > 0 then {problems: $p} else {} end) + + (if ($r | length) > 0 then {restarted: $r} else {} end) + + (if $crash != "" then {last_crash_log: $crash} else {} end)') + np_scope_output instances "$instances" + + meter=$(jq -nc --argjson h "$ready_now" --argjson l "$launched_now" --argjson d "$desired_now" \ + --argjson u "$problem_count" --arg reasons "$(humanize_k8s_reasons "$problem_reasons")" --argjson t "$restart_total" \ + --arg rreasons "$(humanize_k8s_reasons "$restart_reasons")" \ + '{kind: "instances-health", healthy: $h, launched: $l, desired: $d} + + (if $u > 0 then {unhealthy: $u, reasons: ($reasons | split(", ") | map(select(. != "")))} else {} end) + + (if $t > 0 then {restarts: $t} else {} end) + + (if $rreasons != "" then {restart_reasons: ($rreasons | split(", "))} else {} end)') + np_scope_affordance "$meter" + + local restarts_label="restarts" detail_clause="" + [ "$restart_total" -eq 1 ] && restarts_label="restart" + [ -n "$WAIT_REAL_DETAIL" ] && detail_clause=": $WAIT_REAL_DETAIL" + if [ "$problem_count" -gt 0 ]; then + local problem_words + problem_words=$(humanize_k8s_reasons "${problem_reasons:-}") + classify_wait_failure + np_scope_explain --title "$WAIT_TITLE" --severity warn \ + --what "Waiting for $ready_now/$desired_now instances to be healthy — $problem_count with ${problem_words:-failing health checks}$detail_clause" \ + ${WAIT_WHY:+--why "$WAIT_WHY"} \ + --impact "The deployment fails if the instances don't become healthy before the health-check timeout." \ + ${WAIT_NEXT:+--next "$WAIT_NEXT"} + elif [ "$restart_total" -gt 0 ]; then + classify_wait_failure + if [ "$all_healthy" = "true" ]; then + np_scope_explain --title "$WAIT_TITLE" --severity warn \ + --what "All $desired_now instances healthy — after $restart_total $restarts_label$restart_clause" \ + ${WAIT_WHY:+--why "$WAIT_WHY"} \ + --impact "The instances crashed on the way here; the last crash output is attached to this step." \ + ${WAIT_NEXT:+--next "$WAIT_NEXT"} + else + np_scope_explain --title "$WAIT_TITLE" --severity warn \ + --what "Waiting for $ready_now/$desired_now instances to be healthy — $restart_total $restarts_label so far$restart_clause$detail_clause" \ + ${WAIT_WHY:+--why "$WAIT_WHY"} \ + --impact "The last crash output is attached to this step." \ + ${WAIT_NEXT:+--next "$WAIT_NEXT"} + fi + elif [ "$all_healthy" = "true" ]; then + np_scope_explain --title "$WAIT_TITLE" --what "All $desired_now instances healthy" + else + local graced_clause="" + if [ "$launched_now" -gt "$ready_now" ] 2>/dev/null; then + graced_clause=" (instances starting — normal while the app boots)" + fi + np_scope_explain --title "$WAIT_TITLE" --what "Waiting for $ready_now/$desired_now instances to be healthy$graced_clause" + fi + return 0 +} # Report the instance counters onto the deployment's strategy_data # (amount_instances_to_wait / launched_instances / healthy_instances) so the @@ -95,6 +272,10 @@ log debug "📋 Namespace: $K8S_NAMESPACE" log debug "📋 Timeout: ${TIMEOUT}s (max $MAX_ITERATIONS iterations)" log debug "" +if command -v np_scope_wait_heartbeat >/dev/null 2>&1; then + np_scope_wait_heartbeat "deployment-active" 0 "$TIMEOUT" "starting" +fi + while true; do ((++iteration)) if [ $iteration -gt $MAX_ITERATIONS ]; then @@ -104,6 +285,24 @@ while true; do source "$SERVICE_PATH/deployment/print_failed_deployment_hints" + if command -v np_scope_step_timeout >/dev/null 2>&1; then + timeout_cause="${WAIT_REAL_DETAIL:-}" + timeout_reasons="${WAIT_EFFECTIVE_REASONS:-$UNHEALTHY_POD_REASONS}" + timeout_message="deployment '$K8S_DEPLOYMENT_NAME' not active after ${TIMEOUT}s" + if [ -n "$timeout_cause" ]; then + timeout_message="$timeout_cause ($timeout_message)" + fi + timeout_reason_words=$(humanize_k8s_reasons "${timeout_reasons:-}") + np_scope_explain --title "$WAIT_TITLE" --severity error \ + --what "Gave up with ${ready:-0}/${desired:-0} instances healthy${timeout_reason_words:+ — $timeout_reason_words}${timeout_cause:+: $timeout_cause}" \ + ${HUMAN_MESSAGE:+--why "$HUMAN_MESSAGE"} \ + --impact "The previous version keeps serving traffic; this deployment does not go live." \ + ${SUGGESTED_FIX:+--next "$SUGGESTED_FIX"} + np_scope_error "$timeout_message" \ + "$(jq -nc --argjson h "${ready:-0}" --argjson l "${launched:-0}" --argjson d "${desired:-0}" --arg reasons "$timeout_reasons" \ + '{instances: {healthy: $h, launched: $l, desired: $d}} + (if $reasons != "" then {reasons: ($reasons | split(", "))} else {} end)')" + np_scope_step_timeout "$timeout_message" + fi exit 1 fi @@ -141,15 +340,49 @@ while true; do report_instance_counts "$desired" "$launched" "$ready" + report_wait_narrative "$ready" "$desired" "$launched" + if [ "$desired" = "$current" ] && [ "$desired" = "$updated" ] && [ "$desired" = "$ready" ] && [ "$desired" -gt 0 ]; then log debug "" log info "✅ All pods in deployment '$K8S_DEPLOYMENT_NAME' are available and ready!" + if command -v np_scope_progress >/dev/null 2>&1; then + np_scope_progress "$ready" "$desired" count + UNHEALTHY_POD_COUNT=0 + UNHEALTHY_POD_REASONS="" + report_wait_narrative "$ready" "$desired" "$launched" true + + _wda_asset_url=$(echo "$CONTEXT" | jq -r '.asset.url // empty') + _wda_asset_type=$(echo "$CONTEXT" | jq -r '.asset.type // "docker-image"') + if [ -n "$_wda_asset_url" ]; then + np_scope_consumes "$_wda_asset_type:$_wda_asset_url" image "$_wda_asset_url" + fi + _wda_app_id=$(echo "$CONTEXT" | jq -r '.application.id // empty') + _wda_scope_id=$(echo "$CONTEXT" | jq -r '.scope.id // empty') + _wda_created=$(echo "$CONTEXT" | jq -r '.deployment.created_at // empty') + _wda_start_ms=$(date -d "$_wda_created" +%s000 2>/dev/null || echo "") + if [ -n "$_wda_app_id" ] && [ -n "$_wda_scope_id" ]; then + _wda_log_uri="application/$_wda_app_id/log?scope=$_wda_scope_id&type=application" + [ -n "$_wda_start_ms" ] && _wda_log_uri="$_wda_log_uri&start_time=$_wda_start_ms" + np_scope_produces \ + "deployment-log:$_wda_app_id/$_wda_scope_id/$DEPLOYMENT_ID" \ + log "$_wda_log_uri" + np_scope_affordance "{\"kind\":\"deploy-log\",\"application_id\":\"$_wda_app_id\",\"scope_id\":\"$_wda_scope_id\",\"type\":\"application\"${_wda_start_ms:+,\"start_time\":$_wda_start_ms}}" + fi + + NP_TRACE_FLUSH_TIMEOUT=10 np_trace_flush + fi break fi if [ "$iteration" -eq 1 ] || [ $(( iteration % HEARTBEAT_INTERVAL )) -eq 0 ]; then elapsed_s=$(( iteration * 10 )) log info "⏳ Still waiting — Ready: $ready/$desired, Available: $current/$desired (attempt $iteration/$MAX_ITERATIONS, ${elapsed_s}s elapsed)" + if command -v np_scope_wait_heartbeat >/dev/null 2>&1; then + np_scope_wait_heartbeat "deployment-active" "$elapsed_s" "$TIMEOUT" "progressing" \ + "wait.desired=$desired" "wait.launched=$launched" \ + "wait.ready=$ready" "wait.available=$current" "wait.updated=$updated" + np_scope_progress "$ready" "$desired" count + fi fi POD_SELECTOR="deployment_id=${DEPLOYMENT_ID}" @@ -216,8 +449,22 @@ while true; do ') if [ -n "$UNHEALTHY_GROUPS" ]; then + UNHEALTHY_POD_COUNT=0 while IFS=$'\t' read -r ts pod_name messages_concat; do [ -z "$pod_name" ] && continue + ((UNHEALTHY_POD_COUNT++)) + first_msg=$(printf '%s' "$messages_concat" | tr '\001' '\n' | head -1) + parsed=$(parse_probe_message "$first_msg" 2>/dev/null) || parsed="" + probe_kind="${parsed%%|*}" + if [ -n "$probe_kind" ]; then + unhealthy_reason="$probe_kind probe failing" + else + unhealthy_reason="failing health checks" + fi + case ", $UNHEALTHY_POD_REASONS," in + *", $unhealthy_reason,"*) ;; + *) UNHEALTHY_POD_REASONS="${UNHEALTHY_POD_REASONS:+$UNHEALTHY_POD_REASONS, }$unhealthy_reason" ;; + esac log_unhealthy_group "$ts" "$pod_name" "$messages_concat" \ || log_unhealthy_raw "$ts" "$pod_name" "$messages_concat" done <<< "$UNHEALTHY_GROUPS" diff --git a/k8s/deployment/workflows/blue_green.yaml b/k8s/deployment/workflows/blue_green.yaml index 7fac13fb..695046c7 100644 --- a/k8s/deployment/workflows/blue_green.yaml +++ b/k8s/deployment/workflows/blue_green.yaml @@ -2,6 +2,22 @@ include: - "$SERVICE_PATH/deployment/workflows/initial.yaml" configuration: INGRESS_TEMPLATE: "$BLUE_GREEN_INGRESS_PATH" +trace: + title: Blue/green deployment + flavors: ["$K8S_FLAVOR", "$DNS_TYPE"] + default: false + job: + name: k8s-deployment-blue-green + namespace: "@context:scope.provider" + labels: + entity: deployment + strategy: blue_green + scope.provider: "@context:scope.provider" + groups: + - {key: setting-up, title: Setting up} + - {key: waiting-instances, title: Waiting for instances to be healthy} + - {key: switching-traffic, title: Switching traffic} + - {key: finalize, title: Finalize} steps: - name: update blue deployment type: script diff --git a/k8s/deployment/workflows/delete.yaml b/k8s/deployment/workflows/delete.yaml index 538679a5..0896731e 100644 --- a/k8s/deployment/workflows/delete.yaml +++ b/k8s/deployment/workflows/delete.yaml @@ -1,9 +1,21 @@ include: - "$SERVICE_PATH/values.yaml" +trace: + title: Remove deployment + flavors: ["$K8S_FLAVOR", "$DNS_TYPE"] + default: false + job: + name: k8s-deployment-delete + namespace: "@context:scope.provider" + labels: + entity: deployment + operation: delete + scope.provider: "@context:scope.provider" steps: - name: load logging type: script file: "$SERVICE_PATH/logging" + trace: false output: - name: log type: function @@ -13,6 +25,7 @@ steps: - name: assume role type: script file: "$SERVICE_PATH/utils/assume_role_step" + trace: false output: - name: AWS_ACCESS_KEY_ID type: environment @@ -23,6 +36,7 @@ steps: - name: build context type: script file: "$SERVICE_PATH/deployment/build_context" + trace: false output: - name: CONTEXT type: environment diff --git a/k8s/deployment/workflows/diagnose.yaml b/k8s/deployment/workflows/diagnose.yaml index 45d837c3..e15f33e5 100644 --- a/k8s/deployment/workflows/diagnose.yaml +++ b/k8s/deployment/workflows/diagnose.yaml @@ -1,3 +1,5 @@ +trace: + title: Diagnose the failed deployment continue_on_error: true include: - "$SERVICE_PATH/values.yaml" @@ -5,6 +7,7 @@ steps: - name: load_functions type: script file: "$SERVICE_PATH/diagnose/utils/diagnose_utils" + trace: false output: - name: update_check_result type: function @@ -16,6 +19,7 @@ steps: - name: build context type: script file: "$SERVICE_PATH/diagnose/build_context" + trace: false output: - name: CONTEXT type: environment @@ -27,10 +31,12 @@ steps: name: notify_check_running type: script file: "$SERVICE_PATH/diagnose/notify_check_running" + trace: false after_each: name: notify_check_results type: script file: "$SERVICE_PATH/diagnose/notify_diagnose_results" + trace: false folders: - "$SERVICE_PATH/diagnose/service" - "$SERVICE_PATH/diagnose/scope" diff --git a/k8s/deployment/workflows/finalize.yaml b/k8s/deployment/workflows/finalize.yaml index e0246180..7198acd3 100644 --- a/k8s/deployment/workflows/finalize.yaml +++ b/k8s/deployment/workflows/finalize.yaml @@ -2,10 +2,24 @@ include: - "$SERVICE_PATH/values.yaml" configuration: INGRESS_TEMPLATE: "$INITIAL_INGRESS_PATH" +trace: + title: Finalize deployment + flavors: ["$K8S_FLAVOR", "$DNS_TYPE", "@context:providers.scope-configurations.deployment.deployment_strategy"] + default: false + job: + name: k8s-deployment-finalize + namespace: "@context:scope.provider" + labels: + entity: deployment + operation: finalize + scope.provider: "@context:scope.provider" + groups: + - {key: finalize, title: Finalize} steps: - name: load logging type: script file: "$SERVICE_PATH/logging" + trace: false output: - name: log type: function @@ -15,6 +29,7 @@ steps: - name: assume role type: script file: "$SERVICE_PATH/utils/assume_role_step" + trace: false output: - name: AWS_ACCESS_KEY_ID type: environment @@ -25,6 +40,7 @@ steps: - name: build context type: script file: "$SERVICE_PATH/deployment/build_context" + trace: false output: - name: CONTEXT type: environment @@ -39,21 +55,39 @@ steps: - name: BLUE_DEPLOYMENT_ID type: environment - name: build green deployment + trace: + title: Promote new deployment + description: Scales the new version up to full capacity before the old one is removed. + flavors: [rolling] + group: finalize type: script file: "$SERVICE_PATH/deployment/scale_deployments" post: name: wait deployment active type: script file: "$SERVICE_PATH/deployment/wait_deployment_active" + trace: + key: finalize-instances-check + title: Verify final capacity + description: Confirms every instance of the new version is healthy before the old one goes away. + group: finalize configuration: TIMEOUT: DEPLOYMENT_MAX_WAIT_IN_SECONDS SKIP_DEPLOYMENT_STATUS_CHECK: true - name: route traffic + trace: + title: Configure ingress + description: Rewrites the routing rules so the new version owns the scope's address. + group: finalize type: script file: "$SERVICE_PATH/deployment/networking/gateway/route_traffic" configuration: TEMPLATE: "$INGRESS_TEMPLATE" - name: apply traffic + trace: + title: Apply final routing + description: Puts the rewritten routing live. + group: finalize type: script file: "$SERVICE_PATH/apply_templates" configuration: @@ -68,6 +102,10 @@ steps: type: workflow steps: - name: verify_networking_reconciliation + trace: + title: Verify networking + description: Waits for the load balancer to report the new routing as settled. + group: finalize type: script file: "$SERVICE_PATH/deployment/verify_networking_reconciliation" configuration: @@ -75,9 +113,11 @@ steps: # blue deployment is deleted below. Weights cannot express this state. EXPECT_SINGLE_TARGET_GROUP: true - name: publish_alb_metrics + trace: false type: script file: "$SERVICE_PATH/deployment/publish_alb_metrics" - name: build deployment + trace: false type: script file: "$SERVICE_PATH/deployment/build_blue_deployment" output: @@ -94,6 +134,10 @@ steps: type: file file: "$OUTPUT_DIR/service-$SCOPE_ID-$BLUE_DEPLOYMENT_ID.yaml" - name: delete deployment + trace: + title: Remove previous deployment + description: Deletes the old version's workload, now that nothing routes to it. + group: finalize type: script file: "$SERVICE_PATH/apply_templates" configuration: diff --git a/k8s/deployment/workflows/initial.yaml b/k8s/deployment/workflows/initial.yaml index 92a0bb40..a26cbd31 100644 --- a/k8s/deployment/workflows/initial.yaml +++ b/k8s/deployment/workflows/initial.yaml @@ -2,10 +2,26 @@ include: - "$SERVICE_PATH/values.yaml" configuration: INGRESS_TEMPLATE: "$INITIAL_INGRESS_PATH" +trace: + title: Initial deployment + flavors: ["$K8S_FLAVOR", "$DNS_TYPE"] + default: false + job: + name: k8s-deployment-initial + namespace: "@context:scope.provider" + labels: + entity: deployment + strategy: initial + scope.provider: "@context:scope.provider" + groups: + - {key: setting-up, title: Setting up} + - {key: waiting-instances, title: Waiting for instances to be healthy} + - {key: finalize, title: Finalize} steps: - name: load logging type: script file: "$SERVICE_PATH/logging" + trace: false output: - name: log type: function @@ -15,6 +31,7 @@ steps: - name: assume role type: script file: "$SERVICE_PATH/utils/assume_role_step" + trace: false output: - name: AWS_ACCESS_KEY_ID type: environment @@ -25,6 +42,7 @@ steps: - name: build context type: script file: "$SERVICE_PATH/deployment/build_context" + trace: false output: - name: CONTEXT type: environment @@ -41,9 +59,14 @@ steps: - name: validate alb target group capacity type: script file: "$SERVICE_PATH/deployment/validate_alb_target_group_capacity" + trace: + title: Validate load balancer capacity + group: setting-up + flavors: [route53] - name: route traffic type: script file: "$SERVICE_PATH/deployment/networking/gateway/route_traffic" + trace: false configuration: TEMPLATE: "$INGRESS_TEMPLATE" output: @@ -53,6 +76,7 @@ steps: - name: create deployment type: script file: "$SERVICE_PATH/deployment/build_deployment" + trace: false output: - name: DEPLOYMENT_PATH type: file @@ -69,6 +93,9 @@ steps: - name: apply type: script file: "$SERVICE_PATH/apply_templates" + trace: + title: Apply manifests + group: setting-up configuration: ACTION: apply DRY_RUN: false @@ -79,17 +106,27 @@ steps: - name: notify_active_domains type: script file: "$SERVICE_PATH/deployment/notify_active_domains" + trace: false - name: verify_networking_reconciliation type: script file: "$SERVICE_PATH/deployment/verify_networking_reconciliation" + trace: + title: Verify networking + group: setting-up + flavors: [route53, external_dns] configuration: VERIFY_WEIGHTS: false - name: publish_alb_metrics type: script file: "$SERVICE_PATH/deployment/publish_alb_metrics" + trace: false - name: wait deployment active type: script file: "$SERVICE_PATH/deployment/wait_deployment_active" + trace: + key: wait-for-instances + title: Instance health check + group: waiting-instances configuration: TIMEOUT: DEPLOYMENT_MAX_WAIT_IN_SECONDS diff --git a/k8s/deployment/workflows/kill_instance.yaml b/k8s/deployment/workflows/kill_instance.yaml index 74f8427c..b3942a7c 100644 --- a/k8s/deployment/workflows/kill_instance.yaml +++ b/k8s/deployment/workflows/kill_instance.yaml @@ -1,9 +1,12 @@ +trace: + title: Kill an instance include: - "$SERVICE_PATH/values.yaml" steps: - name: load logging type: script file: "$SERVICE_PATH/logging" + trace: false output: - name: log type: function diff --git a/k8s/deployment/workflows/rollback.yaml b/k8s/deployment/workflows/rollback.yaml index 29a919b2..01c336f1 100644 --- a/k8s/deployment/workflows/rollback.yaml +++ b/k8s/deployment/workflows/rollback.yaml @@ -2,10 +2,24 @@ include: - "$SERVICE_PATH/values.yaml" configuration: INGRESS_TEMPLATE: "$INITIAL_INGRESS_PATH" +trace: + title: Roll back deployment + flavors: ["$K8S_FLAVOR", "$DNS_TYPE", "@context:providers.scope-configurations.deployment.deployment_strategy"] + default: false + job: + name: k8s-deployment-rollback + namespace: "@context:scope.provider" + labels: + entity: deployment + operation: rollback + scope.provider: "@context:scope.provider" + groups: + - {key: finalize, title: Finalize} steps: - name: load logging type: script file: "$SERVICE_PATH/logging" + trace: false output: - name: log type: function @@ -15,6 +29,7 @@ steps: - name: assume role type: script file: "$SERVICE_PATH/utils/assume_role_step" + trace: false output: - name: AWS_ACCESS_KEY_ID type: environment @@ -25,6 +40,7 @@ steps: - name: build context type: script file: "$SERVICE_PATH/deployment/build_context" + trace: false output: - name: CONTEXT type: environment @@ -41,7 +57,16 @@ steps: - name: update blue deployment type: script file: "$SERVICE_PATH/deployment/scale_deployments" + trace: + title: Restore previous deployment + description: Scales the previous version back up to full capacity. + flavors: [rolling] + group: finalize - name: rollback traffic + trace: + title: Restore traffic routing + description: Rewrites the routing rules to send traffic back to the previous version. + group: finalize type: script file: "$SERVICE_PATH/deployment/networking/gateway/rollback_traffic" configuration: @@ -51,6 +76,10 @@ steps: type: file file: "$OUTPUT_DIR/ingress-$SCOPE_ID-$BLUE_DEPLOYMENT_ID.yaml" - name: apply traffic + trace: + title: Apply routing + description: Puts the restored routing live. + group: finalize type: script file: "$SERVICE_PATH/apply_templates" configuration: @@ -65,6 +94,7 @@ steps: # the failed deployment is deleted below. Weights cannot express this state. EXPECT_SINGLE_TARGET_GROUP: true - name: build deployment + trace: false type: script file: "$SERVICE_PATH/deployment/build_deployment" output: @@ -81,6 +111,10 @@ steps: type: file file: "$OUTPUT_DIR/service-$SCOPE_ID-$DEPLOYMENT_ID.yaml" - name: delete deployment + trace: + title: Remove new deployment + description: Deletes the version being rolled back, now that nothing routes to it. + group: finalize type: script file: "$SERVICE_PATH/apply_templates" configuration: @@ -93,5 +127,6 @@ steps: configuration: DEPLOYMENT: green - name: print_deployment_error_hints + trace: false type: script file: "$SERVICE_PATH/deployment/print_failed_deployment_hints" diff --git a/k8s/deployment/workflows/switch_traffic.yaml b/k8s/deployment/workflows/switch_traffic.yaml index ce9a9a67..a22b83cd 100644 --- a/k8s/deployment/workflows/switch_traffic.yaml +++ b/k8s/deployment/workflows/switch_traffic.yaml @@ -2,10 +2,24 @@ include: - "$SERVICE_PATH/values.yaml" configuration: INGRESS_TEMPLATE: "$BLUE_GREEN_INGRESS_PATH" +trace: + title: Switch traffic + flavors: ["$K8S_FLAVOR", "$DNS_TYPE"] + default: false + job: + name: k8s-deployment-switch-traffic + namespace: "@context:scope.provider" + labels: + entity: deployment + operation: switch-traffic + scope.provider: "@context:scope.provider" + groups: + - {key: switching-traffic, title: Switching traffic} steps: - name: load logging type: script file: "$SERVICE_PATH/logging" + trace: false output: - name: log type: function @@ -15,6 +29,7 @@ steps: - name: assume role type: script file: "$SERVICE_PATH/utils/assume_role_step" + trace: false output: - name: AWS_ACCESS_KEY_ID type: environment @@ -25,6 +40,7 @@ steps: - name: build context type: script file: "$SERVICE_PATH/deployment/build_context" + trace: false output: - name: CONTEXT type: environment @@ -45,11 +61,16 @@ steps: name: wait deployment active type: script file: "$SERVICE_PATH/deployment/wait_deployment_active" + trace: + key: switch-instances-check + title: Verify scaled instances + group: switching-traffic configuration: TIMEOUT: DEPLOYMENT_MAX_WAIT_IN_SECONDS - name: route traffic type: script file: "$SERVICE_PATH/deployment/networking/gateway/route_traffic" + trace: false configuration: type: ingress TEMPLATE: "$INGRESS_TEMPLATE" @@ -63,9 +84,14 @@ steps: - name: apply traffic type: script file: "$SERVICE_PATH/apply_templates" + trace: + key: traffic-switch + title: Switch traffic + group: switching-traffic configuration: ACTION: apply DRY_RUN: false + TRACE_TRAFFIC_SWITCH: true post: name: post_apply_checks type: workflow @@ -73,8 +99,13 @@ steps: - name: verify_networking_reconciliation type: script file: "$SERVICE_PATH/deployment/verify_networking_reconciliation" + trace: + title: Verify networking + group: switching-traffic + flavors: [route53, external_dns] configuration: VERIFY_WEIGHTS: true - name: publish_alb_metrics type: script file: "$SERVICE_PATH/deployment/publish_alb_metrics" + trace: false diff --git a/k8s/diagnose/tests/diagnose_utils.bats b/k8s/diagnose/tests/diagnose_utils.bats index 640ac395..a0d0fbd2 100644 --- a/k8s/diagnose/tests/diagnose_utils.bats +++ b/k8s/diagnose/tests/diagnose_utils.bats @@ -420,6 +420,60 @@ strip_ansi() { assert_contains "$clean" "⚠ No JSON result files found in $NP_OUTPUT_DIR" } +# --- the verdict reaches the TRACE, not only the results file ----------------- + +_stub_trace() { + np_scope_explain() { echo "EXPLAIN $*" >> "$TRACE_LOG"; } + np_scope_output() { echo "OUTPUT $1" >> "$TRACE_LOG"; } + export -f np_scope_explain np_scope_output + export TRACE_LOG="$(mktemp)" +} + +@test "diagnose_utils: a failed check states its finding on the step, with what to do" { + _stub_trace + evidence=$(evidence_json "1 of 1 pod(s) had OOMKilled containers" "critical" '["pod-a"]' '{}' \ + '["Increase memory limits or optimize application memory usage"]') + + update_check_result --status "failed" --evidence "$evidence" + + grep -q -- "--severity error" "$TRACE_LOG" + grep -q -- "OOMKilled containers" "$TRACE_LOG" + grep -q -- "--next Increase memory limits" "$TRACE_LOG" + grep -q "^OUTPUT check_evidence" "$TRACE_LOG" + rm -f "$TRACE_LOG" +} + +@test "diagnose_utils: a warning check reads as a warning, not an error" { + _stub_trace + evidence=$(evidence_json "2 pod(s) restarted recently" "warning" '[]' '{}' '[]') + + update_check_result --status "warning" --evidence "$evidence" + + grep -q -- "--severity warn" "$TRACE_LOG" + ! grep -q -- "--severity error" "$TRACE_LOG" + rm -f "$TRACE_LOG" +} + +@test "diagnose_utils: a passing check says nothing — a clean run is not 21 lines of green" { + _stub_trace + evidence=$(evidence_json "No OOMKilled containers detected in 1 pod(s)" "info" '[]' '{}' '[]') + + update_check_result --status "success" --evidence "$evidence" + + [ ! -s "$TRACE_LOG" ] + rm -f "$TRACE_LOG" +} + +@test "diagnose_utils: the results file is still written when the workflow is untraced" { + evidence=$(evidence_json "1 of 1 pod(s) had OOMKilled containers" "critical" '["pod-a"]' '{}' '[]') + + run update_check_result --status "failed" --evidence "$evidence" + + [ "$status" -eq 0 ] + assert_equal "$(jq -r '.status' "$SCRIPT_OUTPUT_FILE")" "failed" + assert_contains "$(jq -r '.evidence.summary' "$SCRIPT_OUTPUT_FILE")" "OOMKilled" +} + @test "notify_results: sends payloads larger than the argv limit" { # 2 MB of log text in one check: past the argv limit on both Linux and macOS. local line diff --git a/k8s/diagnose/utils/diagnose_utils b/k8s/diagnose/utils/diagnose_utils index 9cd02f91..43557c3c 100644 --- a/k8s/diagnose/utils/diagnose_utils +++ b/k8s/diagnose/utils/diagnose_utils @@ -329,6 +329,27 @@ update_check_result() { fi mv "$tmpfile" "$output_file" + + _np_trace_check_result "$status_lower" "$evidence" +} + +_np_trace_check_result() { + local _cr_status="$1" _cr_evidence="$2" _cr_severity="" _cr_summary="" _cr_action="" + command -v np_scope_explain >/dev/null 2>&1 || return 0 + + case "$_cr_status" in + failed) _cr_severity="error" ;; + warning) _cr_severity="warn" ;; + *) return 0 ;; + esac + + _cr_summary=$(printf '%s' "$_cr_evidence" | jq -r '.summary // empty' 2>/dev/null) || _cr_summary="" + _cr_action=$(printf '%s' "$_cr_evidence" | jq -r '(.suggested_actions // [])[0] // empty' 2>/dev/null) || _cr_action="" + [ -n "$_cr_summary" ] || return 0 + + np_scope_explain --severity "$_cr_severity" --what "$_cr_summary" ${_cr_action:+--next "$_cr_action"} + np_scope_output check_evidence "$_cr_evidence" 2>/dev/null || true + return 0 } notify_results() { diff --git a/k8s/logging b/k8s/logging index d0df55d7..2d1c62cf 100644 --- a/k8s/logging +++ b/k8s/logging @@ -38,4 +38,318 @@ log() { echo "$message" fi fi + + if [ "$msg_num" -ge 3 ]; then + _np_scopes_trace_error "$message" || true + fi +} + +_np_scopes_node() { + command -v np_trace_adopt >/dev/null 2>&1 || return 1 + [ -n "${NP_TRACE:-}" ] || return 1 + if [ -n "${_NP_SCOPES_SUBSTEP:-}" ]; then + if [ "${_NP_SCOPES_SUBSTEP_UNDER:-}" = "$NP_TRACE" ]; then + printf '%s' "$_NP_SCOPES_SUBSTEP" + return 0 + fi + _NP_SCOPES_SUBSTEP="" _NP_SCOPES_SUBSTEP_UNDER="" + fi + local _nd_node _nd_under _nd_cached + if [ -n "${NP_TRACE_DIR:-}" ] && [ -f "$NP_TRACE_DIR/scopes_adopted" ]; then + IFS=' ' read -r _nd_under _nd_cached < "$NP_TRACE_DIR/scopes_adopted" 2>/dev/null || true + if [ "$_nd_under" = "$NP_TRACE" ] && [ -n "$_nd_cached" ]; then + printf '%s' "$_nd_cached" + return 0 + fi + fi + _nd_node=$(np_trace_adopt 2>/dev/null) || return 1 + [ -n "$_nd_node" ] || return 1 + if [ -n "${NP_TRACE_DIR:-}" ]; then + printf '%s %s' "$NP_TRACE" "$_nd_node" > "$NP_TRACE_DIR/scopes_adopted" 2>/dev/null || true + fi + printf '%s' "$_nd_node" + return 0 +} + +_np_scopes_trace_error() { + local _lt_node _lt_message + _lt_node=$(_np_scopes_node) || return 0 + _lt_message="$1" + _lt_message="${_lt_message#"${_lt_message%%[![:space:]]*}"}" + case "$_lt_message" in "❌ "*) _lt_message="${_lt_message#❌ }" ;; esac + if [ "${_NP_SCOPES_ERRED_ON:-}" = "${NP_TRACE:-}" ] && [ -n "${_NP_SCOPES_ERR_MESSAGE:-}" ]; then + if [ -n "${_NP_SCOPES_ERR_HINTS:-}" ]; then + _NP_SCOPES_ERR_HINTS="$_NP_SCOPES_ERR_HINTS,$(np__json_str "$_lt_message")" + else + _NP_SCOPES_ERR_HINTS="$(np__json_str "$_lt_message")" + fi + np_trace_error "$_lt_node" --message "$_NP_SCOPES_ERR_MESSAGE" \ + --details "{\"hints\":[$_NP_SCOPES_ERR_HINTS]}" + return 0 + fi + np_trace_error "$_lt_node" --message "$_lt_message" ${2:+--code "$2"} + if [ -z "${_NP_SCOPES_TRAP_REPORT:-}" ] && command -v np_step_error >/dev/null 2>&1; then + np_step_error "$_lt_message" + fi + _NP_SCOPES_ERRED_ON="${NP_TRACE:-}" + _NP_SCOPES_LAST_REASON="$_lt_message" + _NP_SCOPES_ERR_MESSAGE="$_lt_message" + _NP_SCOPES_ERR_HINTS="" + return 0 +} + +# np_scope_step_begin [--iteration N] [--attempt N] [--title ] +np_scope_step_begin() { + command -v np_trace_adopt >/dev/null 2>&1 || return 0 + [ -n "${NP_TRACE:-}" ] || return 0 + local _sb_key="${1:-}" _sb_title="" _sb_parent _sb_h + shift || true + local _sb_args=() + while [ "$#" -gt 0 ]; do + case "$1" in + --title) _sb_title="${2:-}"; shift 2 ;; + *) _sb_args+=("$1"); shift ;; + esac + done + [ -n "${_NP_SCOPES_SUBSTEP:-}" ] && np_scope_step_end 0 + _sb_parent=$(np_trace_adopt 2>/dev/null) || return 0 + [ -n "$_sb_parent" ] || return 0 + _sb_h=$(np_trace_step "$_sb_parent" "$_sb_key" ${_sb_args[@]+"${_sb_args[@]}"}) + [ -n "$_sb_h" ] || return 0 + [ -n "$_sb_title" ] && np_trace_explain "$_sb_h" --title "$_sb_title" + _NP_SCOPES_SUBSTEP="$_sb_h" + _NP_SCOPES_SUBSTEP_UNDER="$NP_TRACE" + return 0 +} + +# np_scope_step_end [rc] [message] +np_scope_step_end() { + [ -n "${_NP_SCOPES_SUBSTEP:-}" ] || return 0 + local _se_h="$_NP_SCOPES_SUBSTEP" _se_rc="${1:-0}" + _NP_SCOPES_SUBSTEP="" _NP_SCOPES_SUBSTEP_UNDER="" + if [ "$_se_rc" -eq 0 ] 2>/dev/null; then + np_trace_complete "$_se_h" + else + if [ -n "${2:-}" ]; then + np_trace_fail "$_se_h" "$2" + elif [ "${_NP_SCOPES_ERRED_ON:-}" != "${NP_TRACE:-}" ]; then + np_trace_fail "$_se_h" "phase exited with status $_se_rc" + else + np_trace_fail "$_se_h" + fi + _NP_SCOPES_ERRED_ON="${NP_TRACE:-}" + fi + NP_TRACE_FLUSH_TIMEOUT=2 np_trace_flush + return 0 +} + +# np_scope_step_timeout [message] +np_scope_step_timeout() { + [ -n "${_NP_SCOPES_SUBSTEP:-}" ] || return 0 + local _st_h="$_NP_SCOPES_SUBSTEP" + _NP_SCOPES_SUBSTEP="" _NP_SCOPES_SUBSTEP_UNDER="" + [ -n "${1:-}" ] && np_trace_error "$_st_h" --message "$1" + np_trace_timeout "$_st_h" + NP_TRACE_FLUSH_TIMEOUT=2 np_trace_flush + return 0 +} + +# np_scope_wait_heartbeat [state] [k=v ...] +np_scope_wait_heartbeat() { + local _hb_node + _hb_node=$(_np_scopes_node) || return 0 + local _hb_what="${1:-}" _hb_timeout="${3:-0}" + case "$_hb_timeout" in + '' | *[!0-9]*) np_trace_signal "$_hb_node" "$_hb_what" wait ;; + *) np_trace_signal "$_hb_node" "$_hb_what" wait --timeout-ms $(( _hb_timeout * 1000 )) ;; + esac + np_trace_waiting "$_hb_node" + NP_TRACE_FLUSH_TIMEOUT=2 np_trace_flush + return 0 +} + +# np_scope_produces [ ] +# np_scope_consumes [ ] +np_scope_produces() { + command -v np_trace_produces >/dev/null 2>&1 || return 0 + local _pd_node + _pd_node=$(_np_scopes_node) || return 0 + np_trace_produces "$_pd_node" "$1" ${2:+--name "$2"} ${3:+--uri "$3"} + return 0 +} + +np_scope_consumes() { + command -v np_trace_consumes >/dev/null 2>&1 || return 0 + local _cd_node + _cd_node=$(_np_scopes_node) || return 0 + np_trace_consumes "$_cd_node" "$1" ${2:+--name "$2"} ${3:+--uri "$3"} + return 0 +} + +# np_scope_affordance +np_scope_affordance() { + command -v np_trace_affordances >/dev/null 2>&1 || return 0 + local _ad_node + _ad_node=$(_np_scopes_node) || return 0 + np_trace_affordances "$_ad_node" "$1" + return 0 +} + +# np_scope_progress [unit] +np_scope_progress() { + command -v np_trace_progress >/dev/null 2>&1 || return 0 + local _pg_node + _pg_node=$(_np_scopes_node) || return 0 + np_trace_progress "$_pg_node" "$1" "$2" "${3:-}" + return 0 +} + +# np_scope_output / np_scope_input +np_scope_output() { + command -v np_trace_output >/dev/null 2>&1 || return 0 + local _ot_node + _ot_node=$(_np_scopes_node) || return 0 + np_trace_output "$_ot_node" "$1" "$2" + return 0 +} + +np_scope_input() { + command -v np_trace_input >/dev/null 2>&1 || return 0 + local _in_node + _in_node=$(_np_scopes_node) || return 0 + np_trace_input "$_in_node" "$1" "$2" + return 0 +} + +# np_scope_explain --title T [--what W] [--severity ok|warn|error] ... +np_scope_explain() { + command -v np_trace_explain >/dev/null 2>&1 || return 0 + local _ex_node + _ex_node=$(_np_scopes_node) || return 0 + np_trace_explain "$_ex_node" "$@" + return 0 +} + +# np_scope_error [] +np_scope_error() { + command -v np_trace_error >/dev/null 2>&1 || return 0 + local _sr_node + _sr_node=$(_np_scopes_node) || return 0 + np_trace_error "$_sr_node" --message "$1" ${2:+--details "$2"} + _NP_SCOPES_ERRED_ON="${NP_TRACE:-}" + return 0 +} + +# np_scope_labels +np_scope_labels() { + command -v np_trace_labels >/dev/null 2>&1 || return 0 + local _lb_node + _lb_node=$(_np_scopes_node) || return 0 + np_trace_labels "$_lb_node" "$@" + return 0 } + +# np_scope_k8s_applied +np_scope_k8s_applied() { + command -v np_trace_produces >/dev/null 2>&1 || return 0 + local _ka_ns="$1" _ka_line _ka_kind _ka_name + [ -n "$_ka_ns" ] || return 0 + while IFS= read -r _ka_line; do + [ -n "$_ka_line" ] || continue + _ka_kind="${_ka_line%%/*}" + _ka_name="${_ka_line#*/}" + _ka_name="${_ka_name%% *}" + case "$_ka_kind" in + deployment.apps|deployment) + np_scope_produces "k8s-deployment:$_ka_ns/$_ka_name" deployment "$_ka_name" ;; + service) + np_scope_produces "k8s-service:$_ka_ns/$_ka_name" service "$_ka_name" ;; + ingress.networking.k8s.io|ingress) + np_scope_produces "k8s-ingress:$_ka_ns/$_ka_name" ingress "$_ka_name" ;; + esac + done <<< "$2" + return 0 +} + + +# np_scope_k8s_deleted +np_scope_k8s_deleted() { + command -v np_trace_output >/dev/null 2>&1 || return 0 + local _kd_ns="$1" _kd_node _kd_line _kd_kind _kd_name + [ -n "$_kd_ns" ] || return 0 + _kd_node=$(_np_scopes_node) || return 0 + while IFS= read -r _kd_line; do + [ -n "$_kd_line" ] || continue + case "$_kd_line" in + *" deleted") ;; + *) continue ;; + esac + _kd_kind="${_kd_line%%[ /]*}" + _kd_name="${_kd_line#*\"}" + _kd_name="${_kd_name%%\"*}" + [ -n "$_kd_name" ] || continue + case "$_kd_kind" in + deployment.apps|deployment) + np_trace_output "$_kd_node" removed-deployment --uri "$_kd_name" ;; + service) + np_trace_output "$_kd_node" removed-service --uri "$_kd_name" ;; + ingress.networking.k8s.io|ingress) + np_trace_output "$_kd_node" removed-ingress --uri "$_kd_name" ;; + esac + done <<< "$2" + return 0 +} + +_np_scopes_on_err() { + _NP_SCOPES_LAST_ERR="$BASH_COMMAND (exit ${1:-1})" +} + +_np_scopes_error_on_run() { + command -v np_trace_adopt >/dev/null 2>&1 || return 0 + [ -n "${NP_TRACE:-}" ] || return 0 + local _ru_rest="${NP_TRACE#*|}" + local _ru_version="${NP_TRACE%%|*}" _ru_trace="${_ru_rest%%|*}" _ru_run="${_ru_rest#*|}" + case "$_ru_run" in + *~*) _ru_run="${_ru_run%~*}" ;; + *) return 0 ;; + esac + local _ru_node + _ru_node=$(np_trace_adopt "${_ru_version}|${_ru_trace}|${_ru_run}" 2>/dev/null) || return 0 + [ -n "$_ru_node" ] || return 0 + np_trace_error "$_ru_node" --message "$1" + return 0 +} + +_np_scopes_on_exit() { + local _ex_rc="${1:-0}" + local _ex_reason="${_NP_SCOPES_LAST_REASON:-${_NP_SCOPES_LAST_ERR:-workflow shell exited with status $_ex_rc}}" + if [ "$_ex_rc" -ne 0 ] && [ "${_NP_SCOPES_ERRED_ON:-}" != "${NP_TRACE:-}" ]; then + _NP_SCOPES_TRAP_REPORT=1 + _np_scopes_trace_error "$_ex_reason" || true + _NP_SCOPES_TRAP_REPORT="" + fi + if [ "$_ex_rc" -ne 0 ]; then + _np_scopes_error_on_run "$_ex_reason" || true + fi + [ -n "${_NP_SCOPES_SUBSTEP:-}" ] && np_scope_step_end "$_ex_rc" || true + np_trace_flush +} + +_NP_SCOPES_ROOT="$(cd "$(dirname "${BASH_SOURCE[0]}")/.." && pwd)" +_NP_SCOPES_SDK="$_NP_SCOPES_ROOT/vendor/catalog-tracing-sh/nptrace.sh" +[ -f "$_NP_SCOPES_SDK" ] || _NP_SCOPES_SDK="$_NP_SCOPES_ROOT/nptrace.sh" +if [ -z "${NP_TRACE_LOADED:-}" ] \ + && [ -f "$_NP_SCOPES_SDK" ] \ + && [ -n "${NP_API_KEY:-}" ] \ + && [ -n "${NP_TRACE:-}" ]; then + # shellcheck source=/dev/null + . "$_NP_SCOPES_SDK" + np_trace_init --producer "nullplatform-scopes@1" --api-key "$NP_API_KEY" --no-trap + trap '_np_scopes_on_err $?' ERR + trap '_np_scopes_on_exit $?' EXIT +elif [ -z "${NP_TRACE_LOADED:-}" ] \ + && [ -n "${NP_TRACE:-}" ] \ + && [ -n "${NP_API_KEY:-}" ] \ + && [ ! -f "$_NP_SCOPES_SDK" ]; then + log warn "⚠️ tracing SDK not bundled (vendor/catalog-tracing-sh/nptrace.sh missing) — scope-side tracing disabled for this run" +fi diff --git a/k8s/scope/build_context b/k8s/scope/build_context index 0650f897..8682995a 100755 --- a/k8s/scope/build_context +++ b/k8s/scope/build_context @@ -126,6 +126,9 @@ if ! kubectl get namespace "$K8S_NAMESPACE" &> /dev/null; then kubectl apply -f - log info " ✅ Namespace '$K8S_NAMESPACE' created successfully" + if command -v np_scope_produces >/dev/null 2>&1; then + np_scope_produces "k8s-namespace:$K8S_NAMESPACE" namespace "$K8S_NAMESPACE" + fi else log error "" log error "💡 Possible causes:" @@ -139,6 +142,9 @@ if ! kubectl get namespace "$K8S_NAMESPACE" &> /dev/null; then fi else log info " ✅ Namespace '$K8S_NAMESPACE' exists" + if command -v np_step_skip >/dev/null 2>&1; then + np_step_skip "namespace '$K8S_NAMESPACE' already exists" + fi fi USE_ACCOUNT_SLUG=$(get_config_value \ diff --git a/k8s/scope/iam/build_service_account b/k8s/scope/iam/build_service_account index 64a7511b..a3abb200 100644 --- a/k8s/scope/iam/build_service_account +++ b/k8s/scope/iam/build_service_account @@ -21,7 +21,7 @@ ROLE_ARN=$(aws iam get-role --role-name "$SERVICE_ACCOUNT_NAME" --query 'Role.Ar return 0 fi - log error " ❌ Failed to find IAM role '$SERVICE_ACCOUNT_NAME'" + log error " ❌ Failed to find IAM role '$SERVICE_ACCOUNT_NAME'${ROLE_ARN:+: $ROLE_ARN}" log error "" log error "💡 Possible causes:" log error " The IAM role may not exist or the agent lacks IAM permissions" @@ -39,10 +39,10 @@ SERVICE_ACCOUNT_PATH="$OUTPUT_DIR/service_account-$SCOPE_ID.yaml" echo "$CONTEXT" | jq --arg role_arn "$ROLE_ARN" --arg service_account_name "$SERVICE_ACCOUNT_NAME" '. + {role_arn: $role_arn, service_account_name: $service_account_name}' > "$CONTEXT_PATH" log debug "📝 Building service account template: $SERVICE_ACCOUNT_TEMPLATE" -gomplate -c .="$CONTEXT_PATH" \ +GOMPLATE_OUT=$(gomplate -c .="$CONTEXT_PATH" \ --file "$SERVICE_ACCOUNT_TEMPLATE" \ - --out "$SERVICE_ACCOUNT_PATH" || { - log error " ❌ Failed to build service account template" + --out "$SERVICE_ACCOUNT_PATH" 2>&1) || { + log error " ❌ Failed to build service account template${GOMPLATE_OUT:+: $GOMPLATE_OUT}" log error "" log error "💡 Possible causes:" log error " The template file may be missing or contain invalid gomplate syntax" diff --git a/k8s/scope/iam/create_role b/k8s/scope/iam/create_role index 2307c703..896ead48 100644 --- a/k8s/scope/iam/create_role +++ b/k8s/scope/iam/create_role @@ -17,7 +17,7 @@ ROLE_PATH="/nullplatform/custom-scopes/" NAMESPACE=$(echo "$CONTEXT" | jq -r .k8s_namespace) log debug "🔍 Getting EKS OIDC provider for cluster: $CLUSTER_NAME" OIDC_PROVIDER=$(aws eks describe-cluster --name "$CLUSTER_NAME" --query "cluster.identity.oidc.issuer" --output text 2>&1 | sed -e "s/^https:\/\///") || { - log error " ❌ Failed to get OIDC provider for EKS cluster '$CLUSTER_NAME'" + log error " ❌ Failed to get OIDC provider for EKS cluster '$CLUSTER_NAME'${OIDC_PROVIDER:+: $OIDC_PROVIDER}" log error "" log error "💡 Possible causes:" log error " The OIDC provider may not be configured for this EKS cluster" @@ -31,7 +31,7 @@ OIDC_PROVIDER=$(aws eks describe-cluster --name "$CLUSTER_NAME" --query "cluster log debug "🔍 Getting AWS account ID..." AWS_ACCOUNT_ID=$(aws sts get-caller-identity --query Account --output text 2>&1) || { - log error " ❌ Failed to get AWS account ID" + log error " ❌ Failed to get AWS account ID${AWS_ACCOUNT_ID:+: $AWS_ACCOUNT_ID}" log error "" log error "💡 Possible causes:" log error " AWS credentials may not be configured or have expired" @@ -100,7 +100,7 @@ if [[ -n "$DIMENSIONS" && "$DIMENSIONS" != "null" ]]; then fi create_role_error() { - log error " ❌ Failed to create IAM role '$ROLE_NAME'" + log error " ❌ Failed to create IAM role '$ROLE_NAME'${CREATE_ROLE_OUT:+: $CREATE_ROLE_OUT}" log error "" log error "💡 Possible causes:" log error " The role may already exist or the agent lacks IAM permissions" @@ -127,7 +127,8 @@ if [[ -n "$BOUNDARY_ARN" && "$BOUNDARY_ARN" != "null" ]]; then CREATE_ROLE_ARGS+=(--permissions-boundary "$BOUNDARY_ARN") fi -aws iam create-role "${CREATE_ROLE_ARGS[@]}" || create_role_error +CREATE_ROLE_OUT=$(aws iam create-role "${CREATE_ROLE_ARGS[@]}" 2>&1) || create_role_error +[[ -n "$CREATE_ROLE_OUT" ]] && echo "$CREATE_ROLE_OUT" log info " ✅ IAM role created successfully" rm "$TRUST_POLICY_PATH" @@ -141,10 +142,10 @@ for ((i=0; i<$POLICIES_COUNT; i++)); do if [[ "$POLICY_TYPE" == "arn" ]]; then log debug "📝 Attaching managed policy: $POLICY_VALUE" - aws iam attach-role-policy \ + ATTACH_POLICY_OUT=$(aws iam attach-role-policy \ --role-name "$ROLE_NAME" \ - --policy-arn "$POLICY_VALUE" || { - log error " ❌ Failed to attach managed policy: $POLICY_VALUE" + --policy-arn "$POLICY_VALUE" 2>&1) || { + log error " ❌ Failed to attach managed policy: $POLICY_VALUE${ATTACH_POLICY_OUT:+ — $ATTACH_POLICY_OUT}" log error "" log error "💡 Possible causes:" log error " The policy ARN may be invalid or the agent lacks IAM permissions" @@ -155,6 +156,7 @@ for ((i=0; i<$POLICIES_COUNT; i++)); do log error "" exit 1 } + [[ -n "$ATTACH_POLICY_OUT" ]] && echo "$ATTACH_POLICY_OUT" log info " ✅ Successfully attached managed policy: $POLICY_VALUE" elif [[ "$POLICY_TYPE" == "inline" ]]; then @@ -164,11 +166,11 @@ for ((i=0; i<$POLICIES_COUNT; i++)); do TEMP_POLICY_FILE="$OUTPUT_DIR/inline-policy-$i.json" echo "$POLICY_VALUE" > "$TEMP_POLICY_FILE" - aws iam put-role-policy \ + PUT_POLICY_OUT=$(aws iam put-role-policy \ --role-name "$ROLE_NAME" \ --policy-name "$POLICY_NAME" \ - --policy-document "file://$TEMP_POLICY_FILE" || { - log error " ❌ Failed to attach inline policy: $POLICY_NAME" + --policy-document "file://$TEMP_POLICY_FILE" 2>&1) || { + log error " ❌ Failed to attach inline policy: $POLICY_NAME${PUT_POLICY_OUT:+ — $PUT_POLICY_OUT}" log error "" log error "💡 Possible causes:" log error " The inline policy JSON may be invalid or the agent lacks IAM permissions" @@ -180,6 +182,7 @@ for ((i=0; i<$POLICIES_COUNT; i++)); do rm -f "$TEMP_POLICY_FILE" exit 1 } + [[ -n "$PUT_POLICY_OUT" ]] && echo "$PUT_POLICY_OUT" log info " ✅ Successfully attached inline policy: $POLICY_NAME" rm -f "$TEMP_POLICY_FILE" diff --git a/k8s/scope/iam/delete_role b/k8s/scope/iam/delete_role index eac8dbaf..81a0f458 100755 --- a/k8s/scope/iam/delete_role +++ b/k8s/scope/iam/delete_role @@ -19,7 +19,7 @@ ROLE_ARN=$(aws iam get-role --role-name "$SERVICE_ACCOUNT_NAME" --query 'Role.Ar return 0 fi - log error " ❌ Failed to find IAM role '$SERVICE_ACCOUNT_NAME'" + log error " ❌ Failed to find IAM role '$SERVICE_ACCOUNT_NAME'${ROLE_ARN:+: $ROLE_ARN}" log error "" log error "💡 Possible causes:" log error " The IAM role may not exist or the agent lacks IAM permissions" diff --git a/k8s/scope/networking/dns/manage_dns b/k8s/scope/networking/dns/manage_dns index 6d7538c3..82540a29 100755 --- a/k8s/scope/networking/dns/manage_dns +++ b/k8s/scope/networking/dns/manage_dns @@ -70,3 +70,8 @@ case "$DNS_TYPE" in esac log info "✅ DNS records managed successfully" + +if [ "${ACTION:-}" = "CREATE" ] && [ -n "${SCOPE_DOMAIN:-}" ] \ + && command -v np_scope_produces >/dev/null 2>&1; then + np_scope_produces "dns-record:$SCOPE_DOMAIN" dns_record "$SCOPE_DOMAIN" +fi diff --git a/k8s/scope/networking/wait_for_alb b/k8s/scope/networking/wait_for_alb index 0909f39a..e586493f 100644 --- a/k8s/scope/networking/wait_for_alb +++ b/k8s/scope/networking/wait_for_alb @@ -24,6 +24,9 @@ # time out and fail the scope creation. if [ "${DNS_TYPE:-}" != "route53" ]; then log debug "📋 DNS type is '${DNS_TYPE:-unset}', skipping ALB active-state wait" + if command -v np_step_skip >/dev/null 2>&1; then + np_step_skip "no ALB on DNS type '${DNS_TYPE:-unset}'" + fi return 0 2>/dev/null || exit 0 fi @@ -49,6 +52,10 @@ polls_since_heartbeat=0 heartbeats_emitted=0 log info "⏳ Waiting up to ${TIMEOUT_SECONDS}s for ALB '$ALB_NAME' to become active..." +if command -v np_scope_step_begin >/dev/null 2>&1; then + np_scope_step_begin wait-alb-active --title "Wait for ALB '$ALB_NAME' to become active" + np_scope_wait_heartbeat "alb-active" 0 "$TIMEOUT_SECONDS" "pending" +fi state="" alb_arn="" @@ -80,6 +87,9 @@ while [ "$(date +%s)" -lt "$deadline" ]; do heartbeats_emitted=$((heartbeats_emitted + 1)) elapsed=$((heartbeats_emitted * polls_per_heartbeat * poll_interval)) log info "⏳ Still waiting for ALB '$ALB_NAME' to become active (${state:-pending}, ~${elapsed}s elapsed)" + if command -v np_scope_wait_heartbeat >/dev/null 2>&1; then + np_scope_wait_heartbeat "alb-active" "$elapsed" "$TIMEOUT_SECONDS" "${state:-pending}" + fi polls_since_heartbeat=0 fi @@ -93,9 +103,22 @@ if [ "$state" != "active" ]; then log error "🔧 How to fix:" log error " • Check controller logs: kubectl -n kube-system logs deploy/aws-load-balancer-controller" log error " • Verify ALB quota: aws service-quotas get-service-quota --service-code elasticloadbalancing --quota-code L-53DA6B97" + if command -v np_scope_step_timeout >/dev/null 2>&1; then + np_scope_explain --title "Wait for ingress" --severity error \ + --what "Gave up waiting for ALB '$ALB_NAME' to become active (last state: ${state:-pending})" + np_scope_step_timeout "ALB '$ALB_NAME' not active after ${TIMEOUT_SECONDS}s (last state: ${state:-pending})" + fi exit 1 fi +if [ -n "$alb_arn" ] && command -v np_scope_consumes >/dev/null 2>&1; then + np_scope_consumes "load-balancer:$alb_arn" load_balancer "$alb_arn" +fi + +if command -v np_scope_step_end >/dev/null 2>&1; then + np_scope_step_end 0 +fi + # Audit tags — only on the scope that triggered the autocreate, so the cloud # carries the lineage of which scope created which ALB. Failure is non-fatal: # the provider registration (the authoritative source) already succeeded; the diff --git a/k8s/scope/require_resource b/k8s/scope/require_resource index a3daa10a..5785d6cb 100644 --- a/k8s/scope/require_resource +++ b/k8s/scope/require_resource @@ -55,8 +55,7 @@ find_deployment_by_label() { log debug "🔍 Looking for deployment with label: $label" DEPLOYMENT=$(kubectl get deployment -n "$namespace" -l "$label" -o jsonpath="{.items[0].metadata.name}" 2>&1) || { - log error " ❌ Failed to find deployment with label '$label' in namespace '$namespace'" - log debug "📋 Kubectl error: $DEPLOYMENT" + log error " ❌ Failed to find deployment with label '$label' in namespace '$namespace'${DEPLOYMENT:+: $DEPLOYMENT}" DEPLOYMENT="" } diff --git a/k8s/scope/wait_on_balancer b/k8s/scope/wait_on_balancer index bde5cfec..3e0cee1d 100644 --- a/k8s/scope/wait_on_balancer +++ b/k8s/scope/wait_on_balancer @@ -18,6 +18,11 @@ case "$DNS_TYPE" in log debug "📋 Checking ExternalDNS record creation for domain: $SCOPE_DOMAIN" + if command -v np_scope_step_begin >/dev/null 2>&1; then + np_scope_step_begin wait-dns-endpoint --title "Wait for ExternalDNS to process $DNS_ENDPOINT_NAME" + np_scope_wait_heartbeat "dns-endpoint" 0 "$((MAX_ITERATIONS * 10))" "pending" + fi + while true; do iteration=$((iteration + 1)) if [ $iteration -gt $MAX_ITERATIONS ]; then @@ -31,6 +36,9 @@ case "$DNS_TYPE" in log error " • Check DNSEndpoint resources: kubectl get dnsendpoint -A" log error " • Check ExternalDNS logs: kubectl logs -n external-dns -l app=external-dns --tail=50" log error "" + if command -v np_scope_step_timeout >/dev/null 2>&1; then + np_scope_step_timeout "DNSEndpoint $DNS_ENDPOINT_NAME not processed after $((MAX_ITERATIONS * 10))s" + fi exit 1 fi @@ -44,19 +52,33 @@ case "$DNS_TYPE" in break fi + if [ $((iteration % 3)) -eq 0 ] && command -v np_scope_wait_heartbeat >/dev/null 2>&1; then + np_scope_wait_heartbeat "dns-endpoint" "$((iteration * 10))" "$((MAX_ITERATIONS * 10))" "pending" + fi + log debug "📋 DNSEndpoint not yet processed, waiting 10s..." sleep 10 done + if command -v np_scope_step_end >/dev/null 2>&1; then + np_scope_step_end 0 + fi + log info "" log info "✨ ExternalDNS setup completed successfully" ;; route53|azure) log debug "📋 DNS Type $DNS_TYPE - DNS should already be configured" log debug "📋 Skipping DNS wait check" + if command -v np_step_skip >/dev/null 2>&1; then + np_step_skip "DNS already configured for type '$DNS_TYPE'" + fi ;; *) log debug "📋 Unknown DNS type: $DNS_TYPE" log debug "📋 Skipping DNS wait check" + if command -v np_step_skip >/dev/null 2>&1; then + np_step_skip "no DNS wait for type '$DNS_TYPE'" + fi ;; esac diff --git a/k8s/scope/workflows/create.yaml b/k8s/scope/workflows/create.yaml index 69afe2c8..76bb082c 100644 --- a/k8s/scope/workflows/create.yaml +++ b/k8s/scope/workflows/create.yaml @@ -1,9 +1,20 @@ include: - "$SERVICE_PATH/values.yaml" +trace: + title: Create scope + flavors: ["$K8S_FLAVOR", "$DNS_TYPE"] + job: + name: k8s-scope-create + namespace: "@context:scope.provider" + labels: + entity: scope + operation: create + scope.provider: "@context:scope.provider" steps: - name: load logging type: script file: "$SERVICE_PATH/logging" + trace: false output: - name: log type: function @@ -13,6 +24,7 @@ steps: - name: assume role type: script file: "$SERVICE_PATH/utils/assume_role_step" + trace: false output: - name: AWS_ACCESS_KEY_ID type: environment @@ -23,6 +35,10 @@ steps: - name: build context type: script file: "$SERVICE_PATH/scope/build_context" + trace: + key: create-namespace + title: Create namespace + optional: true output: - name: CONTEXT type: environment @@ -39,6 +55,9 @@ steps: - name: apply autocreated ingress type: script file: "$SERVICE_PATH/apply_templates" + trace: + key: create-ingress + title: Create ingress configuration: ACTION: apply DRY_RUN: false @@ -46,18 +65,28 @@ steps: name: wait for alb type: script file: "$SERVICE_PATH/scope/networking/wait_for_alb" + trace: + key: wait-for-ingress + title: Wait for ingress + flavors: [route53] - name: validate alb capacity type: script file: "$SERVICE_PATH/scope/validate_alb_capacity" + trace: + title: Validate load balancer capacity + flavors: [route53] - name: iam type: workflow steps: - name: create role type: script file: "$SERVICE_PATH/scope/iam/create_role" + trace: + title: Create IAM role - name: build service account type: script file: "$SERVICE_PATH/scope/iam/build_service_account" + trace: false configuration: ACTION: create output: @@ -67,6 +96,9 @@ steps: - name: apply type: script file: "$SERVICE_PATH/apply_templates" + trace: + key: apply-service-account + title: Apply service account configuration: ACTION: apply DRY_RUN: false @@ -76,18 +108,23 @@ steps: - name: generate domain type: script file: "$SERVICE_PATH/scope/networking/dns/domain/generate_domain" + trace: false output: - name: SCOPE_DOMAIN type: environment - name: create dns type: script file: "$SERVICE_PATH/scope/networking/dns/manage_dns" + trace: + key: create-dns + title: Create DNS configuration: ACTION: CREATE pre: name: build dns context type: script file: "$SERVICE_PATH/scope/networking/dns/build_dns_context" + trace: false output: - name: HOSTED_PUBLIC_ZONE_ID type: environment @@ -100,9 +137,15 @@ steps: - name: apply dns templates type: script file: "$SERVICE_PATH/apply_templates" + trace: + key: apply-dns + title: Apply DNS records configuration: ACTION: apply DRY_RUN: false - name: wait on balancer type: script file: "$SERVICE_PATH/scope/wait_on_balancer" + trace: + title: Wait for load balancer + flavors: [external_dns] diff --git a/k8s/scope/workflows/delete.yaml b/k8s/scope/workflows/delete.yaml index e411bedb..8540b1c6 100644 --- a/k8s/scope/workflows/delete.yaml +++ b/k8s/scope/workflows/delete.yaml @@ -1,9 +1,20 @@ include: - "$SERVICE_PATH/values.yaml" +trace: + title: Delete scope + flavors: ["$K8S_FLAVOR", "$DNS_TYPE"] + job: + name: k8s-scope-delete + namespace: "@context:scope.provider" + labels: + entity: scope + operation: delete + scope.provider: "@context:scope.provider" steps: - name: load logging type: script file: "$SERVICE_PATH/logging" + trace: false output: - name: log type: function @@ -13,6 +24,7 @@ steps: - name: assume role type: script file: "$SERVICE_PATH/utils/assume_role_step" + trace: false output: - name: AWS_ACCESS_KEY_ID type: environment @@ -38,12 +50,15 @@ steps: - name: delete dns type: script file: "$SERVICE_PATH/scope/networking/dns/manage_dns" + trace: + title: Delete DNS records configuration: ACTION: DELETE pre: name: build dns context type: script file: "$SERVICE_PATH/scope/networking/dns/build_dns_context" + trace: false output: - name: HOSTED_PUBLIC_ZONE_ID type: environment @@ -55,6 +70,7 @@ steps: - name: build service account type: script file: "$SERVICE_PATH/scope/iam/build_service_account" + trace: false configuration: ACTION: delete output: @@ -64,9 +80,14 @@ steps: - name: apply type: script file: "$SERVICE_PATH/apply_templates" + trace: + key: remove-service-account + title: Remove service account configuration: ACTION: delete DRY_RUN: false - name: delete role type: script - file: "$SERVICE_PATH/scope/iam/delete_role" \ No newline at end of file + file: "$SERVICE_PATH/scope/iam/delete_role" + trace: + title: Delete IAM role \ No newline at end of file diff --git a/k8s/scope/workflows/diagnose.yaml b/k8s/scope/workflows/diagnose.yaml index 45d837c3..00eeea78 100644 --- a/k8s/scope/workflows/diagnose.yaml +++ b/k8s/scope/workflows/diagnose.yaml @@ -1,3 +1,5 @@ +trace: + title: Diagnose the scope continue_on_error: true include: - "$SERVICE_PATH/values.yaml" @@ -5,6 +7,7 @@ steps: - name: load_functions type: script file: "$SERVICE_PATH/diagnose/utils/diagnose_utils" + trace: false output: - name: update_check_result type: function @@ -16,6 +19,7 @@ steps: - name: build context type: script file: "$SERVICE_PATH/diagnose/build_context" + trace: false output: - name: CONTEXT type: environment @@ -27,10 +31,12 @@ steps: name: notify_check_running type: script file: "$SERVICE_PATH/diagnose/notify_check_running" + trace: false after_each: name: notify_check_results type: script file: "$SERVICE_PATH/diagnose/notify_diagnose_results" + trace: false folders: - "$SERVICE_PATH/diagnose/service" - "$SERVICE_PATH/diagnose/scope" diff --git a/k8s/scope/workflows/pause-autoscaling.yaml b/k8s/scope/workflows/pause-autoscaling.yaml index 362ef27c..70d65773 100644 --- a/k8s/scope/workflows/pause-autoscaling.yaml +++ b/k8s/scope/workflows/pause-autoscaling.yaml @@ -1,9 +1,12 @@ +trace: + title: Pause autoscaling include: - "$SERVICE_PATH/values.yaml" steps: - name: load logging type: script file: "$SERVICE_PATH/logging" + trace: false output: - name: log type: function diff --git a/k8s/scope/workflows/restart-pods.yaml b/k8s/scope/workflows/restart-pods.yaml index 7771041a..e6e40d7b 100644 --- a/k8s/scope/workflows/restart-pods.yaml +++ b/k8s/scope/workflows/restart-pods.yaml @@ -1,9 +1,12 @@ +trace: + title: Restart the instances include: - "$SERVICE_PATH/values.yaml" steps: - name: load logging type: script file: "$SERVICE_PATH/logging" + trace: false output: - name: log type: function diff --git a/k8s/scope/workflows/resume-autoscaling.yaml b/k8s/scope/workflows/resume-autoscaling.yaml index 8b155b68..21c7640e 100644 --- a/k8s/scope/workflows/resume-autoscaling.yaml +++ b/k8s/scope/workflows/resume-autoscaling.yaml @@ -1,9 +1,12 @@ +trace: + title: Resume autoscaling include: - "$SERVICE_PATH/values.yaml" steps: - name: load logging type: script file: "$SERVICE_PATH/logging" + trace: false output: - name: log type: function diff --git a/k8s/scope/workflows/set-desired-instance-count.yaml b/k8s/scope/workflows/set-desired-instance-count.yaml index 03e3ba0f..a5778f03 100644 --- a/k8s/scope/workflows/set-desired-instance-count.yaml +++ b/k8s/scope/workflows/set-desired-instance-count.yaml @@ -1,9 +1,12 @@ +trace: + title: Set the instance count include: - "$SERVICE_PATH/values.yaml" steps: - name: load logging type: script file: "$SERVICE_PATH/logging" + trace: false output: - name: log type: function diff --git a/k8s/scope/workflows/update.yaml b/k8s/scope/workflows/update.yaml index b1e48442..a715ea9b 100644 --- a/k8s/scope/workflows/update.yaml +++ b/k8s/scope/workflows/update.yaml @@ -1,5 +1,15 @@ include: - "$SERVICE_PATH/scope/workflows/create.yaml" +trace: + title: Update scope + flavors: ["$K8S_FLAVOR", "$DNS_TYPE"] + job: + name: k8s-scope-update + namespace: "@context:scope.provider" + labels: + entity: scope + operation: update + scope.provider: "@context:scope.provider" steps: - name: networking type: workflow diff --git a/k8s/utils/tests/trace_logging.bats b/k8s/utils/tests/trace_logging.bats new file mode 100644 index 00000000..fcbcf627 --- /dev/null +++ b/k8s/utils/tests/trace_logging.bats @@ -0,0 +1,451 @@ +#!/usr/bin/env bats +# Unit tests for the tracing hooks in k8s/logging + +setup() { + export PROJECT_ROOT="$(cd "$BATS_TEST_DIRNAME/../../.." && pwd)" + source "$PROJECT_ROOT/testing/assertions.sh" + + export LOGGING="$PROJECT_ROOT/k8s/logging" + + export NP_TRACE="1|trace-9|scope-provision-42~apply-manifests@0.0" + export NP_API_KEY="test-key" + export NP_TRACE_DIR="$BATS_TEST_TMPDIR/nptrace" + export NP_TRACE_BASE_URL="http://127.0.0.1:1" + export NP_TRACE_AUTH_URL="http://127.0.0.1:1" + export NP_TRACE_FLUSH_TIMEOUT=1 + export NP_TRACE_MAX_RETRIES=0 +} + +teardown() { + unset NP_TRACE NP_API_KEY NP_TRACE_DIR NP_TRACE_BASE_URL NP_TRACE_AUTH_URL + unset NP_TRACE_FLUSH_TIMEOUT NP_TRACE_MAX_RETRIES +} + +run_logged() { + run "$BASH" -c " + source '$LOGGING' + $1 + for f in \"\$NP_TRACE_DIR\"/spool/*.json \"\$NP_TRACE_DIR\"/failed/*.json; do + [ -f \"\$f\" ] && cat \"\$f\" && echo + done + true + " +} + +@test "log error lands as a tracing.error facet on the current step" { + run_logged 'log error "❌ kubectl apply failed: forbidden"' + [ "$status" -eq 0 ] + echo "$output" | grep -q '"run_id":"scope-provision-42~apply-manifests@0.0"' + echo "$output" | grep -q '"tracing.error"' + echo "$output" | grep -q 'kubectl apply failed: forbidden' +} + +@test "the error attaches to the step CURRENT at the moment it happened" { + run_logged ' + log error "first failure" + export NP_TRACE="1|trace-9|scope-provision-42~wait-for-alb@0.0" + log error "second failure" + ' + [ "$status" -eq 0 ] + echo "$output" | grep '"first failure"' | grep -q 'apply-manifests@0.0' + echo "$output" | grep '"second failure"' | grep -q 'wait-for-alb@0.0' +} + +@test "an uncaught command failure surfaces the failing command" { + run "$BASH" -c " + source '$LOGGING' + "$BASH" -c 'exit 7' # a real failing command, no log error anywhere + " || true + run "$BASH" -c " + source '$LOGGING' + trap - EXIT # neutralize for inspection after the inner shell + ( source '$LOGGING'; bash -c 'exit 7' ) || true + for f in \"\$NP_TRACE_DIR\"/spool/*.json \"\$NP_TRACE_DIR\"/failed/*.json; do + [ -f \"\$f\" ] && cat \"\$f\" && echo + done + true + " + [ "$status" -eq 0 ] + echo "$output" | grep -q '"tracing.error"' + echo "$output" | grep -q 'exit 7' +} + +@test "a log error already recorded is not shadowed by the exit trap" { + run "$BASH" -c " + ( source '$LOGGING'; log error 'the real reason'; exit 3 ) || true + source '$LOGGING'; trap - EXIT ERR + for f in \"\$NP_TRACE_DIR\"/spool/*.json \"\$NP_TRACE_DIR\"/failed/*.json; do + [ -f \"\$f\" ] && cat \"\$f\" && echo + done + true + " + [ "$status" -eq 0 ] + echo "$output" | grep -q 'the real reason' + [ "$(echo "$output" | grep 'apply-manifests@0.0"' | grep -c 'tracing.error')" -eq 1 ] +} + +@test "wait heartbeat marks the step waiting and states the signal it waits on" { + run_logged 'np_scope_wait_heartbeat "alb-active" 90 300 "pending"' + [ "$status" -eq 0 ] + echo "$output" | grep -q '"status":"waiting"' + echo "$output" | grep -q '"tracing.signal":{"name":"alb-active","direction":"wait","timeout_ms":300000}' +} + +@test "a wait with an unresolved timeout still states the wait, without a deadline" { + run_logged 'np_scope_wait_heartbeat "alb-active" 90 "MAX_WAIT" "pending"' + [ "$status" -eq 0 ] + echo "$output" | grep -q '"tracing.signal":{"name":"alb-active","direction":"wait"}' + ! echo "$output" | grep -q 'timeout_ms' +} + +@test "without NP_TRACE, logging is byte-identical to plain logging" { + unset NP_TRACE + run "$BASH" -c "source '$LOGGING'; log error 'plain'; log info 'hello'" + [ "$status" -eq 0 ] + [ "$output" = "plain +hello" ] + [ ! -d "$NP_TRACE_DIR/spool" ] || [ -z "$(ls -A "$NP_TRACE_DIR/spool" 2>/dev/null)" ] +} + +@test "without NP_API_KEY, logging is byte-identical to plain logging" { + unset NP_API_KEY + run "$BASH" -c "source '$LOGGING'; log error 'plain'" + [ "$status" -eq 0 ] + [ "$output" = "plain" ] + [ ! -d "$NP_TRACE_DIR/spool" ] || [ -z "$(ls -A "$NP_TRACE_DIR/spool" 2>/dev/null)" ] +} + +@test "heartbeat is a defined no-op when the workflow is untraced" { + unset NP_TRACE + run "$BASH" -c "source '$LOGGING'; np_scope_wait_heartbeat what 1 2; echo rc=\$?" + [ "$status" -eq 0 ] + [[ "$output" == *"rc=0"* ]] +} + +@test "stdout and stderr routing of log() is unchanged when traced" { + run "$BASH" -c "source '$LOGGING'; log info 'to-stdout' 2>/dev/null" + [[ "$output" == *"to-stdout"* ]] + run "$BASH" -c "source '$LOGGING'; log error 'to-stderr' 2>&1 >/dev/null" + [[ "$output" == *"to-stderr"* ]] +} + +# --- sub-steps -------------------------------------------------------------- + +@test "step_begin opens a keyed sub-step under the platform step" { + run_logged 'np_scope_step_begin wait-alb-active --title "Wait for the ALB"; np_scope_step_end 0' + [ "$status" -eq 0 ] + echo "$output" | grep -q '"run_id":"scope-provision-42~apply-manifests@0.0~wait-alb-active@0.0"' + echo "$output" | grep -q '"status":"started"' + echo "$output" | grep -q 'Wait for the ALB' +} + +@test "step_end 0 completes the sub-step" { + run_logged 'np_scope_step_begin wait-alb-active; np_scope_step_end 0' + [ "$status" -eq 0 ] + echo "$output" | grep '"status":"completed"' | grep -q 'wait-alb-active@0.0' +} + +@test "step_end with a non-zero rc fails the sub-step with the message" { + run_logged 'np_scope_step_begin wait-alb-active; np_scope_step_end 1 "ALB never came up"' + [ "$status" -eq 0 ] + echo "$output" | grep '"status":"failed"' | grep -q 'wait-alb-active@0.0' + echo "$output" | grep -q 'ALB never came up' +} + +@test "step_timeout closes the sub-step as timed_out, not failed" { + run_logged 'np_scope_step_begin wait-alb-active; np_scope_step_timeout "deadline hit"' + [ "$status" -eq 0 ] + echo "$output" | grep '"status":"timed_out"' | grep -q 'wait-alb-active@0.0' + echo "$output" | grep -q 'deadline hit' + ! echo "$output" | grep '"status":"failed"' | grep -q 'wait-alb-active@0.0' +} + +@test "while a sub-step is open, log error attaches to IT, not the platform step" { + run_logged 'np_scope_step_begin wait-alb-active; log error "quota exceeded"; np_scope_step_end 1' + [ "$status" -eq 0 ] + echo "$output" | grep '"quota exceeded"' | grep -q 'wait-alb-active@0.0' + ! echo "$output" | grep -q 'phase exited with status' +} + +@test "while a sub-step is open, heartbeats attach to it" { + run_logged 'np_scope_step_begin wait-alb-active; np_scope_wait_heartbeat "alb-active" 30 300 "pending"' + [ "$status" -eq 0 ] + echo "$output" | grep '"status":"waiting"' | grep -q 'wait-alb-active@0.0' +} + +@test "a heartbeat puts NO wait bookkeeping in the labels" { + run_logged 'np_scope_wait_heartbeat "deployment-active" 20 600 "progressing"' + [ "$status" -eq 0 ] + ! echo "$output" | grep -q '"wait\.' +} + +@test "a sub-step left open when the platform moves on is forgotten, not reused" { + run_logged ' + np_scope_step_begin wait-alb-active + export NP_TRACE="1|trace-9|scope-provision-42~wait-for-alb@0.0" + log error "late failure" + ' + [ "$status" -eq 0 ] + echo "$output" | grep '"late failure"' | grep -q 'scope-provision-42~wait-for-alb@0.0"' +} + +@test "a sub-step still open when the shell dies inherits the failure" { + run "$BASH" -c " + ( source '$LOGGING'; np_scope_step_begin wait-alb-active; log error 'the real reason'; exit 3 ) || true + source '$LOGGING'; trap - EXIT ERR + for f in \"\$NP_TRACE_DIR\"/spool/*.json \"\$NP_TRACE_DIR\"/failed/*.json; do + [ -f \"\$f\" ] && cat \"\$f\" && echo + done + true + " + [ "$status" -eq 0 ] + echo "$output" | grep '"status":"failed"' | grep -q 'wait-alb-active@0.0' + echo "$output" | grep '"the real reason"' | grep -q 'wait-alb-active@0.0' + ! echo "$output" | grep -q 'phase exited with status' +} + +@test "opening a second sub-step completes the first — phases are sequential" { + run_logged 'np_scope_step_begin phase-one; np_scope_step_begin phase-two; np_scope_step_end 0' + [ "$status" -eq 0 ] + echo "$output" | grep '"status":"completed"' | grep -q 'phase-one@0.0' + echo "$output" | grep '"status":"completed"' | grep -q 'phase-two@0.0' +} + +@test "step functions are defined no-ops when the workflow is untraced" { + unset NP_TRACE + run "$BASH" -c "source '$LOGGING'; np_scope_step_begin x; np_scope_step_end 1; np_scope_step_timeout; echo rc=\$?" + [ "$status" -eq 0 ] + [[ "$output" == *"rc=0"* ]] +} + +@test "step_end without an open sub-step is a no-op" { + run_logged 'np_scope_step_end 1 "nothing open"' + [ "$status" -eq 0 ] + ! echo "$output" | grep -q 'nothing open' +} + +# --- lineage ---------------------------------------------------------------- + +@test "produces records the edge and the pointer on the current step" { + run_logged 'np_scope_produces "dns-record:api.example.com" dns_record "api.example.com"' + [ "$status" -eq 0 ] + echo "$output" | grep '"edge.produces"' | grep -q '"id":"dns-record:api.example.com"' + echo "$output" | grep -q '"tracing.binding":{"name":"dns_record"}' + echo "$output" | grep '"tracing.output"' | grep -q 'apply-manifests@0.0' +} + +@test "consumes records the cross-flow image edge" { + run_logged 'np_scope_consumes "docker-image:registry.example.com/app:1.2" image "registry.example.com/app:1.2"' + [ "$status" -eq 0 ] + echo "$output" | grep '"edge.consumes"' | grep -q '"id":"docker-image:registry.example.com/app:1.2"' +} + +@test "lineage inside an open sub-step attaches to the sub-step" { + run_logged ' + np_scope_step_begin wait-alb-active + np_scope_consumes "load-balancer:arn:aws:elb:demo" load_balancer "arn:aws:elb:demo" + np_scope_step_end 0 + ' + [ "$status" -eq 0 ] + echo "$output" | grep '"edge.consumes"' | grep -q 'wait-alb-active@0.0' +} + +@test "kubectl apply output becomes workload/service/ingress lineage" { + run_logged ' + np_scope_k8s_applied "ns-42" "deployment.apps/d-1-2 created +service/s-1-2 configured +ingress.networking.k8s.io/i-1-2 created +secret/sec-1 created" + ' + [ "$status" -eq 0 ] + echo "$output" | grep -q '"id":"k8s-deployment:ns-42/d-1-2"' + echo "$output" | grep -q '"id":"k8s-service:ns-42/s-1-2"' + echo "$output" | grep -q '"id":"k8s-ingress:ns-42/i-1-2"' + ! echo "$output" | grep -q 'sec-1' +} + +@test "affordance and progress land as their core facets" { + run_logged ' + np_scope_affordance "{\"kind\":\"deploy-log\",\"application_id\":\"7\"}" + np_scope_progress 3 10 count + ' + [ "$status" -eq 0 ] + echo "$output" | grep -q '"tracing.affordances":\[{"kind":"deploy-log","application_id":"7"}\]' + echo "$output" | grep -q '"tracing.progress":{"current":3,"target":10,"unit":"count"}' +} + +@test "lineage helpers are defined no-ops when untraced" { + unset NP_TRACE + run "$BASH" -c "source '$LOGGING'; np_scope_produces d:1 n u; np_scope_consumes d:2; np_scope_affordance '{\"kind\":\"x\"}'; np_scope_progress 1 2; np_scope_k8s_applied ns 'deployment.apps/x created'; echo rc=\$?" + [ "$status" -eq 0 ] + [[ "$output" == *"rc=0"* ]] +} + +# --- narrative: inline io, explain, structured errors ------------------------ + +@test "inline output and explain land on the open sub-step" { + run_logged ' + np_scope_step_begin wait-deployment-active + np_scope_output instances "{\"healthy\":2,\"desired\":3}" + np_scope_explain --title "Instance health check" --severity warn --what "Waiting for 2/3 instances to be healthy" + np_scope_step_end 0 + ' + [ "$status" -eq 0 ] + echo "$output" | grep '"tracing.output"' | grep -q 'wait-deployment-active@0.0' + echo "$output" | grep -q '"value":{"healthy":2,"desired":3}' + echo "$output" | grep -q '"severity":"warn"' + echo "$output" | grep -q 'Waiting for 2/3 instances to be healthy' +} + +@test "the traffic switch set lands whole on the current step" { + run_logged ' + np_scope_labels "deployment.id=777" "action=traffic-switch" + np_scope_explain --title "Switch traffic for deployment 777" --what "Switching blue/green traffic for deployment 777 from 0% to 100%" + np_scope_affordance "{\"kind\":\"traffic-switch\",\"deployment_id\":\"777\",\"current_traffic\":100,\"new_traffic\":100,\"old_traffic\":0,\"target_traffic\":100}" + np_scope_input traffic "{\"from\":0,\"desired\":100}" + np_scope_output traffic "{\"switched\":100}" + np_scope_progress 100 100 percent + ' + [ "$status" -eq 0 ] + echo "$output" | grep -q '"kind":"traffic-switch"' + echo "$output" | grep -q '"tracing.input":\[{"kind":"inline","name":"traffic","value":{"from":0,"desired":100}}\]' + echo "$output" | grep -q '"tracing.output":\[{"kind":"inline","name":"traffic","value":{"switched":100}}\]' + echo "$output" | grep -q '"tracing.progress":{"current":100,"target":100,"unit":"percent"}' + echo "$output" | grep -q '"action":"traffic-switch"' +} + +@test "np_scope_error carries structured details and stands down the exit trap" { + run "$BASH" -c " + ( source '$LOGGING'; np_scope_error 'gave up' '{\"instances\":{\"healthy\":1,\"desired\":3}}'; exit 3 ) || true + source '$LOGGING'; trap - EXIT ERR + for f in \"\$NP_TRACE_DIR\"/spool/*.json \"\$NP_TRACE_DIR\"/failed/*.json; do + [ -f \"\$f\" ] && cat \"\$f\" && echo + done + true + " + [ "$status" -eq 0 ] + echo "$output" | grep -q '"details":{"instances":{"healthy":1,"desired":3}}' + [ "$(echo "$output" | grep 'apply-manifests@0.0"' | grep -c 'tracing.error')" -eq 1 ] +} + +@test "narrative helpers are defined no-ops when untraced" { + unset NP_TRACE + run "$BASH" -c "source '$LOGGING'; np_scope_output x '{}'; np_scope_input x '{}'; np_scope_explain --title t; np_scope_error m; np_scope_labels a=b; echo rc=\$?" + [ "$status" -eq 0 ] + [[ "$output" == *"rc=0"* ]] +} + +@test "a fatal exit mirrors the real reason onto the RUN, one level up" { + run "$BASH" -c " + ( source '$LOGGING'; log error 'the real reason'; exit 3 ) || true + source '$LOGGING'; trap - EXIT ERR + for f in \"\$NP_TRACE_DIR\"/spool/*.json \"\$NP_TRACE_DIR\"/failed/*.json; do + [ -f \"\$f\" ] && cat \"\$f\" && echo + done + true + " + [ "$status" -eq 0 ] + echo "$output" | grep '"the real reason"' | grep -q 'scope-provision-42~apply-manifests@0.0"' + echo "$output" | grep '"the real reason"' | grep -q '"run_id":"scope-provision-42"' +} + +@test "a run-level NP_TRACE (no step segment) mirrors nowhere extra" { + run "$BASH" -c " + export NP_TRACE='1|trace-9|scope-provision-42' + ( source '$LOGGING'; log error 'root failure'; exit 3 ) || true + source '$LOGGING'; trap - EXIT ERR + for f in \"\$NP_TRACE_DIR\"/spool/*.json \"\$NP_TRACE_DIR\"/failed/*.json; do + [ -f \"\$f\" ] && cat \"\$f\" && echo + done + true + " + [ "$status" -eq 0 ] + [ "$(echo "$output" | grep -c '"root failure"')" -eq 1 ] +} + +@test "a hint burst never shadows the cause: first message wins, hints ride as evidence" { + run_logged ' + log error "❌ HostedZone not found (AccessDenied)" + log error "💡 Possible causes:" + log error " • The role lacks route53:ListHostedZones" + ' + [ "$status" -eq 0 ] + ! echo "$output" | grep '"tracing.error"' | grep -q '"message":"💡' + echo "$output" | grep -q '"message":"HostedZone not found (AccessDenied)","details":{"hints":\["💡 Possible causes:","• The role lacks route53:ListHostedZones"\]}' +} + +@test "the first error cause is stated to the workflow engine via np_step_error" { + STATED="$BATS_TEST_TMPDIR/stated" + export STATED + run_logged ' + np_step_error() { printf "%s\n" "$1" >>"$STATED"; } + log error "❌ HostedZone not found (AccessDenied)" + log error "💡 a hint, not a cause" + ' + [ "$status" -eq 0 ] + run cat "$STATED" + assert_equal "$output" "HostedZone not found (AccessDenied)" +} + +@test "the exit trap's synthetic message is never stated as a cause" { + STATED="$BATS_TEST_TMPDIR/stated" + export STATED + run_logged ' + np_step_error() { printf "%s\n" "$1" >>"$STATED"; } + ( exit 3 ) # arm LAST_ERR without any log error, then die unhandled + exit 3 + ' + [ "$status" -eq 3 ] + [ ! -s "$STATED" ] +} + +@test "trace errors carry the cause stripped of console decoration" { + run_logged ' + log error " ❌ Failed to find IAM role: An error occurred (NoSuchEntity)" + ' + [ "$status" -eq 0 ] + echo "$output" | grep -q '"message":"Failed to find IAM role: An error occurred (NoSuchEntity)"' + ! echo "$output" | grep '"tracing.error"' | grep -q '"message":" ❌' +} + +@test "a new step starts a new error burst" { + run_logged ' + log error "first cause" + export NP_TRACE="1|trace-9|scope-provision-42~create-dns@0.0" + log error "second cause" + log error "a hint for the second" + ' + [ "$status" -eq 0 ] + echo "$output" | grep 'create-dns@0.0' | grep '"tracing.error"' | grep -q '"message":"second cause"' + echo "$output" | grep -q '"hints":\["a hint for the second"\]' + ! echo "$output" | grep 'create-dns@0.0' | grep -q '"message":"first cause"' +} + +@test "a traced run with credentials but NO bundled SDK warns loudly instead of degrading silently" { + run "$BASH" -c ' + export NP_TRACE="1|trace-1|run-1@0.0" + export NP_API_KEY="key" + NP_SCOPES_TEST_ROOT="$BATS_TEST_TMPDIR/empty-bundle" + mkdir -p "$NP_SCOPES_TEST_ROOT/k8s" + cp "'"$LOGGING"'" "$NP_SCOPES_TEST_ROOT/k8s/logging" + source "$NP_SCOPES_TEST_ROOT/k8s/logging" + log info "workflow proceeds" + ' + [ "$status" -eq 0 ] + echo "$output" | grep -q "tracing SDK not bundled" + echo "$output" | grep -q "workflow proceeds" +} + +@test "an untraced run (no NP_TRACE) stays silent about the SDK" { + run "$BASH" -c ' + unset NP_TRACE + export NP_API_KEY="key" + NP_SCOPES_TEST_ROOT="$BATS_TEST_TMPDIR/empty-bundle2" + mkdir -p "$NP_SCOPES_TEST_ROOT/k8s" + cp "'"$LOGGING"'" "$NP_SCOPES_TEST_ROOT/k8s/logging" + source "$NP_SCOPES_TEST_ROOT/k8s/logging" + log info "plain logging" + ' + [ "$status" -eq 0 ] + ! echo "$output" | grep -q "tracing SDK not bundled" +} diff --git a/k8s/values.yaml b/k8s/values.yaml index edf18f08..4f43e079 100644 --- a/k8s/values.yaml +++ b/k8s/values.yaml @@ -10,6 +10,7 @@ configuration: # PRIVATE_DOMAIN: nullapps.io USE_ACCOUNT_SLUG: false DNS_TYPE: route53 # Available values route53 | azure | external_dns + K8S_FLAVOR: eks # The cluster variant (eks | aks | aro | gke) — independent of DNS_TYPE ALB_RECONCILIATION_ENABLED: false ALB_MAX_CAPACITY: 75 # 100 is the max target groups for ALB. Keeps 2 free for emergencies diff --git a/nptrace.sh b/nptrace.sh new file mode 100755 index 00000000..1d971f6e --- /dev/null +++ b/nptrace.sh @@ -0,0 +1,2349 @@ +#!/bin/sh + +# ---- src/header.sh ---- +# nullplatform tracing for POSIX shell — producer SDK for the nullplatform +# tracing API. Zero runtime dependencies beyond curl and the POSIX toolset. +# +# Generated file: edit src/*.sh and run ./build.sh. + +if [ -n "${NP_TRACE_LOADED:-}" ]; then + return 0 2>/dev/null || exit 0 +fi +NP_TRACE_LOADED=1 +NP_TRACE_VERSION="0.1.0" + +# ---- src/compat.sh ---- +# compat.sh — portability shims. The ONLY place OS differences live. + +# Unix milliseconds. GNU date supports %N; busybox and BSD may not, and they +# fail in two DIFFERENT ways: +# +# busybox 1.38 / BSD -> "1786045823%3N" the format leaks through literally +# busybox 1.37 -> "1786045823" the format is silently DROPPED +# +# The second is the dangerous one: the result is clean digits that merely happen +# to be seconds, so a digits-only check accepts it and every timestamp is then +# 1000x too small — which silently destroys UUIDv7 ordering, since the seconds +# value lands in a 48-bit millisecond field and decodes to 1970. +# +# Length is what separates them: Unix milliseconds have been 13 digits since +# 2001-09-09 and stay 13 until 2286, while seconds are 10. Anything shorter than +# 13 is not milliseconds, whatever it looks like. +np__epoch_ms() { + _epoch_ms_ms=$(date -u +%s%3N 2>/dev/null) || _epoch_ms_ms='' + case "$_epoch_ms_ms" in + '' | *[!0-9]*) _epoch_ms_ms='' ;; + esac + if [ -n "$_epoch_ms_ms" ] && [ "${#_epoch_ms_ms}" -ge 13 ]; then + printf '%s' "$_epoch_ms_ms" + return 0 + fi + # Second precision. Event ids stay unique via their random bits. + printf '%s000' "$(date -u +%s)" +} + +# Exactly $1 lowercase hex characters from the kernel CSPRNG. +np__rand_hex() { + _rand_hex_want=$1 + _rand_hex_bytes=$(( (_rand_hex_want + 1) / 2 )) + od -An -tx1 -N"$_rand_hex_bytes" /dev/urandom | tr -d ' \n' | cut -c1-"$_rand_hex_want" +} + +# RFC 3339 UTC, second precision — the envelope `time` field. +np__iso8601() { + date -u +%Y-%m-%dT%H:%M:%SZ +} + +# ---- src/json.sh ---- +# json.sh — JSON emission. There is no parser here beyond one field extractor +# for the auth response; the SDK only ever WRITES JSON. + +# Escape a string for a JSON string body (no surrounding quotes). +# +# Fast path: a string made only of unmistakably safe characters is returned +# unchanged, so the common label/id case never forks an awk. The allowlist is +# deliberately conservative — routing an unusual string to the slow path is +# always correct, only slower. +# +# Slow path: awk under LC_ALL=C, so length/substr are BYTE oriented on every +# awk (gawk, mawk, busybox). UTF-8 sequences pass through byte for byte, which +# is valid JSON; only the seven shorthand escapes and C0 controls are rewritten. +# Records are read line by line and rejoined with \n rather than using a +# multi-character RS, whose behaviour POSIX leaves undefined. +np__json_escape() { + case "$1" in + *[!A-Za-z0-9\ ._:/@=+,-]*) ;; + *) printf '%s' "$1"; return 0 ;; + esac + printf '%s' "$1" | LC_ALL=C awk ' + function esc(s, i, c, n, o) { + o = "" + n = length(s) + for (i = 1; i <= n; i++) { + c = substr(s, i, 1) + if (c == "\\") { o = o "\\\\" } + else if (c == "\"") { o = o "\\\"" } + else if (c == "\t") { o = o "\\t" } + else if (c == "\r") { o = o "\\r" } + else if (c == "\b") { o = o "\\b" } + else if (c == "\f") { o = o "\\f" } + else if (c < " ") { o = o sprintf("\\u%04x", ORD[c]) } + else { o = o c } + } + return o + } + BEGIN { + ORS = "" + for (i = 0; i < 256; i++) { ORD[sprintf("%c", i)] = i } + out = "" + } + { + if (NR > 1) { out = out "\\n" } + out = out esc($0) + } + END { printf "%s", out } + ' +} + +# A complete quoted JSON string. +np__json_str() { + printf '"%s"' "$(np__json_escape "$1")" +} + +# A JSON object from alternating key/value arguments. Values are emitted as +# JSON strings. A pair whose key or value is empty is OMITTED — an absent +# optional is absent, never the string "". +np__json_obj() { + _json_obj_out='' + while [ "$#" -ge 2 ]; do + if [ -n "$1" ] && [ -n "$2" ]; then + if [ -n "$_json_obj_out" ]; then + _json_obj_out="$_json_obj_out," + fi + _json_obj_out="$_json_obj_out$(np__json_str "$1"):$(np__json_str "$2")" + fi + shift 2 + done + printf '{%s}' "$_json_obj_out" +} + +# As np__json_obj, but each value is already-formed JSON inserted verbatim. +# Use for nested objects, arrays, numbers, and booleans. +np__json_obj_raw() { + _json_obj_raw_out='' + while [ "$#" -ge 2 ]; do + if [ -n "$1" ] && [ -n "$2" ]; then + if [ -n "$_json_obj_raw_out" ]; then + _json_obj_raw_out="$_json_obj_raw_out," + fi + _json_obj_raw_out="$_json_obj_raw_out$(np__json_str "$1"):$2" + fi + shift 2 + done + printf '{%s}' "$_json_obj_raw_out" +} + +# A JSON array of strings from a comma-separated list ("a, b" → ["a","b"]). +# Surrounding whitespace per item is trimmed; empty items are omitted. +np__json_str_array_csv() { + _json_str_array_csv_out='' + _json_str_array_csv_rest=$1 + while [ -n "$_json_str_array_csv_rest" ]; do + case "$_json_str_array_csv_rest" in + *,*) _json_str_array_csv_item=${_json_str_array_csv_rest%%,*}; _json_str_array_csv_rest=${_json_str_array_csv_rest#*,} ;; + *) _json_str_array_csv_item=$_json_str_array_csv_rest; _json_str_array_csv_rest='' ;; + esac + _json_str_array_csv_item=$(printf '%s' "$_json_str_array_csv_item" | sed 's/^ *//; s/ *$//') + if [ -n "$_json_str_array_csv_item" ]; then + if [ -n "$_json_str_array_csv_out" ]; then + _json_str_array_csv_out="$_json_str_array_csv_out," + fi + _json_str_array_csv_out="$_json_str_array_csv_out$(np__json_str "$_json_str_array_csv_item")" + fi + done + printf '[%s]' "$_json_str_array_csv_out" +} + +# ---- src/uuid.sh ---- +# uuid.sh — UUIDv7. The event id MUST be a v7: the API derives the storage +# partition from its embedded millisecond timestamp and rejects anything else. +# +# Layout: 48-bit big-endian ms timestamp | version nibble 7 | 12 random bits +# | variant bits 10 | 62 random bits. + +np__uuidv7() { + _u7_ts=$(printf '%012x' "$(np__epoch_ms)") + _u7_r=$(np__rand_hex 19) + + # The variant nibble must be one of 8, 9, a, b. Fold a random hex digit into + # that range rather than drawing again. + case $(printf '%s' "$_u7_r" | cut -c1) in + 0 | 1 | 2 | 3) _u7_var=8 ;; + 4 | 5 | 6 | 7) _u7_var=9 ;; + 8 | 9 | a | b) _u7_var=a ;; + *) _u7_var=b ;; + esac + + printf '%s-%s-7%s-%s%s-%s\n' \ + "$(printf '%s' "$_u7_ts" | cut -c1-8)" \ + "$(printf '%s' "$_u7_ts" | cut -c9-12)" \ + "$(printf '%s' "$_u7_r" | cut -c2-4)" \ + "$_u7_var" \ + "$(printf '%s' "$_u7_r" | cut -c5-7)" \ + "$(printf '%s' "$_u7_r" | cut -c8-19)" +} + +# Mint a per-occurrence token for a repeatable operation's run_id. Time-ordered, +# so minted ids sort by creation time. +np_trace_occurrence() { + np__uuidv7 +} + +# ---- src/identity.sh ---- +# identity.sh — the node identity grammar. A hand-port of the tracing API's +# contract module; these functions and their tests are the drift safety net. +# +# child_run_id = parent_run_id "~" key "@" attempt "." iteration +# +# One charset covers every producer-authored segment: [A-Za-z0-9_.-]+. The +# delimiter '~' and the coordinate marker '@' sit outside it, which is what +# makes the grammar collision-proof — no named id can ever parse as a derived +# one. + +NP_ID_DELIMITER='~' +NP_MAX_RUN_ID_LENGTH=1024 +NP_MAX_KEY_LENGTH=256 +NP_MAX_TRACE_ID_LENGTH=256 + +np__is_identifier() { + case "${1:-}" in + '') return 1 ;; + *[!A-Za-z0-9_.-]*) return 1 ;; + *) return 0 ;; + esac +} + +# Print a reason and return 1, or return 0 silently. +np__identifier_violation() { + if [ -z "$1" ]; then + printf 'must be non-empty' + return 1 + fi + if [ "${#1}" -gt "$2" ]; then + printf 'exceeds %s chars' "$2" + return 1 + fi + if ! np__is_identifier "$1"; then + printf "must be identifier-charset: letters, digits, '_', '.', '-'" + return 1 + fi + return 0 +} + +np__key_violation() { + np__identifier_violation "${1:-}" "$NP_MAX_KEY_LENGTH" +} + +np__named_id_violation() { + np__identifier_violation "${1:-}" "$NP_MAX_RUN_ID_LENGTH" +} + +np__trace_id_violation() { + np__identifier_violation "${1:-}" "$NP_MAX_TRACE_ID_LENGTH" +} + +# The derived id of a keyed child. +np__derive_child_id() { + printf '%s%s%s@%s.%s' "$1" "$NP_ID_DELIMITER" "$2" "$3" "$4" +} + +# Everything before the FIRST delimiter — the nearest named ancestor. Every +# keyed descendant of a named run shares its scope root at any depth. +np__scope_root_of() { + case "$1" in + *"$NP_ID_DELIMITER"*) printf '%s' "${1%%"$NP_ID_DELIMITER"*}" ;; + *) printf '%s' "$1" ;; + esac +} + +# Parse the LAST hop of a derived id. Prints " ". +# Returns 1 for a named id (no delimiter) or a malformed tail. +np__parse_node_id() { + case "$1" in + *"$NP_ID_DELIMITER"*) ;; + *) return 1 ;; + esac + _parse_node_id_parent=${1%"$NP_ID_DELIMITER"*} + _parse_node_id_tail=${1##*"$NP_ID_DELIMITER"} + case "$_parse_node_id_tail" in + *@*.*) ;; + *) return 1 ;; + esac + _parse_node_id_key=${_parse_node_id_tail%%@*} + _parse_node_id_coord=${_parse_node_id_tail#*@} + _parse_node_id_attempt=${_parse_node_id_coord%%.*} + _parse_node_id_iteration=${_parse_node_id_coord#*.} + if [ -z "$_parse_node_id_parent" ] || [ -z "$_parse_node_id_key" ]; then + return 1 + fi + case "$_parse_node_id_attempt" in + '' | *[!0-9]*) return 1 ;; + esac + case "$_parse_node_id_iteration" in + '' | *[!0-9]*) return 1 ;; + esac + printf '%s %s %s %s' "$_parse_node_id_parent" "$_parse_node_id_key" "$_parse_node_id_attempt" "$_parse_node_id_iteration" +} + +# Join parts into a stable id, dropping empty parts. Use instead of +# hand-interpolation so an absent part never leaves a dangling separator. +# The joiner is '-', a charset character, so the result stays a legal named id. +np_trace_key() { + _k_out='' + for _k_part in "$@"; do + if [ -n "$_k_part" ]; then + if [ -n "$_k_out" ]; then + _k_out="$_k_out-" + fi + _k_out="$_k_out$_k_part" + fi + done + printf '%s' "$_k_out" +} + +# ---- src/wire.sh ---- +# wire.sh — contract constants, hand-ported from the tracing API's wire +# package. When the API's contract changes, this file and identity.sh are what +# must be re-ported; their tests are the safety net. + +NP_TYPE_NODE_RUN='node.run' +NP_TYPE_NODE_DATASET='node.dataset' +NP_TYPE_NODE_JOB='node.job' + +NP_TYPE_EDGE_PARENT='edge.parent' +NP_TYPE_EDGE_TRIGGERED_BY='edge.triggered_by' +NP_TYPE_EDGE_RETRY_OF='edge.retry_of' +NP_TYPE_EDGE_CONTINUES='edge.continues' +NP_TYPE_EDGE_CORRELATES='edge.correlates' +NP_TYPE_EDGE_COMPENSATES='edge.compensates' +NP_TYPE_EDGE_PRODUCES='edge.produces' +NP_TYPE_EDGE_CONSUMES='edge.consumes' +NP_TYPE_EDGE_INSTANCE_OF='edge.instance_of' + +NP_STATUS_STARTED='started' +NP_STATUS_COMPLETED='completed' +NP_STATUS_FAILED='failed' +NP_STATUS_CANCELLED='cancelled' +NP_STATUS_TIMED_OUT='timed_out' +NP_STATUS_SKIPPED='skipped' +NP_STATUS_WAITING='waiting' + +NP_FACET_ERROR='tracing.error' +NP_FACET_TIMING='tracing.timing' +NP_FACET_INPUT='tracing.input' +NP_FACET_OUTPUT='tracing.output' +NP_FACET_BINDING='tracing.binding' +NP_FACET_DECISION='tracing.decision' +NP_FACET_RETRY='tracing.retry' +NP_FACET_SIGNAL='tracing.signal' +NP_FACET_EXTERNAL_LINKS='tracing.externalLinks' +NP_FACET_PLAN='tracing.plan' +NP_FACET_ACTOR='tracing.actor' +NP_FACET_DROPPED='tracing.dropped' +NP_FACET_ENGINE_STATUS='tracing.engineStatus' +NP_FACET_AFFORDANCES='tracing.affordances' +NP_FACET_EXPLAIN='tracing.explain' +NP_FACET_PROGRESS='tracing.progress' + +NP_CORE_FACETS="$NP_FACET_ERROR $NP_FACET_TIMING $NP_FACET_INPUT $NP_FACET_OUTPUT \ +$NP_FACET_BINDING $NP_FACET_DECISION $NP_FACET_RETRY $NP_FACET_SIGNAL \ +$NP_FACET_EXTERNAL_LINKS $NP_FACET_PLAN $NP_FACET_ACTOR $NP_FACET_DROPPED \ +$NP_FACET_ENGINE_STATUS $NP_FACET_AFFORDANCES $NP_FACET_EXPLAIN $NP_FACET_PROGRESS" + +NP_RESERVED_FACET_PREFIX='tracing.' +NP_RESERVED_LABEL_PREFIX='tracing.io/' + +# The context carrier: ONE field whose value packs version, trace and run. +NP_CARRIER_KEY='np-trace' +NP_CARRIER_VERSION='1' +NP_CARRIER_DELIMITER='|' + +np__is_terminal_status() { + case "${1:-}" in + completed | failed | cancelled | timed_out | skipped) return 0 ;; + *) return 1 ;; + esac +} + +# ---- src/state.sh ---- +# state.sh — the on-disk node registry. State lives on disk rather than in +# shell memory so handles survive process boundaries: in CI every pipeline step +# is a fresh shell. + +# Create the state tree. If it cannot be created or written — a read-only +# filesystem, a full disk, a bad NP_TRACE_DIR — the SDK degrades to a REAL +# no-op rather than half-working: a half-initialised SDK whose next write fails +# would take down a caller running under `set -e`, which is exactly the failure +# mode tracing must never cause. +np__state_init() { + if [ -z "${NP_TRACE_DIR:-}" ]; then + NP_TRACE_DIR="${TMPDIR:-/tmp}/nptrace.$$" + fi + export NP_TRACE_DIR + if ! mkdir -p "$NP_TRACE_DIR/nodes" "$NP_TRACE_DIR/staged" \ + "$NP_TRACE_DIR/spool" "$NP_TRACE_DIR/failed" 2>/dev/null; then + NP_TRACE_ENABLED=0 + return 0 + fi + # Prove the tree is actually writable before trusting it. + if ! printf '0' > "$NP_TRACE_DIR/seq.probe" 2>/dev/null; then + NP_TRACE_ENABLED=0 + return 0 + fi + rm -f "$NP_TRACE_DIR/seq.probe" 2>/dev/null || : + if [ ! -f "$NP_TRACE_DIR/seq" ]; then + printf '0' > "$NP_TRACE_DIR/seq" 2>/dev/null || : + fi + return 0 +} + +# Allocate the next handle. Handles are opaque by contract: consumers never +# parse them. +np__handle_new() { + _handle_new_seq=$(cat "$NP_TRACE_DIR/seq" 2>/dev/null || printf '0') + case "$_handle_new_seq" in + '' | *[!0-9]*) _handle_new_seq=0 ;; + esac + _handle_new_seq=$((_handle_new_seq + 1)) + printf '%s' "$_handle_new_seq" > "$NP_TRACE_DIR/seq" + _handle_new_handle="n$_handle_new_seq" + : > "$NP_TRACE_DIR/nodes/$_handle_new_handle" + printf '%s' "$_handle_new_handle" +} + +# THE rule the whole public surface rests on: an argument is a handle iff it +# has the allocator's shape AND names an existing node file. The shape check +# comes first so a caller-supplied string can never traverse out of nodes/. +np__is_handle() { + case "${1:-}" in + n) return 1 ;; + n*) case "${1#n}" in '' | *[!0-9]*) return 1 ;; esac ;; + *) return 1 ;; + esac + [ -f "$NP_TRACE_DIR/nodes/$1" ] +} + +np__node_set() { + _node_set_file="$NP_TRACE_DIR/nodes/$1" + [ -f "$_node_set_file" ] || return 0 + # Drop any prior value for this key, then append the new one. The trailing + # '=' in the match means a key that is a prefix of another never collides. + if grep -q "^$2=" "$_node_set_file" 2>/dev/null; then + grep -v "^$2=" "$_node_set_file" > "$_node_set_file.tmp" 2>/dev/null || : > "$_node_set_file.tmp" + mv "$_node_set_file.tmp" "$_node_set_file" + fi + printf '%s=%s\n' "$2" "$3" >> "$_node_set_file" + return 0 +} + +np__node_get() { + _node_get_file="$NP_TRACE_DIR/nodes/$1" + [ -f "$_node_get_file" ] || return 0 + # Strip only the leading "key=", so a value containing '=' survives intact. + sed -n "s/^$2=//p" "$_node_get_file" 2>/dev/null | head -n 1 + return 0 +} + +# Ambient resolution, exactly two levels. There is deliberately no third, +# session-wide level: that is where concurrent writers race. +# +# 1. NP_TRACE_CURRENT — explicit, and what you export to cross a CI step. +# 2. current.$$ — auto-maintained within one process tree. POSIX $$ +# does not change in a subshell, so a handle created +# inside $(...) is visible to the caller. +np__ambient() { + if [ -n "${NP_TRACE_CURRENT:-}" ]; then + printf '%s' "$NP_TRACE_CURRENT" + return 0 + fi + cat "$NP_TRACE_DIR/current.$$" 2>/dev/null || printf '' + return 0 +} + +np__ambient_set() { + printf '%s' "$1" > "$NP_TRACE_DIR/current.$$" 2>/dev/null || return 0 + return 0 +} + +np__ambient_clear() { + # Only clear when the cleared handle IS current, so terminalizing an outer + # node cannot silently retarget an inner one. + if [ "$(np__ambient)" = "$1" ]; then + rm -f "$NP_TRACE_DIR/current.$$" 2>/dev/null || : + if [ -n "${NP_TRACE_CURRENT:-}" ] && [ "$NP_TRACE_CURRENT" = "$1" ]; then + NP_TRACE_CURRENT='' + fi + fi + return 0 +} + +# Every node-scoped public function starts here: use $1 when it is a handle, +# otherwise fall back to the ambient node. +np__resolve_handle() { + if np__is_handle "${1:-}"; then + printf '%s' "$1" + else + np__ambient + fi + return 0 +} + +# ---- src/spool.sh ---- +# spool.sh — the emit hot path. Every emit is a LOCAL FILE WRITE: the network +# is never touched here, which is what makes API downtime invisible to the +# caller. The spool file's NAME is the event id, so re-POSTing after a crash is +# idempotent — that is recover() for free. + +# np__spool -> prints the event id +np__spool() { + _spool_id=$(np__uuidv7) + _spool_env=$(np__json_obj_raw \ + id "$(np__json_str "$_spool_id")" \ + time "$(np__json_str "$(np__iso8601)")" \ + type "$(np__json_str "$1")" \ + nrn "$(if [ -n "$2" ]; then np__json_str "$2"; fi)" \ + producer "$(np__json_str "${NP_TRACE_PRODUCER:-}")" \ + data "$3") + + _spool_tmp="$NP_TRACE_DIR/spool/$_spool_id.json.tmp" + _spool_final="$NP_TRACE_DIR/spool/$_spool_id.json" + printf '%s' "$_spool_env" > "$_spool_tmp" 2>/dev/null || return 0 + # Create-then-rename: a concurrent flush never sees a half-written envelope. + mv "$_spool_tmp" "$_spool_final" 2>/dev/null || return 0 + printf '%s' "$_spool_id" + return 0 +} + +np__spool_count() { + _spool_count_n=0 + for _spool_count_f in "$NP_TRACE_DIR/spool"/*.json; do + [ -f "$_spool_count_f" ] || continue + _spool_count_n=$((_spool_count_n + 1)) + done + printf '%s' "$_spool_count_n" + return 0 +} + +# ---- src/http.sh ---- +# http.sh — the only module that touches the network. Every request is bounded +# by a connect AND a total timeout, so an unreachable or hanging API can never +# stall the caller. + +NP_TRACE_CONNECT_TIMEOUT="${NP_TRACE_CONNECT_TIMEOUT:-3}" +NP_TRACE_MAX_TIME="${NP_TRACE_MAX_TIME:-10}" +NP_TRACE_DEFAULT_BASE_URL='https://api.nullplatform.com/tracing' +NP_TRACE_DEFAULT_AUTH_URL='https://api.nullplatform.com' + +np__drop() { + printf '%s\t%s\t%s\n' "$(np__iso8601)" "$1" "$2" >> "$NP_TRACE_DIR/drops.log" 2>/dev/null || : + if [ -n "${NP_TRACE_ON_DROP:-}" ]; then + "$NP_TRACE_ON_DROP" "$1" "$2" 2>/dev/null || : + fi + if [ -n "${NP_TRACE_DEBUG:-}" ]; then + printf 'np-trace drop: %s (%s)\n' "$1" "$2" >&2 + fi + return 0 +} + +# Suppress xtrace for a credential-handling region, remembering whether it was +# on. CI scripts routinely `set -x`, and shell options are global — so without +# this a sourced SDK function would print the bearer token into the build log +# even though it never reaches curl's argv. Every credential path is bracketed +# by np__secret_begin / np__secret_end. +np__secret_begin() { + case "$-" in + *x*) NP_TRACE_XTRACE=1; set +x ;; + *) NP_TRACE_XTRACE='' ;; + esac +} + +np__secret_end() { + if [ -n "${NP_TRACE_XTRACE:-}" ]; then + NP_TRACE_XTRACE='' + set -x + fi + return 0 +} + +# A bearer token. A pre-issued NP_TRACE_TOKEN wins; otherwise exchange the api +# key, caching until shortly before expiry. Called LAZILY, at first flush — +# never at init, so a down auth endpoint cannot delay pipeline startup. +np__token() { + np__secret_begin + if [ -n "${NP_TRACE_TOKEN:-}" ]; then + printf '%s' "$NP_TRACE_TOKEN" + np__secret_end + return 0 + fi + np__token_exchange + np__secret_end + return 0 +} + +# The api-key exchange. Always called from inside a secret region. +np__token_exchange() { + if [ -z "${NP_TRACE_API_KEY:-}" ]; then + printf '' + return 0 + fi + + _token_exchange_cache="$NP_TRACE_DIR/token" + if [ -f "$_token_exchange_cache" ]; then + _token_exchange_exp=$(sed -n '1p' "$_token_exchange_cache" 2>/dev/null) + _token_exchange_val=$(sed -n '2p' "$_token_exchange_cache" 2>/dev/null) + case "$_token_exchange_exp" in + '' | *[!0-9]*) _token_exchange_exp=0 ;; + esac + if [ -n "$_token_exchange_val" ] && [ "$_token_exchange_exp" -gt "$(date +%s)" ]; then + printf '%s' "$_token_exchange_val" + return 0 + fi + fi + + _token_exchange_body=$(curl -sS -X POST \ + --connect-timeout "$NP_TRACE_CONNECT_TIMEOUT" --max-time "$NP_TRACE_MAX_TIME" \ + -H 'Content-Type: application/json' \ + -d "$(np__json_obj apiKey "$NP_TRACE_API_KEY")" \ + "${NP_TRACE_AUTH_URL:-$NP_TRACE_DEFAULT_AUTH_URL}/token" 2>/dev/null) || _token_exchange_body='' + + _token_exchange_new=$(printf '%s' "$_token_exchange_body" | + sed -n 's/.*"access_token"[[:space:]]*:[[:space:]]*"\([^"]*\)".*/\1/p') + if [ -z "$_token_exchange_new" ]; then + np__drop 'auth' 'token exchange failed' + printf '' + return 0 + fi + ( umask 077; printf '%s\n%s\n' "$(( $(date +%s) + 3540 ))" "$_token_exchange_new" > "$_token_exchange_cache" ) + printf '%s' "$_token_exchange_new" + return 0 +} + +# The auth header goes to curl via --config from a mode-600 file, NEVER as -H +# in argv: CI runs with `set -x`, and an argv-borne header prints the token +# straight into the build log. +np__auth_config() { + np__secret_begin + _auth_config_file="$NP_TRACE_DIR/curlcfg.$$" + ( umask 077; printf 'header = "Authorization: Bearer %s"\n' "$(np__token)" > "$_auth_config_file" ) + np__secret_end + printf '%s' "$_auth_config_file" + return 0 +} + +# POST one spool file. Prints the HTTP status code, or 000 on a network failure. +np__post_event() { + _post_event_cfg=$(np__auth_config) + _post_event_code=$(curl -sS -o /dev/null -w '%{http_code}' -X POST \ + --config "$_post_event_cfg" \ + --connect-timeout "$NP_TRACE_CONNECT_TIMEOUT" --max-time "$NP_TRACE_MAX_TIME" \ + -H 'Content-Type: application/json' \ + --data-binary "@$1" \ + "${NP_TRACE_BASE_URL:-$NP_TRACE_DEFAULT_BASE_URL}/events" 2>/dev/null) || _post_event_code='000' + rm -f "$_post_event_cfg" 2>/dev/null || : + case "$_post_event_code" in + '' | *[!0-9]*) _post_event_code='000' ;; + esac + printf '%s' "$_post_event_code" + return 0 +} + +# ---- src/flush.sh ---- +# flush.sh — the spool drain. Bounded by a wall-clock budget so a dead API can +# never hang process exit; every path returns 0. + +NP_TRACE_FLUSH_TIMEOUT="${NP_TRACE_FLUSH_TIMEOUT:-10}" +NP_TRACE_MAX_RETRIES="${NP_TRACE_MAX_RETRIES:-3}" + +np__attempts_of() { + _attempts_of_n=$(cat "$1.attempts" 2>/dev/null || printf '0') + case "$_attempts_of_n" in + '' | *[!0-9]*) _attempts_of_n=0 ;; + esac + printf '%s' "$_attempts_of_n" +} + +np__fail_event() { + mv "$1" "$NP_TRACE_DIR/failed/" 2>/dev/null || rm -f "$1" 2>/dev/null || : + rm -f "$1.attempts" 2>/dev/null || : + np__drop "${1##*/}" "$2" + return 0 +} + +np_trace_flush() { + [ -n "${NP_TRACE_DIR:-}" ] || return 0 + [ -d "$NP_TRACE_DIR/spool" ] || return 0 + [ "${NP_TRACE_ENABLED:-1}" = '1' ] || return 0 + _flush_deadline=$(( $(date +%s) + NP_TRACE_FLUSH_TIMEOUT )) + + for _flush_file in "$NP_TRACE_DIR/spool"/*.json; do + [ -f "$_flush_file" ] || continue + if [ "$(date +%s)" -ge "$_flush_deadline" ]; then + # Budget spent. Remaining events stay on disk for the next flush or a + # later np_trace_recover; the process exits on time regardless. This is + # the guarantee that a dead API cannot hang a build. + return 0 + fi + + _flush_code=$(np__post_event "$_flush_file") + case "$_flush_code" in + 201 | 200) + # 200 is an idempotent re-POST of an already-accepted event. + rm -f "$_flush_file" "$_flush_file.attempts" 2>/dev/null || : + ;; + 400) + # A contract violation. Never retried — retrying cannot change it. + np__fail_event "$_flush_file" "rejected 400" + ;; + 401 | 403) + rm -f "$NP_TRACE_DIR/token" 2>/dev/null || : + np__fail_event "$_flush_file" "unauthorized $_flush_code" + ;; + *) + _flush_n=$(( $(np__attempts_of "$_flush_file") + 1 )) + if [ "$_flush_n" -gt "$NP_TRACE_MAX_RETRIES" ]; then + np__fail_event "$_flush_file" "gave up after $_flush_n attempts (last status $_flush_code)" + else + printf '%s' "$_flush_n" > "$_flush_file.attempts" 2>/dev/null || : + fi + ;; + esac + done + return 0 +} + +np_trace_shutdown() { + np_trace_flush + if [ -n "${NP_TRACE_DIR:-}" ] && [ "${NP_TRACE_KEEP_STATE:-0}" != '1' ]; then + rm -rf "$NP_TRACE_DIR" 2>/dev/null || : + fi + return 0 +} + +# Re-deliver a previous process's leftover spool. Idempotent by construction: +# the spool file name IS the event id, so the API answers a re-POST with +# 200 duplicate. +np_trace_recover() { + np_trace_flush + return 0 +} + +np__install_trap() { + if [ -z "${NP_TRACE_NO_TRAP:-}" ]; then + trap 'np_trace_flush' EXIT + trap 'np_trace_flush' INT + trap 'np_trace_flush' TERM + fi + return 0 +} + +# ---- src/propagation.sh ---- +# --------------------------------------------------------------------------- +# Propagation +# +# Cross-process trace context, wire-identical to the Go and JS SDKs: a single +# carrier value packing "||". The '|' delimiter is +# reserved, so the value splits unambiguously even though a run_id may itself +# contain '~' and '@'. +# +# The carrier travels in the NP_TRACE environment variable. Note that this is +# deliberately OUTSIDE the NP_TRACE_* configuration namespace the SDK reads for +# its own settings: NP_TRACE is context handed to us by a caller, not something +# a user configures. +# --------------------------------------------------------------------------- + +# np_trace_inject [handle] +# +# Print the carrier value for a handle (defaults to the ambient node), for +# handing to a child process. Prints nothing when there is no node to inject, +# so `NP_TRACE=$(np_trace_inject)` is always safe. +np_trace_inject() { + [ "${NP_TRACE_ENABLED:-1}" = '1' ] || return 0 + _inject_h=$(np__resolve_handle "${1:-}") + np__is_handle "$_inject_h" || return 0 + printf '%s%s%s%s%s' \ + "$NP_CARRIER_VERSION" "$NP_CARRIER_DELIMITER" \ + "$(np__node_get "$_inject_h" trace_id)" "$NP_CARRIER_DELIMITER" \ + "$(np__node_get "$_inject_h" run_id)" + return 0 +} + +# np_trace_extract [carrier] +# +# Parse a carrier value (defaults to $NP_TRACE) and print " ". +# Returns 1 when there is no usable context, so callers can branch: +# +# if ctx=$(np_trace_extract); then set -- $ctx; fi +# +# When only a trace id is present it is used for both, matching the Go SDK, so +# the result is always a usable pair. +np_trace_extract() { + _extract_raw=${1-${NP_TRACE:-}} + [ -n "$_extract_raw" ] || return 1 + + case "$_extract_raw" in + "$NP_CARRIER_VERSION$NP_CARRIER_DELIMITER"*) ;; + *) return 1 ;; + esac + _extract_rest=${_extract_raw#*"$NP_CARRIER_DELIMITER"} + + # trace_id is up to the next delimiter; run_id is the whole remainder, which + # may itself contain '~' and '@' but never a delimiter. + case "$_extract_rest" in + *"$NP_CARRIER_DELIMITER"*) + _extract_trace=${_extract_rest%%"$NP_CARRIER_DELIMITER"*} + _extract_run=${_extract_rest#*"$NP_CARRIER_DELIMITER"} + ;; + *) + _extract_trace=$_extract_rest + _extract_run=$_extract_rest + ;; + esac + [ -n "$_extract_trace" ] || return 1 + [ -n "$_extract_run" ] || _extract_run=$_extract_trace + + printf '%s %s' "$_extract_trace" "$_extract_run" + return 0 +} + +# np_trace_adopt [carrier] +# +# Attach to an upstream node and return a handle standing in for it, so work +# started here nests UNDERNEATH it: +# +# parent=$(np_trace_adopt) || parent=$(np_trace_run --run-id "$(np_trace_occurrence)") +# step=$(np_trace_step "$parent" build) +# +# The adopted node belongs to whoever created it — typically the np CLI, which +# exports NP_TRACE per workflow step. We hold its ids so children derive +# correctly, but must never speak for it: it is marked foreign, so it emits no +# node event of its own and the terminal verbs refuse to close it. Children +# hanging off it still emit their own containment edges, which IS ours to say. +# +# Returns 1 when there is no upstream context, leaving the caller to open a root +# run instead. +np_trace_adopt() { + [ "${NP_TRACE_ENABLED:-1}" = '1' ] || return 1 + _adopt_ctx=$(np_trace_extract "${1-${NP_TRACE:-}}") || return 1 + _adopt_trace=${_adopt_ctx%% *} + _adopt_run=${_adopt_ctx#* } + + if ! _adopt_why=$(np__trace_id_violation "$_adopt_trace"); then + np__drop 'adopt' "trace_id $_adopt_why" + return 1 + fi + # An upstream run_id is commonly a DERIVED path (parent~key@attempt.iteration) + # rather than a named id — the np CLI hands us the step it is running. Accept + # either: parse it as a node path first, and only fall back to the named-id + # rules when it has no delimiter. + if ! _adopt_coords=$(np__parse_node_id "$_adopt_run" 2>/dev/null); then + _adopt_coords='' + if ! _adopt_why=$(np__named_id_violation "$_adopt_run"); then + np__drop 'adopt' "run_id $_adopt_why" + return 1 + fi + fi + + _adopt_h=$(np__handle_new) + np__node_set "$_adopt_h" kind run + np__node_set "$_adopt_h" trace_id "$_adopt_trace" + np__node_set "$_adopt_h" run_id "$_adopt_run" + # A keyed (derived-path) node event must carry its coordinate triple — the + # API rejects a derived run_id whose key/attempt/iteration are absent. The + # foreign re-emit (np__flush_foreign) therefore needs the coordinates on the + # handle, even though the node itself stays the upstream owner's to close. + if [ -n "$_adopt_coords" ]; then + np__node_set "$_adopt_h" key "$(printf '%s' "$_adopt_coords" | cut -d' ' -f2)" + np__node_set "$_adopt_h" attempt "$(printf '%s' "$_adopt_coords" | cut -d' ' -f3)" + np__node_set "$_adopt_h" iteration "$(printf '%s' "$_adopt_coords" | cut -d' ' -f4)" + fi + np__node_set "$_adopt_h" nrn "${NP_TRACE_NRN:-}" + np__node_set "$_adopt_h" foreign 1 + # started=1 suppresses the lazy `started` emit; closed=0 keeps it usable as a + # parent for the whole script. + np__node_set "$_adopt_h" started 1 + np__node_set "$_adopt_h" closed 0 + np__ambient_set "$_adopt_h" + printf '%s' "$_adopt_h" + return 0 +} + +# True when a handle stands in for a node owned by another process. +np__is_foreign() { + [ "$(np__node_get "$1" foreign)" = '1' ] +} + +# ---- src/api.sh ---- +# api.sh — the public producer surface. Every function here returns 0, always: +# tracing must never fail the caller. +# +# Every node-scoped function takes an OPTIONAL leading handle. This is one +# function with a defaulted argument, not two ways to say the same thing: when +# the first argument is not a handle it falls back to the innermost open node. + +np_trace_init() { + while [ "$#" -gt 0 ]; do + case "$1" in + --producer) NP_TRACE_PRODUCER=${2:-}; shift 2 ;; + --base-url) NP_TRACE_BASE_URL=${2:-}; shift 2 ;; + --auth-url) NP_TRACE_AUTH_URL=${2:-}; shift 2 ;; + --api-key) NP_TRACE_API_KEY=${2:-}; shift 2 ;; + --token) NP_TRACE_TOKEN=${2:-}; shift 2 ;; + --nrn) NP_TRACE_NRN=${2:-}; shift 2 ;; + --enabled) NP_TRACE_ENABLED=${2:-1}; shift 2 ;; + --no-trap) NP_TRACE_NO_TRAP=1; shift ;; + *) shift ;; + esac + done + NP_TRACE_ENABLED="${NP_TRACE_ENABLED:-1}" + np__state_init + # No network call here, deliberately: a down auth endpoint must never delay + # the start of a pipeline. The token is fetched lazily, at first flush. + np__install_trap + return 0 +} + +# --------------------------------------------------------------------------- +# Emission +# --------------------------------------------------------------------------- + +# Emit the node event for a handle at the given status, carrying whatever +# context is currently staged. +np__emit_node() { + _emit_node_h=$1 + _emit_node_status=$2 + [ "${NP_TRACE_ENABLED:-1}" = '1' ] || return 0 + + _emit_node_labels=$(np__node_get "$_emit_node_h" labels) + _emit_node_facets=$(np__node_get "$_emit_node_h" facets) + _emit_node_key=$(np__node_get "$_emit_node_h" key) + _emit_node_schema=$(np__node_get "$_emit_node_h" schema_url) + + if [ -n "$_emit_node_key" ]; then + _emit_node_data=$(np__json_obj_raw \ + trace_id "$(np__json_str "$(np__node_get "$_emit_node_h" trace_id)")" \ + run_id "$(np__json_str "$(np__node_get "$_emit_node_h" run_id)")" \ + key "$(np__json_str "$_emit_node_key")" \ + attempt "$(np__node_get "$_emit_node_h" attempt)" \ + iteration "$(np__node_get "$_emit_node_h" iteration)" \ + status "$(np__json_str "$_emit_node_status")" \ + labels "$_emit_node_labels" \ + facets "$_emit_node_facets" \ + schema_url "$(if [ -n "$_emit_node_schema" ]; then np__json_str "$_emit_node_schema"; fi)") + else + _emit_node_data=$(np__json_obj_raw \ + trace_id "$(np__json_str "$(np__node_get "$_emit_node_h" trace_id)")" \ + run_id "$(np__json_str "$(np__node_get "$_emit_node_h" run_id)")" \ + status "$(np__json_str "$_emit_node_status")" \ + labels "$_emit_node_labels" \ + facets "$_emit_node_facets" \ + schema_url "$(if [ -n "$_emit_node_schema" ]; then np__json_str "$_emit_node_schema"; fi)") + fi + + np__spool "$NP_TYPE_NODE_RUN" "$(np__node_get "$_emit_node_h" nrn)" "$_emit_node_data" >/dev/null + return 0 +} + +# A run ref for a handle — the self-describing address used on edge endpoints. +np__ref_of() { + np__json_obj \ + type run \ + trace_id "$(np__node_get "$1" trace_id)" \ + run_id "$(np__node_get "$1" run_id)" +} + +np__emit_parent_edge() { + [ "${NP_TRACE_ENABLED:-1}" = '1' ] || return 0 + _emit_parent_edge_data=$(np__json_obj_raw from "$(np__ref_of "$1")" to "$(np__ref_of "$2")") + np__spool "$NP_TYPE_EDGE_PARENT" "$(np__node_get "$1" nrn)" "$_emit_parent_edge_data" >/dev/null + return 0 +} + +# Force the lazy `started`. Idempotent. +# +# Shell has no microtask, so `started` is emitted at the first event that must +# follow it — a terminal, a child open, an explicit call, or flush. Context +# staged before that lands on `started`; context staged after lands on the +# terminal. Same observable semantics as the JS and Go SDKs, without a timer. +np_trace_start() { + _start_h=$(np__resolve_handle "${1:-}") + np__is_handle "$_start_h" || return 0 + if [ "$(np__node_get "$_start_h" started)" = '1' ]; then + return 0 + fi + np__node_set "$_start_h" started 1 + np__emit_node "$_start_h" "$NP_STATUS_STARTED" + return 0 +} + +# --------------------------------------------------------------------------- +# Nodes +# --------------------------------------------------------------------------- + +np_trace_run() { + [ "${NP_TRACE_ENABLED:-1}" = '1' ] || return 0 + _run_trace='' + _run_run='' + _run_nrn="${NP_TRACE_NRN:-}" + while [ "$#" -gt 0 ]; do + case "$1" in + --trace-id) _run_trace=${2:-}; shift 2 ;; + --run-id) _run_run=${2:-}; shift 2 ;; + --nrn) _run_nrn=${2:-}; shift 2 ;; + *) shift ;; + esac + done + # A lone root run's trace_id defaults to its run_id, and vice versa. + [ -n "$_run_trace" ] || _run_trace=$_run_run + [ -n "$_run_run" ] || _run_run=$_run_trace + + if ! _run_why=$(np__trace_id_violation "$_run_trace"); then + np__drop 'run' "trace_id $_run_why" + return 0 + fi + if ! _run_why=$(np__named_id_violation "$_run_run"); then + np__drop 'run' "run_id $_run_why" + return 0 + fi + + _run_h=$(np__handle_new) + np__node_set "$_run_h" kind run + np__node_set "$_run_h" trace_id "$_run_trace" + np__node_set "$_run_h" run_id "$_run_run" + np__node_set "$_run_h" nrn "$_run_nrn" + np__node_set "$_run_h" auto_started_at "$(np__iso8601)" + np__node_set "$_run_h" started 0 + np__node_set "$_run_h" closed 0 + np__ambient_set "$_run_h" + printf '%s' "$_run_h" + return 0 +} + +# np_trace_step [handle] [--attempt N] [--iteration N] +np_trace_step() { + [ "${NP_TRACE_ENABLED:-1}" = '1' ] || return 0 + _step_parent=$(np__resolve_handle "${1:-}") + if np__is_handle "${1:-}"; then + shift + fi + _step_key=${1:-} + if [ "$#" -gt 0 ]; then + shift + fi + _step_attempt=0 + _step_iteration=0 + while [ "$#" -gt 0 ]; do + case "$1" in + --attempt) _step_attempt=${2:-0}; shift 2 ;; + --iteration) _step_iteration=${2:-0}; shift 2 ;; + *) shift ;; + esac + done + + if ! np__is_handle "$_step_parent"; then + np__drop 'step' 'no parent node in scope' + return 0 + fi + if ! _step_why=$(np__key_violation "$_step_key"); then + np__drop 'step' "key $_step_why" + return 0 + fi + case "$_step_attempt$_step_iteration" in + '' | *[!0-9]*) np__drop 'step' 'attempt and iteration must be integers'; return 0 ;; + esac + + # Opening a child forces the parent's started: a parent edge must not point + # at a node the read model has never seen. + np_trace_start "$_step_parent" + + _step_id=$(np__derive_child_id "$(np__node_get "$_step_parent" run_id)" \ + "$_step_key" "$_step_attempt" "$_step_iteration") + + _step_h=$(np__handle_new) + np__node_set "$_step_h" kind step + np__node_set "$_step_h" trace_id "$(np__node_get "$_step_parent" trace_id)" + np__node_set "$_step_h" run_id "$_step_id" + np__node_set "$_step_h" nrn "$(np__node_get "$_step_parent" nrn)" + np__node_set "$_step_h" key "$_step_key" + np__node_set "$_step_h" attempt "$_step_attempt" + np__node_set "$_step_h" iteration "$_step_iteration" + np__node_set "$_step_h" parent "$_step_parent" + np__node_set "$_step_h" auto_started_at "$(np__iso8601)" + np__node_set "$_step_h" started 0 + np__node_set "$_step_h" closed 0 + + np_trace_start "$_step_h" + np__emit_parent_edge "$_step_parent" "$_step_h" + np__ambient_set "$_step_h" + printf '%s' "$_step_h" + return 0 +} + +# A named child run — a new scope under the same trace. +np_trace_child() { + [ "${NP_TRACE_ENABLED:-1}" = '1' ] || return 0 + _child_parent=$(np__resolve_handle "${1:-}") + if np__is_handle "${1:-}"; then + shift + fi + _child_run='' + while [ "$#" -gt 0 ]; do + case "$1" in + --run-id) _child_run=${2:-}; shift 2 ;; + *) shift ;; + esac + done + if ! np__is_handle "$_child_parent"; then + np__drop 'child' 'no parent node in scope' + return 0 + fi + if ! _child_why=$(np__named_id_violation "$_child_run"); then + np__drop 'child' "run_id $_child_why" + return 0 + fi + np_trace_start "$_child_parent" + _child_h=$(np_trace_run --trace-id "$(np__node_get "$_child_parent" trace_id)" \ + --run-id "$_child_run" \ + --nrn "$(np__node_get "$_child_parent" nrn)") + np__is_handle "$_child_h" || return 0 + np__node_set "$_child_h" parent "$_child_parent" + np_trace_start "$_child_h" + np__emit_parent_edge "$_child_parent" "$_child_h" + np__ambient_set "$_child_h" + printf '%s' "$_child_h" + return 0 +} + +# --------------------------------------------------------------------------- +# Staging context +# --------------------------------------------------------------------------- + +# Upsert one pre-formed `"key":value` entry into a node's staged OBJECT store +# (labels / facets) under its key: re-staging a key REPLACES its entry, so an +# event never ships duplicate keys the parser has to break ties on — and a +# step that re-stages its narrative per heartbeat never grows its payload. +# $1 handle, $2 store key, $3 the `"key":value` entry, $4 the entry's key. +np__stage_entry() { + _stage_entry_handle=$1 + _stage_entry_store=$2 + _stage_entry_slot=$(np__descriptor_slot "$4") + _stage_entry_slots=$(np__node_get "$_stage_entry_handle" "${_stage_entry_store}_slots") + case " $_stage_entry_slots " in + *" $_stage_entry_slot "*) ;; + *) + _stage_entry_slots="${_stage_entry_slots:+$_stage_entry_slots }$_stage_entry_slot" + np__node_set "$_stage_entry_handle" "${_stage_entry_store}_slots" "$_stage_entry_slots" + ;; + esac + np__node_set "$_stage_entry_handle" "${_stage_entry_store}.$_stage_entry_slot" "$3" + _stage_entry_joined='' + for _stage_entry_each in $_stage_entry_slots; do + _stage_entry_value=$(np__node_get "$_stage_entry_handle" "${_stage_entry_store}.$_stage_entry_each") + [ -n "$_stage_entry_value" ] || continue + _stage_entry_joined="${_stage_entry_joined:+$_stage_entry_joined,}$_stage_entry_value" + done + np__node_set "$_stage_entry_handle" "$_stage_entry_store" "{$_stage_entry_joined}" + return 0 +} + +# Merge a pre-formed `"key":value` fragment into the node's staged labels. +np__stage_label() { + _stage_label_key=$(printf '%s' "$2" | sed -n 's/^"\([^"]*\)".*/\1/p') + np__stage_entry "$1" labels "$2" "${_stage_label_key:-$2}" + return 0 +} + +# Last write wins per namespace: re-staging a facet replaces its entry. +np__stage_facet() { + np__stage_entry "$1" facets "$(np__json_str "$2"):$3" "$2" + return 0 +} + +# Staged context normally rides the node's NEXT lifecycle emit. A FOREIGN +# (adopted) node never has one here — its owner closes it in another process — +# so anything staged on it would die in local state. Re-emit `started` with the +# full current bag instead (additive, the same shape the JS SDK's +# late-enrichment flush produces): the fold keeps the node's real outcome (the +# owner's terminal is later by time) and gains the facts this process observed. +np__flush_foreign() { + [ "$(np__node_get "$1" foreign)" = '1' ] || return 0 + np__emit_node "$1" "$NP_STATUS_STARTED" + return 0 +} + +# np_trace_labels [handle] key=value ... +np_trace_labels() { + _labels_h=$(np__resolve_handle "${1:-}") + if np__is_handle "${1:-}"; then + shift + fi + np__is_handle "$_labels_h" || return 0 + for _labels_pair in "$@"; do + case "$_labels_pair" in + *=*) ;; + *) continue ;; + esac + _labels_k=${_labels_pair%%=*} + _labels_v=${_labels_pair#*=} + # An absent optional is omitted, never recorded as the string "null". + if [ -n "$_labels_k" ] && [ -n "$_labels_v" ]; then + np__stage_label "$_labels_h" "$(np__json_str "$_labels_k"):$(np__json_str "$_labels_v")" + fi + done + np__flush_foreign "$_labels_h" + return 0 +} + +# np_trace_facet [handle] — your own namespace. +np_trace_facet() { + _facet_h=$(np__resolve_handle "${1:-}") + if np__is_handle "${1:-}"; then + shift + fi + np__is_handle "$_facet_h" || return 0 + if [ -z "${1:-}" ] || [ -z "${2:-}" ]; then + return 0 + fi + np__stage_facet "$_facet_h" "$1" "$2" + np__flush_foreign "$_facet_h" + return 0 +} + +np_trace_schema() { + _schema_h=$(np__resolve_handle "${1:-}") + if np__is_handle "${1:-}"; then + shift + fi + np__is_handle "$_schema_h" || return 0 + np__node_set "$_schema_h" schema_url "${1:-}" + return 0 +} + +np_trace_explain() { + _explain_h=$(np__resolve_handle "${1:-}") + if np__is_handle "${1:-}"; then + shift + fi + np__is_handle "$_explain_h" || return 0 + _explain_title='' + _explain_what='' + _explain_why='' + _explain_impact='' + _explain_next='' + _explain_sev='' + while [ "$#" -gt 0 ]; do + case "$1" in + --title) _explain_title=${2:-}; shift 2 ;; + --what) _explain_what=${2:-}; shift 2 ;; + --why) _explain_why=${2:-}; shift 2 ;; + --impact) _explain_impact=${2:-}; shift 2 ;; + --next) _explain_next=${2:-}; shift 2 ;; + --severity) _explain_sev=${2:-}; shift 2 ;; + *) shift ;; + esac + done + if [ -z "$_explain_title" ]; then + np__drop 'explain' 'title is required' + return 0 + fi + np__stage_facet "$_explain_h" "$NP_FACET_EXPLAIN" \ + "$(np__json_obj title "$_explain_title" severity "$_explain_sev" what "$_explain_what" \ + why "$_explain_why" impact "$_explain_impact" next "$_explain_next")" + np__flush_foreign "$_explain_h" + return 0 +} + +np_trace_error() { + _error_h=$(np__resolve_handle "${1:-}") + if np__is_handle "${1:-}"; then + shift + fi + np__is_handle "$_error_h" || return 0 + _error_msg='' + _error_code='' + _error_stack='' + _error_details='' + while [ "$#" -gt 0 ]; do + case "$1" in + --message) _error_msg=${2:-}; shift 2 ;; + --code) _error_code=${2:-}; shift 2 ;; + --stack-trace) _error_stack=${2:-}; shift 2 ;; + # A JSON object with the diagnosis's structured evidence (counts, the + # failing probe, ...) — the sibling SDKs' error `details`. + --details) _error_details=${2:-}; shift 2 ;; + *) + if [ -z "$_error_msg" ]; then + _error_msg=$1 + fi + shift + ;; + esac + done + [ -n "$_error_msg" ] || return 0 + case "$_error_details" in + '' | \{*) ;; + *) _error_details='' ;; + esac + np__stage_facet "$_error_h" "$NP_FACET_ERROR" \ + "$(np__json_obj_raw \ + message "$(np__json_str "$_error_msg")" \ + code "$(if [ -n "$_error_code" ]; then np__json_str "$_error_code"; fi)" \ + stack_trace "$(if [ -n "$_error_stack" ]; then np__json_str "$_error_stack"; fi)" \ + details "$_error_details")" + np__flush_foreign "$_error_h" + return 0 +} + +np_trace_timing() { + _timing_h=$(np__resolve_handle "${1:-}") + if np__is_handle "${1:-}"; then + shift + fi + np__is_handle "$_timing_h" || return 0 + while [ "$#" -gt 0 ]; do + case "$1" in + --started-at) np__node_set "$_timing_h" started_at "${2:-}"; shift 2 ;; + --ended-at) np__node_set "$_timing_h" ended_at "${2:-}"; shift 2 ;; + *) shift ;; + esac + done + return 0 +} + +# Stamp the auto timing facet, letting any manual override win per field. +np__stage_timing() { + _stage_timing_started=$(np__node_get "$1" started_at) + _stage_timing_ended=$(np__node_get "$1" ended_at) + [ -n "$_stage_timing_started" ] || _stage_timing_started=$(np__node_get "$1" auto_started_at) + [ -n "$_stage_timing_ended" ] || _stage_timing_ended=$2 + np__stage_facet "$1" "$NP_FACET_TIMING" \ + "$(np__json_obj started_at "$_stage_timing_started" ended_at "$_stage_timing_ended")" + return 0 +} + +# --------------------------------------------------------------------------- +# Lineage — produces/consumes edges with io pointers +# --------------------------------------------------------------------------- + +# A dataset ref for an edge endpoint. The id is the CANONICAL dataset id — the +# exact string a producer and a consumer must both name for lineage to join +# them by value (an ARN, an FQDN, `:` for an asset) — never a +# synthesised id. +np__dataset_ref() { + np__json_obj type dataset id "$1" +} + +# A store-safe slot id for a descriptor's identity string (an io NAME, an +# affordance KIND): cksum is POSIX everywhere and collision-resistant enough +# for a node's handful of descriptors. +np__descriptor_slot() { + printf '%s' "$1" | cksum | tr ' \t' '__' +} + +# Upsert one descriptor into a node's list by IDENTITY; the facet is re-staged +# whole each time (last write wins per namespace). A re-declared identity +# REPLACES its previous descriptor in place — a step that reports the same +# name as its state evolves ("instances" per heartbeat) owns ONE entry +# carrying the latest telling, at its first telling's position — while a new +# identity appends. $1 handle, $2 facet namespace, $3 descriptor store key, +# $4 the already-formed descriptor JSON, $5 the identity string. +np__upsert_descriptor() { + _upsert_descriptor_handle=$1 + _upsert_descriptor_facet=$2 + _upsert_descriptor_store=$3 + _upsert_descriptor_slot=$(np__descriptor_slot "$5") + _upsert_descriptor_slots=$(np__node_get "$_upsert_descriptor_handle" "${_upsert_descriptor_store}_slots") + case " $_upsert_descriptor_slots " in + *" $_upsert_descriptor_slot "*) ;; + *) + _upsert_descriptor_slots="${_upsert_descriptor_slots:+$_upsert_descriptor_slots }$_upsert_descriptor_slot" + np__node_set "$_upsert_descriptor_handle" "${_upsert_descriptor_store}_slots" "$_upsert_descriptor_slots" + ;; + esac + np__node_set "$_upsert_descriptor_handle" "${_upsert_descriptor_store}.$_upsert_descriptor_slot" "$4" + _upsert_descriptor_list='' + for _upsert_descriptor_each in $_upsert_descriptor_slots; do + _upsert_descriptor_value=$(np__node_get "$_upsert_descriptor_handle" "${_upsert_descriptor_store}.$_upsert_descriptor_each") + [ -n "$_upsert_descriptor_value" ] || continue + _upsert_descriptor_list="${_upsert_descriptor_list:+$_upsert_descriptor_list,}$_upsert_descriptor_value" + done + np__node_set "$_upsert_descriptor_handle" "$_upsert_descriptor_store" "$_upsert_descriptor_list" + np__stage_facet "$_upsert_descriptor_handle" "$_upsert_descriptor_facet" "[$_upsert_descriptor_list]" + return 0 +} + +# Build one io descriptor from its parsed parts, choosing the kind by which +# parts are present: a uri is a POINTER (large data referenced, not inlined), +# a source+external-id is a REF (an entity in an external catalog), a JSON +# value is INLINE (carried in the event itself). Prints the descriptor, or +# nothing (with a drop) when the parts don't form one. +# $1 verb (for drop records), $2 name, $3 inline JSON, $4 uri, $5 ref source, +# $6 ref external id, $7 ref version. +np__build_io_descriptor() { + _build_io_descriptor_verb=$1 + _build_io_descriptor_name=$2 + _build_io_descriptor_inline=$3 + _build_io_descriptor_uri=$4 + _build_io_descriptor_ref_source=$5 + _build_io_descriptor_ref_id=$6 + _build_io_descriptor_ref_version=$7 + if [ -z "$_build_io_descriptor_name" ]; then + np__drop "$_build_io_descriptor_verb" 'a descriptor name is required' + return 1 + fi + if [ -n "$_build_io_descriptor_uri" ]; then + np__json_obj kind pointer name "$_build_io_descriptor_name" uri "$_build_io_descriptor_uri" + return 0 + fi + if [ -n "$_build_io_descriptor_ref_source" ] && [ -n "$_build_io_descriptor_ref_id" ]; then + np__json_obj kind ref name "$_build_io_descriptor_name" source "$_build_io_descriptor_ref_source" \ + external_id "$_build_io_descriptor_ref_id" version "$_build_io_descriptor_ref_version" + return 0 + fi + if [ -n "$_build_io_descriptor_inline" ]; then + case "$_build_io_descriptor_inline" in + \{* | \[* | \"* | [0-9-]* | true | false | null) + np__json_obj_raw kind '"inline"' name "$(np__json_str "$_build_io_descriptor_name")" value "$_build_io_descriptor_inline" + return 0 + ;; + esac + np__drop "$_build_io_descriptor_verb" 'value must be JSON' + return 1 + fi + np__drop "$_build_io_descriptor_verb" 'a JSON value, --uri, or --source + --external-id is required' + return 1 +} + +# The shared body of np_trace_output / np_trace_input. +# $1 direction (out|in), $2 verb, then the caller's argv: +# [handle] [] [--uri U] [--source S --external-id E [--version V]] +np__declare_io() { + _declare_io_direction=$1 + _declare_io_verb=$2 + shift 2 + _declare_io_handle=$(np__resolve_handle "${1:-}") + if np__is_handle "${1:-}"; then + shift + fi + np__is_handle "$_declare_io_handle" || { np__drop "$_declare_io_verb" 'no node in scope'; return 0; } + _declare_io_name=${1:-} + if [ "$#" -gt 0 ]; then + shift + fi + _declare_io_inline='' + _declare_io_uri='' + _declare_io_ref_source='' + _declare_io_ref_id='' + _declare_io_ref_version='' + while [ "$#" -gt 0 ]; do + case "$1" in + --uri) _declare_io_uri=${2:-}; shift 2 ;; + --source) _declare_io_ref_source=${2:-}; shift 2 ;; + --external-id) _declare_io_ref_id=${2:-}; shift 2 ;; + --version) _declare_io_ref_version=${2:-}; shift 2 ;; + *) + if [ -z "$_declare_io_inline" ]; then + _declare_io_inline=$1 + fi + shift + ;; + esac + done + _declare_io_descriptor=$(np__build_io_descriptor "$_declare_io_verb" "$_declare_io_name" "$_declare_io_inline" \ + "$_declare_io_uri" "$_declare_io_ref_source" "$_declare_io_ref_id" "$_declare_io_ref_version") || return 0 + if [ "$_declare_io_direction" = 'out' ]; then + np__upsert_descriptor "$_declare_io_handle" "$NP_FACET_OUTPUT" io_output "$_declare_io_descriptor" "$_declare_io_name" + else + np__upsert_descriptor "$_declare_io_handle" "$NP_FACET_INPUT" io_input "$_declare_io_descriptor" "$_declare_io_name" + fi + np__flush_foreign "$_declare_io_handle" + return 0 +} + +# np_trace_output [handle] [] [--uri U] [--source S --external-id E [--version V]] +# +# Record what this node PRODUCED: an inline value carried in the event +# (`np_trace_output instances '{"healthy":2}'`), a pointer to large data +# (`--uri`), or a ref to an external catalog entity (`--source`/`--external-id`). +# For an artifact that should ALSO join the lineage graph, prefer +# np_trace_produces (descriptor + edge in one call). +np_trace_output() { + [ "${NP_TRACE_ENABLED:-1}" = '1' ] || return 0 + np__declare_io out output "$@" + return 0 +} + +# np_trace_input [handle] [] [--uri U] [--source S --external-id E [--version V]] +# +# Record what this node CONSUMED; see np_trace_output. +np_trace_input() { + [ "${NP_TRACE_ENABLED:-1}" = '1' ] || return 0 + np__declare_io in input "$@" + return 0 +} + +# np__emit_io_edge [descriptor-json] [descriptor-name] +# +# Emit one lineage edge. The direction decides everything else: `out` is +# edge.produces + tracing.output, `in` is edge.consumes + tracing.input. +# +# With a descriptor the io is declared ONCE: it upserts into the node's io +# facet BY NAME (a re-declared name replaces its entry), and the edge carries +# a tracing.binding built from it. The binding's WIRE shape is `{name, +# content_type?, size_bytes?}` — never the io descriptor itself (whose +# kind/uri/value the binding schema rejects, dead-lettering the edge). +# Without a descriptor, the edge records lineage only. +# +# On a FOREIGN (adopted) node this is an observed fact, exactly like +# np_trace_error: the edge is ours to say, and the staged io facet reaches the +# wire through the foreign re-emit. +np__emit_io_edge() { + _emit_io_edge_handle=$1 + _emit_io_edge_direction=$2 + _emit_io_edge_dataset_id=$3 + + if [ "$_emit_io_edge_direction" = 'out' ]; then + _emit_io_edge_edge_type=$NP_TYPE_EDGE_PRODUCES + _emit_io_edge_facet_namespace=$NP_FACET_OUTPUT + _emit_io_edge_descriptor_store=io_output + else + _emit_io_edge_edge_type=$NP_TYPE_EDGE_CONSUMES + _emit_io_edge_facet_namespace=$NP_FACET_INPUT + _emit_io_edge_descriptor_store=io_input + fi + + _emit_io_edge_descriptor=$4 + _emit_io_edge_name=${5:-} + + if [ -n "$_emit_io_edge_descriptor" ]; then + np__upsert_descriptor "$_emit_io_edge_handle" "$_emit_io_edge_facet_namespace" "$_emit_io_edge_descriptor_store" \ + "$_emit_io_edge_descriptor" "${_emit_io_edge_name:-$_emit_io_edge_descriptor}" + fi + + # An edge must not point FROM a node the read model has never seen. + np_trace_start "$_emit_io_edge_handle" + + if [ -n "$_emit_io_edge_descriptor" ] && [ -n "$_emit_io_edge_name" ]; then + _emit_io_edge_binding=$(np__json_obj name "$_emit_io_edge_name") + _emit_io_edge_edge_data=$(np__json_obj_raw \ + from "$(np__ref_of "$_emit_io_edge_handle")" \ + to "$(np__dataset_ref "$_emit_io_edge_dataset_id")" \ + facets "{$(np__json_str "$NP_FACET_BINDING"):$_emit_io_edge_binding}") + else + _emit_io_edge_edge_data=$(np__json_obj_raw \ + from "$(np__ref_of "$_emit_io_edge_handle")" \ + to "$(np__dataset_ref "$_emit_io_edge_dataset_id")") + fi + np__spool "$_emit_io_edge_edge_type" "$(np__node_get "$_emit_io_edge_handle" nrn)" "$_emit_io_edge_edge_data" >/dev/null + np__flush_foreign "$_emit_io_edge_handle" + return 0 +} + +# The shared argv handling of np_trace_produces / np_trace_consumes: +# resolve the optional leading handle, take the dataset id, parse the +# pointer flags, and hand off to np__emit_io_edge. +# $1 direction (out|in), $2 verb name for drop records, then the caller's argv. +np__declare_lineage() { + [ "${NP_TRACE_ENABLED:-1}" = '1' ] || return 0 + _declare_lineage_direction=$1 + _declare_lineage_verb=$2 + shift 2 + + _declare_lineage_handle=$(np__resolve_handle "${1:-}") + if np__is_handle "${1:-}"; then + shift + fi + np__is_handle "$_declare_lineage_handle" || { np__drop "$_declare_lineage_verb" 'no node in scope'; return 0; } + + _declare_lineage_dataset_id=${1:-} + if [ "$#" -gt 0 ]; then + shift + fi + if [ -z "$_declare_lineage_dataset_id" ]; then + np__drop "$_declare_lineage_verb" 'dataset id is required' + return 0 + fi + + _declare_lineage_name='' + _declare_lineage_inline='' + _declare_lineage_uri='' + _declare_lineage_ref_source='' + _declare_lineage_ref_id='' + _declare_lineage_ref_version='' + while [ "$#" -gt 0 ]; do + case "$1" in + --name) _declare_lineage_name=${2:-}; shift 2 ;; + --uri) _declare_lineage_uri=${2:-}; shift 2 ;; + --value) _declare_lineage_inline=${2:-}; shift 2 ;; + --source) _declare_lineage_ref_source=${2:-}; shift 2 ;; + --external-id) _declare_lineage_ref_id=${2:-}; shift 2 ;; + --version) _declare_lineage_ref_version=${2:-}; shift 2 ;; + *) shift ;; + esac + done + + _declare_lineage_binding='' + if [ -n "$_declare_lineage_name" ]; then + _declare_lineage_binding=$(np__build_io_descriptor "$_declare_lineage_verb" "$_declare_lineage_name" "$_declare_lineage_inline" \ + "$_declare_lineage_uri" "$_declare_lineage_ref_source" "$_declare_lineage_ref_id" "$_declare_lineage_ref_version") || return 0 + fi + + np__emit_io_edge "$_declare_lineage_handle" "$_declare_lineage_direction" "$_declare_lineage_dataset_id" \ + "$_declare_lineage_binding" "$_declare_lineage_name" + return 0 +} + +# np_trace_produces [handle] [--name (--uri U | --value JSON | --source S --external-id E [--version V])] +# +# Declare this node WROTE the dataset. With `--name` the io is declared once +# — a pointer (`--uri`, the artifact's address), an inline value (`--value`), +# or a catalog ref (`--source`/`--external-id`) — on both the node and the +# edge's binding. Bare form records lineage only. +np_trace_produces() { + np__declare_lineage out produces "$@" + return 0 +} + +# np_trace_consumes [handle] [--name (--uri U | --value JSON | --source S --external-id E [--version V])] +# +# Declare this node READ the dataset; see np_trace_produces. +np_trace_consumes() { + np__declare_lineage in consumes "$@" + return 0 +} + +# --------------------------------------------------------------------------- +# Run-to-run edges — how operations relate across the graph +# --------------------------------------------------------------------------- + +# Resolve an edge target: a handle from this process, or a PACKED CARRIER +# ("1||") — the natural address in shell, where the other +# end of an edge usually arrived via an env var. Prints the target's ref. +np__edge_target_ref() { + if np__is_handle "$1"; then + np__ref_of "$1" + return 0 + fi + _edge_target_ref_context=$(np_trace_extract "$1") || return 1 + _edge_target_ref_trace=${_edge_target_ref_context%% *} + _edge_target_ref_run=${_edge_target_ref_context#* } + np__json_obj type run trace_id "$_edge_target_ref_trace" run_id "$_edge_target_ref_run" + return 0 +} + +# Emit one relationship edge from a node this process holds. +# $1 handle, $2 edge type, $3 target ref JSON, $4 verb for drop records. +np__emit_ref_edge() { + _emit_ref_edge_from=$(np__ref_of "$1") + if [ "$_emit_ref_edge_from" = "$3" ]; then + np__drop "$4" 'self-edge forbidden' + return 0 + fi + # An edge must not point FROM a node the read model has never seen. + np_trace_start "$1" + _emit_ref_edge_data=$(np__json_obj_raw from "$_emit_ref_edge_from" to "$3") + np__spool "$2" "$(np__node_get "$1" nrn)" "$_emit_ref_edge_data" >/dev/null + np__flush_foreign "$1" + return 0 +} + +# The shared argv handling of the run-to-run edge verbs. +# $1 edge type, $2 verb, then the caller's argv: [handle] . +np__declare_relation() { + [ "${NP_TRACE_ENABLED:-1}" = '1' ] || return 0 + _declare_relation_type=$1 + _declare_relation_verb=$2 + shift 2 + _declare_relation_handle=$(np__resolve_handle "${1:-}") + if np__is_handle "${1:-}"; then + shift + fi + np__is_handle "$_declare_relation_handle" || { np__drop "$_declare_relation_verb" 'no node in scope'; return 0; } + if [ -z "${1:-}" ]; then + np__drop "$_declare_relation_verb" 'a target (handle or packed carrier) is required' + return 0 + fi + _declare_relation_target=$(np__edge_target_ref "$1") || { + np__drop "$_declare_relation_verb" 'target is not a handle or a valid carrier' + return 0 + } + np__emit_ref_edge "$_declare_relation_handle" "$_declare_relation_type" "$_declare_relation_target" "$_declare_relation_verb" + return 0 +} + +# np_trace_triggered_by [handle] +# +# The operation that CAUSED this one — a cross-trace fact (the target is +# usually another trace's run, addressed by its packed carrier). +np_trace_triggered_by() { + np__declare_relation "$NP_TYPE_EDGE_TRIGGERED_BY" triggered_by "$@" + return 0 +} + +# np_trace_retry_of [handle] — this run retries that one. +np_trace_retry_of() { + np__declare_relation "$NP_TYPE_EDGE_RETRY_OF" retry_of "$@" + return 0 +} + +# np_trace_continues [handle] — this run resumes that one's work. +np_trace_continues() { + np__declare_relation "$NP_TYPE_EDGE_CONTINUES" continues "$@" + return 0 +} + +# np_trace_correlates [handle] — related, with no causal claim. +np_trace_correlates() { + np__declare_relation "$NP_TYPE_EDGE_CORRELATES" correlates "$@" + return 0 +} + +# np_trace_compensates [handle] — this run undoes that one's effect. +np_trace_compensates() { + np__declare_relation "$NP_TYPE_EDGE_COMPENSATES" compensates "$@" + return 0 +} + +# np_trace_link [handle] +# +# Escape hatch over the named verbs — emit any known edge type. Prefer the +# named functions when one fits. +np_trace_link() { + [ "${NP_TRACE_ENABLED:-1}" = '1' ] || return 0 + _link_handle=$(np__resolve_handle "${1:-}") + if np__is_handle "${1:-}"; then + shift + fi + np__is_handle "$_link_handle" || { np__drop 'link' 'no node in scope'; return 0; } + _link_type=${1:-} + case "$_link_type" in + "$NP_TYPE_EDGE_TRIGGERED_BY" | "$NP_TYPE_EDGE_RETRY_OF" | "$NP_TYPE_EDGE_CONTINUES" \ + | "$NP_TYPE_EDGE_CORRELATES" | "$NP_TYPE_EDGE_COMPENSATES" | "$NP_TYPE_EDGE_PARENT") ;; + *) np__drop 'link' "unknown edge type '${_link_type}'"; return 0 ;; + esac + if [ -z "${2:-}" ]; then + np__drop 'link' 'a target (handle or packed carrier) is required' + return 0 + fi + _link_target=$(np__edge_target_ref "$2") || { + np__drop 'link' 'target is not a handle or a valid carrier' + return 0 + } + np__emit_ref_edge "$_link_handle" "$_link_type" "$_link_target" link + return 0 +} + +# np_trace_instance_of [handle] [--nrn N] +# +# This run instantiates a reusable JOB definition — the read model resolves +# the run's plan from the definition. Emit the definition itself with +# np_trace_job. +np_trace_instance_of() { + [ "${NP_TRACE_ENABLED:-1}" = '1' ] || return 0 + _instance_of_handle=$(np__resolve_handle "${1:-}") + if np__is_handle "${1:-}"; then + shift + fi + np__is_handle "$_instance_of_handle" || { np__drop 'instance_of' 'no node in scope'; return 0; } + _instance_of_namespace=${1:-} + _instance_of_name=${2:-} + _instance_of_version=${3:-} + if [ "$#" -ge 3 ]; then + shift 3 + fi + _instance_of_nrn='' + while [ "$#" -gt 0 ]; do + case "$1" in + --nrn) _instance_of_nrn=${2:-}; shift 2 ;; + *) shift ;; + esac + done + if [ -z "$_instance_of_namespace" ] || [ -z "$_instance_of_name" ] || [ -z "$_instance_of_version" ]; then + np__drop 'instance_of' 'namespace, name and version are required' + return 0 + fi + _instance_of_target=$(np__json_obj type job namespace "$_instance_of_namespace" \ + name "$_instance_of_name" version "$_instance_of_version" nrn "$_instance_of_nrn") + np__emit_ref_edge "$_instance_of_handle" "$NP_TYPE_EDGE_INSTANCE_OF" "$_instance_of_target" instance_of + return 0 +} + +# --------------------------------------------------------------------------- +# Definition nodes — identities, not executions +# --------------------------------------------------------------------------- + +# np_trace_dataset [--nrn N] +# +# Emit a dataset node — an identity a lineage edge can point at. The id is +# the CANONICAL address (see np_trace_produces); edges to an unemitted +# dataset still resolve, so this is only needed to carry the node itself. +np_trace_dataset() { + [ "${NP_TRACE_ENABLED:-1}" = '1' ] || return 0 + _dataset_id=${1:-} + if [ "$#" -gt 0 ]; then + shift + fi + _dataset_nrn='' + while [ "$#" -gt 0 ]; do + case "$1" in + --nrn) _dataset_nrn=${2:-}; shift 2 ;; + *) shift ;; + esac + done + if [ -z "$_dataset_id" ]; then + np__drop 'dataset' 'an id is required' + return 0 + fi + np__spool "$NP_TYPE_NODE_DATASET" "$_dataset_nrn" "$(np__json_obj id "$_dataset_id")" >/dev/null + return 0 +} + +# np_trace_job [--nrn N] [--plan JSON] +# +# Emit a job definition node — the reusable spec runs link instance_of, with +# its expected step plan (previewable before any run exists). +np_trace_job() { + [ "${NP_TRACE_ENABLED:-1}" = '1' ] || return 0 + _job_namespace=${1:-} + _job_name=${2:-} + _job_version=${3:-} + if [ "$#" -ge 3 ]; then + shift 3 + fi + _job_nrn='' + _job_plan='' + while [ "$#" -gt 0 ]; do + case "$1" in + --nrn) _job_nrn=${2:-}; shift 2 ;; + --plan) _job_plan=${2:-}; shift 2 ;; + *) shift ;; + esac + done + if [ -z "$_job_namespace" ] || [ -z "$_job_name" ] || [ -z "$_job_version" ]; then + np__drop 'job' 'namespace, name and version are required' + return 0 + fi + case "$_job_plan" in + '' | \[*) ;; + *) np__drop 'job' 'the plan must be a JSON array of steps'; return 0 ;; + esac + if [ -n "$_job_plan" ]; then + _job_data=$(np__json_obj_raw \ + namespace "$(np__json_str "$_job_namespace")" \ + name "$(np__json_str "$_job_name")" \ + version "$(np__json_str "$_job_version")" \ + facets "{$(np__json_str "$NP_FACET_PLAN"):$_job_plan}") + else + _job_data=$(np__json_obj namespace "$_job_namespace" name "$_job_name" version "$_job_version") + fi + np__spool "$NP_TYPE_NODE_JOB" "$_job_nrn" "$_job_data" >/dev/null + return 0 +} + +# --------------------------------------------------------------------------- +# The remaining core-facet setters +# --------------------------------------------------------------------------- + +# np_trace_actor [handle] [--source S] +# +# WHO acted. The sibling SDKs also accept a bearer JWT and decode it; that +# sugar needs base64, which this SDK's runtime toolset excludes — pass the +# identity explicitly (the np CLI stamps the actor on workflow runs already). +np_trace_actor() { + _actor_handle=$(np__resolve_handle "${1:-}") + if np__is_handle "${1:-}"; then + shift + fi + np__is_handle "$_actor_handle" || return 0 + _actor_kind=${1:-} + _actor_id=${2:-} + if [ "$#" -ge 2 ]; then + shift 2 + fi + _actor_source='' + while [ "$#" -gt 0 ]; do + case "$1" in + --source) _actor_source=${2:-}; shift 2 ;; + *) shift ;; + esac + done + case "$_actor_kind" in + user | service) ;; + *) np__drop 'actor' "kind must be user or service, got '${_actor_kind}'"; return 0 ;; + esac + if [ -z "$_actor_id" ]; then + np__drop 'actor' 'an id is required' + return 0 + fi + np__stage_facet "$_actor_handle" "$NP_FACET_ACTOR" \ + "$(np__json_obj kind "$_actor_kind" id "$_actor_id" source "$_actor_source")" + np__flush_foreign "$_actor_handle" + return 0 +} + +# np_trace_decision [handle] [--available a,b,c] [--expression E] +# +# The branch(es) this node chose, with the option set and the human-readable +# expression when known. +np_trace_decision() { + _decision_handle=$(np__resolve_handle "${1:-}") + if np__is_handle "${1:-}"; then + shift + fi + np__is_handle "$_decision_handle" || return 0 + _decision_chosen=${1:-} + if [ "$#" -gt 0 ]; then + shift + fi + _decision_available='' + _decision_expression='' + while [ "$#" -gt 0 ]; do + case "$1" in + --available) _decision_available=${2:-}; shift 2 ;; + --expression) _decision_expression=${2:-}; shift 2 ;; + *) shift ;; + esac + done + if [ -z "$_decision_chosen" ]; then + np__drop 'decision' 'at least one chosen branch is required' + return 0 + fi + np__stage_facet "$_decision_handle" "$NP_FACET_DECISION" \ + "$(np__json_obj_raw \ + chosen "$(np__json_str_array_csv "$_decision_chosen")" \ + available "$(if [ -n "$_decision_available" ]; then np__json_str_array_csv "$_decision_available"; fi)" \ + expression "$(if [ -n "$_decision_expression" ]; then np__json_str "$_decision_expression"; fi)")" + np__flush_foreign "$_decision_handle" + return 0 +} + +# np_trace_retry [handle] [--next-attempt N] [--delay-ms MS] +np_trace_retry() { + _retry_handle=$(np__resolve_handle "${1:-}") + if np__is_handle "${1:-}"; then + shift + fi + np__is_handle "$_retry_handle" || return 0 + _retry_attempt=${1:-} + if [ "$#" -gt 0 ]; then + shift + fi + _retry_next='' + _retry_delay='' + while [ "$#" -gt 0 ]; do + case "$1" in + --next-attempt) _retry_next=${2:-}; shift 2 ;; + --delay-ms) _retry_delay=${2:-}; shift 2 ;; + *) shift ;; + esac + done + case "$_retry_attempt$_retry_next$_retry_delay" in + '' | *[!0-9]*) np__drop 'retry' 'attempt, next-attempt and delay-ms must be non-negative integers'; return 0 ;; + esac + np__stage_facet "$_retry_handle" "$NP_FACET_RETRY" \ + "$(np__json_obj_raw attempt "$_retry_attempt" next_attempt "$_retry_next" delay_ms "$_retry_delay")" + np__flush_foreign "$_retry_handle" + return 0 +} + +# np_trace_signal [handle] [--timeout-ms MS] +np_trace_signal() { + _signal_handle=$(np__resolve_handle "${1:-}") + if np__is_handle "${1:-}"; then + shift + fi + np__is_handle "$_signal_handle" || return 0 + _signal_name=${1:-} + _signal_direction=${2:-} + if [ "$#" -ge 2 ]; then + shift 2 + fi + _signal_timeout='' + while [ "$#" -gt 0 ]; do + case "$1" in + --timeout-ms) _signal_timeout=${2:-}; shift 2 ;; + *) shift ;; + esac + done + if [ -z "$_signal_name" ]; then + np__drop 'signal' 'a name is required' + return 0 + fi + case "$_signal_direction" in + wait | received) ;; + *) np__drop 'signal' "direction must be wait or received, got '${_signal_direction}'"; return 0 ;; + esac + case "$_signal_timeout" in + '' | *[!0-9]*) + if [ -n "$_signal_timeout" ]; then + np__drop 'signal' 'timeout-ms must be a non-negative integer' + return 0 + fi + ;; + esac + np__stage_facet "$_signal_handle" "$NP_FACET_SIGNAL" \ + "$(np__json_obj_raw \ + name "$(np__json_str "$_signal_name")" \ + direction "$(np__json_str "$_signal_direction")" \ + timeout_ms "$_signal_timeout")" + np__flush_foreign "$_signal_handle" + return 0 +} + +# np_trace_external_links [handle] [--label L] +# +# One off-platform link (a CI run, a dashboard). Accumulates: call once per +# link, the facet is the array of everything declared so far. +np_trace_external_links() { + _external_links_handle=$(np__resolve_handle "${1:-}") + if np__is_handle "${1:-}"; then + shift + fi + np__is_handle "$_external_links_handle" || return 0 + _external_links_rel=${1:-} + _external_links_uri=${2:-} + if [ "$#" -ge 2 ]; then + shift 2 + fi + _external_links_label='' + while [ "$#" -gt 0 ]; do + case "$1" in + --label) _external_links_label=${2:-}; shift 2 ;; + *) shift ;; + esac + done + if [ -z "$_external_links_rel" ] || [ -z "$_external_links_uri" ]; then + np__drop 'external_links' 'rel and uri are required' + return 0 + fi + _external_links_link=$(np__json_obj rel "$_external_links_rel" uri "$_external_links_uri" label "$_external_links_label") + _external_links_links=$(np__node_get "$_external_links_handle" external_links) + if [ -n "$_external_links_links" ]; then + _external_links_links="$_external_links_links,$_external_links_link" + else + _external_links_links=$_external_links_link + fi + np__node_set "$_external_links_handle" external_links "$_external_links_links" + np__stage_facet "$_external_links_handle" "$NP_FACET_EXTERNAL_LINKS" "[$_external_links_links]" + np__flush_foreign "$_external_links_handle" + return 0 +} + +# np_trace_engine_status [handle] [--raw JSON] +# +# The underlying engine's own view of this node (a k8s rollout's status, a +# queue's verdict), verbatim. +np_trace_engine_status() { + _engine_status_handle=$(np__resolve_handle "${1:-}") + if np__is_handle "${1:-}"; then + shift + fi + np__is_handle "$_engine_status_handle" || return 0 + _engine_status_engine=${1:-} + _engine_status_state=${2:-} + if [ "$#" -ge 2 ]; then + shift 2 + fi + _engine_status_raw='' + while [ "$#" -gt 0 ]; do + case "$1" in + --raw) _engine_status_raw=${2:-}; shift 2 ;; + *) shift ;; + esac + done + if [ -z "$_engine_status_engine" ] || [ -z "$_engine_status_state" ]; then + np__drop 'engine_status' 'engine and state are required' + return 0 + fi + case "$_engine_status_raw" in + '' | \{*) ;; + *) np__drop 'engine_status' 'raw must be a JSON object'; return 0 ;; + esac + np__stage_facet "$_engine_status_handle" "$NP_FACET_ENGINE_STATUS" \ + "$(np__json_obj_raw \ + engine "$(np__json_str "$_engine_status_engine")" \ + state "$(np__json_str "$_engine_status_state")" \ + raw "$_engine_status_raw")" + np__flush_foreign "$_engine_status_handle" + return 0 +} + +# np_trace_dropped [handle] +# +# A record of data intentionally dropped — pair with np_trace_skip. +np_trace_dropped() { + _dropped_handle=$(np__resolve_handle "${1:-}") + if np__is_handle "${1:-}"; then + shift + fi + np__is_handle "$_dropped_handle" || return 0 + if [ -z "${1:-}" ]; then + np__drop 'dropped' 'a reason is required' + return 0 + fi + np__stage_facet "$_dropped_handle" "$NP_FACET_DROPPED" "$(np__json_obj reason "$1")" + np__flush_foreign "$_dropped_handle" + return 0 +} + +# np_trace_plan [handle] +# +# Declare the node's EXPECTED step plan ([{"key":...,"title":...}, ...]) so +# the read model reports expected-vs-observed progress. On a reusable +# definition, prefer np_trace_job --plan. +np_trace_plan() { + _plan_handle=$(np__resolve_handle "${1:-}") + if np__is_handle "${1:-}"; then + shift + fi + np__is_handle "$_plan_handle" || return 0 + case "${1:-}" in + \[*) ;; + *) np__drop 'plan' 'the plan must be a JSON array of steps'; return 0 ;; + esac + np__stage_facet "$_plan_handle" "$NP_FACET_PLAN" "$1" + np__flush_foreign "$_plan_handle" + return 0 +} + +# np_trace_affordances [handle] +# +# What this node OFFERS a human to do — a declared fact the UI renders as a +# control (view live logs, switch traffic). One affordance object +# ('{"kind":"deploy-log",...}') or a bare array of them; the wire form is +# always the array. +# +# A single object UPSERTS by its `kind`: re-declaring a kind replaces that +# entry (a live meter re-emitted per heartbeat), while a NEW kind joins the +# list — a later "deploy-log" never erases the "instances-health" meter. +# An array is a FULL declaration and replaces the whole list. +np_trace_affordances() { + _affordances_handle=$(np__resolve_handle "${1:-}") + if np__is_handle "${1:-}"; then + shift + fi + np__is_handle "$_affordances_handle" || return 0 + _affordances_body=${1:-} + case "$_affordances_body" in + \[*) + np__node_set "$_affordances_handle" affordances_slots '' + np__node_set "$_affordances_handle" affordances '' + np__stage_facet "$_affordances_handle" "$NP_FACET_AFFORDANCES" "$_affordances_body" + ;; + \{*) + _affordances_kind=$(printf '%s' "$_affordances_body" \ + | sed -n 's/.*"kind"[[:space:]]*:[[:space:]]*"\([^"]*\)".*/\1/p') + # No kind: the object itself is its identity (append-once semantics). + [ -n "$_affordances_kind" ] || _affordances_kind=$_affordances_body + np__upsert_descriptor "$_affordances_handle" "$NP_FACET_AFFORDANCES" affordances \ + "$_affordances_body" "$_affordances_kind" + ;; + *) np__drop 'affordances' 'body must be a JSON object or array'; return 0 ;; + esac + np__flush_foreign "$_affordances_handle" + return 0 +} + +# np_trace_progress [handle] [unit] +# +# How far a CONVERGING phase has advanced toward its declared target — +# instances 3 of 10, traffic 40 of 100. Non-negative integers. The unit is a +# number-FORMAT hint from the wire's CLOSED vocabulary (percent, count, bytes, +# milliseconds) — the API rejects the whole EVENT over an unknown unit, and an +# enriched node re-emits its full facet bag, so one bad unit would poison every +# later emission. A word outside the vocabulary is therefore dropped here (the +# noun belongs in the step's title, not the unit). +np_trace_progress() { + _progress_handle=$(np__resolve_handle "${1:-}") + if np__is_handle "${1:-}"; then + shift + fi + np__is_handle "$_progress_handle" || return 0 + _progress_current=${1:-} + _progress_target=${2:-} + _progress_unit=${3:-} + if [ -z "$_progress_current" ] || [ -z "$_progress_target" ]; then + np__drop 'progress' 'current and target must be non-negative integers' + return 0 + fi + case "$_progress_current$_progress_target" in + *[!0-9]*) np__drop 'progress' 'current and target must be non-negative integers'; return 0 ;; + esac + case "$_progress_unit" in + '' | percent | count | bytes | milliseconds) ;; + *) + np__drop 'progress' "unit '$_progress_unit' is not in the wire vocabulary (percent, count, bytes, milliseconds); omitted" + _progress_unit='' + ;; + esac + np__stage_facet "$_progress_handle" "$NP_FACET_PROGRESS" \ + "$(np__json_obj_raw current "$_progress_current" target "$_progress_target" \ + unit "$(if [ -n "$_progress_unit" ]; then np__json_str "$_progress_unit"; fi)")" + np__flush_foreign "$_progress_handle" + return 0 +} + +# --------------------------------------------------------------------------- +# Lifecycle terminals +# --------------------------------------------------------------------------- + +# The shared terminal path. $1 = handle, $2 = status. +np__terminalize() { + np__is_handle "$1" || return 0 + if [ "$(np__node_get "$1" closed)" = '1' ]; then + return 0 + fi + # An adopted node belongs to the process that created it. Its owner decides + # its outcome; emitting a terminal here would assert a state we did not + # observe, and would race the owner's own terminal event. + if np__is_foreign "$1"; then + np__drop 'terminal' 'refusing to close an adopted node' + return 0 + fi + np_trace_start "$1" + np__stage_timing "$1" "$(np__iso8601)" + np__node_set "$1" closed 1 + np__emit_node "$1" "$2" + np__ambient_clear "$1" + # Restore the parent as ambient so a sibling opened next lands correctly. + _terminalize_parent=$(np__node_get "$1" parent) + if [ -n "$_terminalize_parent" ] && np__is_handle "$_terminalize_parent"; then + if [ "$(np__node_get "$_terminalize_parent" closed)" != '1' ]; then + np__ambient_set "$_terminalize_parent" + fi + fi + return 0 +} + +np_trace_complete() { + np__terminalize "$(np__resolve_handle "${1:-}")" "$NP_STATUS_COMPLETED" + return 0 +} + +# An idempotent completing close. +np_trace_end() { + np_trace_complete "$@" + return 0 +} + +np_trace_fail() { + _fail_h=$(np__resolve_handle "${1:-}") + if np__is_handle "${1:-}"; then + shift + fi + # Refuse a foreign fail WHOLE, before the message stages: half-applying it + # (error facet emitted via the foreign flush, close refused) would smear an + # unowned outcome onto the node. Recording an observed fact on a foreign + # node is np_trace_error, deliberately. + if np__is_foreign "$_fail_h"; then + np__drop 'terminal' 'refusing to close an adopted node' + return 0 + fi + if [ -n "${1:-}" ]; then + np_trace_error "$_fail_h" --message "$1" + fi + # fail cascades to still-open child steps; complete deliberately does not — + # auto-completing an open child would assert a success the SDK cannot vouch + # for, and back-date its duration. + np__cascade_fail "$_fail_h" "${1:-}" + np__terminalize "$_fail_h" "$NP_STATUS_FAILED" + return 0 +} + +# True when $1 is a descendant of $2, by walking the parent chain upward. +# Deliberately NOT recursive: POSIX sh has no `local`, so a recursive walk +# clobbers its caller's loop variables — which silently skipped intermediate +# nodes in the cascade. +np__is_descendant_of() { + _is_descendant_of_cur=$(np__node_get "$1" parent) + _is_descendant_of_guard=0 + while [ -n "$_is_descendant_of_cur" ] && [ "$_is_descendant_of_guard" -lt 64 ]; do + if [ "$_is_descendant_of_cur" = "$2" ]; then + return 0 + fi + _is_descendant_of_cur=$(np__node_get "$_is_descendant_of_cur" parent) + _is_descendant_of_guard=$((_is_descendant_of_guard + 1)) + done + return 1 +} + +# Fail every still-open descendant. One flat pass over the registry, deepest +# first, so a node is closed before anything reads it as a parent. +np__cascade_fail() { + _cascade_fail_depth=64 + while [ "$_cascade_fail_depth" -ge 0 ]; do + for _cascade_fail_file in "$NP_TRACE_DIR/nodes"/*; do + [ -f "$_cascade_fail_file" ] || continue + _cascade_fail_h=${_cascade_fail_file##*/} + [ "$_cascade_fail_h" = "$1" ] && continue + [ "$(np__node_get "$_cascade_fail_h" closed)" = '1' ] && continue + np__is_descendant_of "$_cascade_fail_h" "$1" || continue + [ "$(np__depth_of "$_cascade_fail_h")" -eq "$_cascade_fail_depth" ] || continue + if [ -n "$2" ]; then + np_trace_error "$_cascade_fail_h" --message "$2" + fi + np__terminalize "$_cascade_fail_h" "$NP_STATUS_FAILED" + done + _cascade_fail_depth=$((_cascade_fail_depth - 1)) + done + return 0 +} + +# How many parent links sit above this node. +np__depth_of() { + _depth_of_cur=$(np__node_get "$1" parent) + _depth_of_n=0 + while [ -n "$_depth_of_cur" ] && [ "$_depth_of_n" -lt 64 ]; do + _depth_of_n=$((_depth_of_n + 1)) + _depth_of_cur=$(np__node_get "$_depth_of_cur" parent) + done + printf '%s' "$_depth_of_n" +} + +np_trace_skip() { + _skip_h=$(np__resolve_handle "${1:-}") + if np__is_handle "${1:-}"; then + shift + fi + np__is_handle "$_skip_h" || return 0 + if [ -n "${1:-}" ]; then + np__stage_facet "$_skip_h" "$NP_FACET_DROPPED" "$(np__json_obj reason "$1")" + fi + np__terminalize "$_skip_h" "$NP_STATUS_SKIPPED" + return 0 +} + +np_trace_cancel() { + _cancel_h=$(np__resolve_handle "${1:-}") + if np__is_handle "${1:-}"; then + shift + fi + np__terminalize "$_cancel_h" "$NP_STATUS_CANCELLED" + return 0 +} + +np_trace_timeout() { + np__terminalize "$(np__resolve_handle "${1:-}")" "$NP_STATUS_TIMED_OUT" + return 0 +} + +# Non-terminal: the node stays open. +np_trace_waiting() { + _waiting_h=$(np__resolve_handle "${1:-}") + np__is_handle "$_waiting_h" || return 0 + np_trace_start "$_waiting_h" + np__emit_node "$_waiting_h" "$NP_STATUS_WAITING" + return 0 +} + +# ---- src/cli.sh ---- +# cli.sh — argv to function shim (Phase 2). diff --git a/scheduled_task/logging b/scheduled_task/logging index d0df55d7..2d1c62cf 100644 --- a/scheduled_task/logging +++ b/scheduled_task/logging @@ -38,4 +38,318 @@ log() { echo "$message" fi fi + + if [ "$msg_num" -ge 3 ]; then + _np_scopes_trace_error "$message" || true + fi +} + +_np_scopes_node() { + command -v np_trace_adopt >/dev/null 2>&1 || return 1 + [ -n "${NP_TRACE:-}" ] || return 1 + if [ -n "${_NP_SCOPES_SUBSTEP:-}" ]; then + if [ "${_NP_SCOPES_SUBSTEP_UNDER:-}" = "$NP_TRACE" ]; then + printf '%s' "$_NP_SCOPES_SUBSTEP" + return 0 + fi + _NP_SCOPES_SUBSTEP="" _NP_SCOPES_SUBSTEP_UNDER="" + fi + local _nd_node _nd_under _nd_cached + if [ -n "${NP_TRACE_DIR:-}" ] && [ -f "$NP_TRACE_DIR/scopes_adopted" ]; then + IFS=' ' read -r _nd_under _nd_cached < "$NP_TRACE_DIR/scopes_adopted" 2>/dev/null || true + if [ "$_nd_under" = "$NP_TRACE" ] && [ -n "$_nd_cached" ]; then + printf '%s' "$_nd_cached" + return 0 + fi + fi + _nd_node=$(np_trace_adopt 2>/dev/null) || return 1 + [ -n "$_nd_node" ] || return 1 + if [ -n "${NP_TRACE_DIR:-}" ]; then + printf '%s %s' "$NP_TRACE" "$_nd_node" > "$NP_TRACE_DIR/scopes_adopted" 2>/dev/null || true + fi + printf '%s' "$_nd_node" + return 0 +} + +_np_scopes_trace_error() { + local _lt_node _lt_message + _lt_node=$(_np_scopes_node) || return 0 + _lt_message="$1" + _lt_message="${_lt_message#"${_lt_message%%[![:space:]]*}"}" + case "$_lt_message" in "❌ "*) _lt_message="${_lt_message#❌ }" ;; esac + if [ "${_NP_SCOPES_ERRED_ON:-}" = "${NP_TRACE:-}" ] && [ -n "${_NP_SCOPES_ERR_MESSAGE:-}" ]; then + if [ -n "${_NP_SCOPES_ERR_HINTS:-}" ]; then + _NP_SCOPES_ERR_HINTS="$_NP_SCOPES_ERR_HINTS,$(np__json_str "$_lt_message")" + else + _NP_SCOPES_ERR_HINTS="$(np__json_str "$_lt_message")" + fi + np_trace_error "$_lt_node" --message "$_NP_SCOPES_ERR_MESSAGE" \ + --details "{\"hints\":[$_NP_SCOPES_ERR_HINTS]}" + return 0 + fi + np_trace_error "$_lt_node" --message "$_lt_message" ${2:+--code "$2"} + if [ -z "${_NP_SCOPES_TRAP_REPORT:-}" ] && command -v np_step_error >/dev/null 2>&1; then + np_step_error "$_lt_message" + fi + _NP_SCOPES_ERRED_ON="${NP_TRACE:-}" + _NP_SCOPES_LAST_REASON="$_lt_message" + _NP_SCOPES_ERR_MESSAGE="$_lt_message" + _NP_SCOPES_ERR_HINTS="" + return 0 +} + +# np_scope_step_begin [--iteration N] [--attempt N] [--title ] +np_scope_step_begin() { + command -v np_trace_adopt >/dev/null 2>&1 || return 0 + [ -n "${NP_TRACE:-}" ] || return 0 + local _sb_key="${1:-}" _sb_title="" _sb_parent _sb_h + shift || true + local _sb_args=() + while [ "$#" -gt 0 ]; do + case "$1" in + --title) _sb_title="${2:-}"; shift 2 ;; + *) _sb_args+=("$1"); shift ;; + esac + done + [ -n "${_NP_SCOPES_SUBSTEP:-}" ] && np_scope_step_end 0 + _sb_parent=$(np_trace_adopt 2>/dev/null) || return 0 + [ -n "$_sb_parent" ] || return 0 + _sb_h=$(np_trace_step "$_sb_parent" "$_sb_key" ${_sb_args[@]+"${_sb_args[@]}"}) + [ -n "$_sb_h" ] || return 0 + [ -n "$_sb_title" ] && np_trace_explain "$_sb_h" --title "$_sb_title" + _NP_SCOPES_SUBSTEP="$_sb_h" + _NP_SCOPES_SUBSTEP_UNDER="$NP_TRACE" + return 0 +} + +# np_scope_step_end [rc] [message] +np_scope_step_end() { + [ -n "${_NP_SCOPES_SUBSTEP:-}" ] || return 0 + local _se_h="$_NP_SCOPES_SUBSTEP" _se_rc="${1:-0}" + _NP_SCOPES_SUBSTEP="" _NP_SCOPES_SUBSTEP_UNDER="" + if [ "$_se_rc" -eq 0 ] 2>/dev/null; then + np_trace_complete "$_se_h" + else + if [ -n "${2:-}" ]; then + np_trace_fail "$_se_h" "$2" + elif [ "${_NP_SCOPES_ERRED_ON:-}" != "${NP_TRACE:-}" ]; then + np_trace_fail "$_se_h" "phase exited with status $_se_rc" + else + np_trace_fail "$_se_h" + fi + _NP_SCOPES_ERRED_ON="${NP_TRACE:-}" + fi + NP_TRACE_FLUSH_TIMEOUT=2 np_trace_flush + return 0 +} + +# np_scope_step_timeout [message] +np_scope_step_timeout() { + [ -n "${_NP_SCOPES_SUBSTEP:-}" ] || return 0 + local _st_h="$_NP_SCOPES_SUBSTEP" + _NP_SCOPES_SUBSTEP="" _NP_SCOPES_SUBSTEP_UNDER="" + [ -n "${1:-}" ] && np_trace_error "$_st_h" --message "$1" + np_trace_timeout "$_st_h" + NP_TRACE_FLUSH_TIMEOUT=2 np_trace_flush + return 0 +} + +# np_scope_wait_heartbeat [state] [k=v ...] +np_scope_wait_heartbeat() { + local _hb_node + _hb_node=$(_np_scopes_node) || return 0 + local _hb_what="${1:-}" _hb_timeout="${3:-0}" + case "$_hb_timeout" in + '' | *[!0-9]*) np_trace_signal "$_hb_node" "$_hb_what" wait ;; + *) np_trace_signal "$_hb_node" "$_hb_what" wait --timeout-ms $(( _hb_timeout * 1000 )) ;; + esac + np_trace_waiting "$_hb_node" + NP_TRACE_FLUSH_TIMEOUT=2 np_trace_flush + return 0 +} + +# np_scope_produces [ ] +# np_scope_consumes [ ] +np_scope_produces() { + command -v np_trace_produces >/dev/null 2>&1 || return 0 + local _pd_node + _pd_node=$(_np_scopes_node) || return 0 + np_trace_produces "$_pd_node" "$1" ${2:+--name "$2"} ${3:+--uri "$3"} + return 0 +} + +np_scope_consumes() { + command -v np_trace_consumes >/dev/null 2>&1 || return 0 + local _cd_node + _cd_node=$(_np_scopes_node) || return 0 + np_trace_consumes "$_cd_node" "$1" ${2:+--name "$2"} ${3:+--uri "$3"} + return 0 +} + +# np_scope_affordance +np_scope_affordance() { + command -v np_trace_affordances >/dev/null 2>&1 || return 0 + local _ad_node + _ad_node=$(_np_scopes_node) || return 0 + np_trace_affordances "$_ad_node" "$1" + return 0 +} + +# np_scope_progress [unit] +np_scope_progress() { + command -v np_trace_progress >/dev/null 2>&1 || return 0 + local _pg_node + _pg_node=$(_np_scopes_node) || return 0 + np_trace_progress "$_pg_node" "$1" "$2" "${3:-}" + return 0 +} + +# np_scope_output / np_scope_input +np_scope_output() { + command -v np_trace_output >/dev/null 2>&1 || return 0 + local _ot_node + _ot_node=$(_np_scopes_node) || return 0 + np_trace_output "$_ot_node" "$1" "$2" + return 0 +} + +np_scope_input() { + command -v np_trace_input >/dev/null 2>&1 || return 0 + local _in_node + _in_node=$(_np_scopes_node) || return 0 + np_trace_input "$_in_node" "$1" "$2" + return 0 +} + +# np_scope_explain --title T [--what W] [--severity ok|warn|error] ... +np_scope_explain() { + command -v np_trace_explain >/dev/null 2>&1 || return 0 + local _ex_node + _ex_node=$(_np_scopes_node) || return 0 + np_trace_explain "$_ex_node" "$@" + return 0 +} + +# np_scope_error [] +np_scope_error() { + command -v np_trace_error >/dev/null 2>&1 || return 0 + local _sr_node + _sr_node=$(_np_scopes_node) || return 0 + np_trace_error "$_sr_node" --message "$1" ${2:+--details "$2"} + _NP_SCOPES_ERRED_ON="${NP_TRACE:-}" + return 0 +} + +# np_scope_labels +np_scope_labels() { + command -v np_trace_labels >/dev/null 2>&1 || return 0 + local _lb_node + _lb_node=$(_np_scopes_node) || return 0 + np_trace_labels "$_lb_node" "$@" + return 0 } + +# np_scope_k8s_applied +np_scope_k8s_applied() { + command -v np_trace_produces >/dev/null 2>&1 || return 0 + local _ka_ns="$1" _ka_line _ka_kind _ka_name + [ -n "$_ka_ns" ] || return 0 + while IFS= read -r _ka_line; do + [ -n "$_ka_line" ] || continue + _ka_kind="${_ka_line%%/*}" + _ka_name="${_ka_line#*/}" + _ka_name="${_ka_name%% *}" + case "$_ka_kind" in + deployment.apps|deployment) + np_scope_produces "k8s-deployment:$_ka_ns/$_ka_name" deployment "$_ka_name" ;; + service) + np_scope_produces "k8s-service:$_ka_ns/$_ka_name" service "$_ka_name" ;; + ingress.networking.k8s.io|ingress) + np_scope_produces "k8s-ingress:$_ka_ns/$_ka_name" ingress "$_ka_name" ;; + esac + done <<< "$2" + return 0 +} + + +# np_scope_k8s_deleted +np_scope_k8s_deleted() { + command -v np_trace_output >/dev/null 2>&1 || return 0 + local _kd_ns="$1" _kd_node _kd_line _kd_kind _kd_name + [ -n "$_kd_ns" ] || return 0 + _kd_node=$(_np_scopes_node) || return 0 + while IFS= read -r _kd_line; do + [ -n "$_kd_line" ] || continue + case "$_kd_line" in + *" deleted") ;; + *) continue ;; + esac + _kd_kind="${_kd_line%%[ /]*}" + _kd_name="${_kd_line#*\"}" + _kd_name="${_kd_name%%\"*}" + [ -n "$_kd_name" ] || continue + case "$_kd_kind" in + deployment.apps|deployment) + np_trace_output "$_kd_node" removed-deployment --uri "$_kd_name" ;; + service) + np_trace_output "$_kd_node" removed-service --uri "$_kd_name" ;; + ingress.networking.k8s.io|ingress) + np_trace_output "$_kd_node" removed-ingress --uri "$_kd_name" ;; + esac + done <<< "$2" + return 0 +} + +_np_scopes_on_err() { + _NP_SCOPES_LAST_ERR="$BASH_COMMAND (exit ${1:-1})" +} + +_np_scopes_error_on_run() { + command -v np_trace_adopt >/dev/null 2>&1 || return 0 + [ -n "${NP_TRACE:-}" ] || return 0 + local _ru_rest="${NP_TRACE#*|}" + local _ru_version="${NP_TRACE%%|*}" _ru_trace="${_ru_rest%%|*}" _ru_run="${_ru_rest#*|}" + case "$_ru_run" in + *~*) _ru_run="${_ru_run%~*}" ;; + *) return 0 ;; + esac + local _ru_node + _ru_node=$(np_trace_adopt "${_ru_version}|${_ru_trace}|${_ru_run}" 2>/dev/null) || return 0 + [ -n "$_ru_node" ] || return 0 + np_trace_error "$_ru_node" --message "$1" + return 0 +} + +_np_scopes_on_exit() { + local _ex_rc="${1:-0}" + local _ex_reason="${_NP_SCOPES_LAST_REASON:-${_NP_SCOPES_LAST_ERR:-workflow shell exited with status $_ex_rc}}" + if [ "$_ex_rc" -ne 0 ] && [ "${_NP_SCOPES_ERRED_ON:-}" != "${NP_TRACE:-}" ]; then + _NP_SCOPES_TRAP_REPORT=1 + _np_scopes_trace_error "$_ex_reason" || true + _NP_SCOPES_TRAP_REPORT="" + fi + if [ "$_ex_rc" -ne 0 ]; then + _np_scopes_error_on_run "$_ex_reason" || true + fi + [ -n "${_NP_SCOPES_SUBSTEP:-}" ] && np_scope_step_end "$_ex_rc" || true + np_trace_flush +} + +_NP_SCOPES_ROOT="$(cd "$(dirname "${BASH_SOURCE[0]}")/.." && pwd)" +_NP_SCOPES_SDK="$_NP_SCOPES_ROOT/vendor/catalog-tracing-sh/nptrace.sh" +[ -f "$_NP_SCOPES_SDK" ] || _NP_SCOPES_SDK="$_NP_SCOPES_ROOT/nptrace.sh" +if [ -z "${NP_TRACE_LOADED:-}" ] \ + && [ -f "$_NP_SCOPES_SDK" ] \ + && [ -n "${NP_API_KEY:-}" ] \ + && [ -n "${NP_TRACE:-}" ]; then + # shellcheck source=/dev/null + . "$_NP_SCOPES_SDK" + np_trace_init --producer "nullplatform-scopes@1" --api-key "$NP_API_KEY" --no-trap + trap '_np_scopes_on_err $?' ERR + trap '_np_scopes_on_exit $?' EXIT +elif [ -z "${NP_TRACE_LOADED:-}" ] \ + && [ -n "${NP_TRACE:-}" ] \ + && [ -n "${NP_API_KEY:-}" ] \ + && [ ! -f "$_NP_SCOPES_SDK" ]; then + log warn "⚠️ tracing SDK not bundled (vendor/catalog-tracing-sh/nptrace.sh missing) — scope-side tracing disabled for this run" +fi diff --git a/scheduled_task/scope/workflows/trigger-job.yaml b/scheduled_task/scope/workflows/trigger-job.yaml index 02df28f0..5b05a728 100644 --- a/scheduled_task/scope/workflows/trigger-job.yaml +++ b/scheduled_task/scope/workflows/trigger-job.yaml @@ -3,10 +3,14 @@ include: provider_categories: - container-orchestration - cloud-providers +trace: + title: Run scheduled task + job: scheduled-task-trigger steps: - name: load logging type: script file: "$OVERRIDES_PATH/logging" + trace: false output: - name: log type: function diff --git a/vendor/catalog-tracing-sh b/vendor/catalog-tracing-sh new file mode 160000 index 00000000..31bb0721 --- /dev/null +++ b/vendor/catalog-tracing-sh @@ -0,0 +1 @@ +Subproject commit 31bb0721c8d9fa102084470cebff56ca60ccf93f