diff --git a/.github/workflows/pr-checks.yml b/.github/workflows/pr-checks.yml index 4fad504a..6a13381f 100644 --- a/.github/workflows/pr-checks.yml +++ b/.github/workflows/pr-checks.yml @@ -9,7 +9,7 @@ jobs: uses: nullplatform/actions-nullplatform/.github/workflows/pr-checks-go.yml@main with: working-directory: k8s/log/kube-logger-go - go-version: '1.25' + go-version: '1.25.13' shellcheck: uses: nullplatform/actions-nullplatform/.github/workflows/shellcheck.yml@main @@ -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/.github/workflows/publish-images.yml b/.github/workflows/publish-images.yml new file mode 100644 index 00000000..6792a521 --- /dev/null +++ b/.github/workflows/publish-images.yml @@ -0,0 +1,169 @@ +name: publish-images + +# Publishes every scope's worker image to ECR Public on each semver tag, then +# registers each as an oci_image platform artifact (visible-to organization=*). +# Same mold as scopes-lambda (publish-image.yml), fanned out to the 3 images: +# +# scopes/containers <- k8s/ (base; FROM worker-bridge + tooling) +# scopes/scheduled-task <- scheduled_task/ (leaner) +# scopes/containers-datadog <- containers + datadog/ overlay (metric) +# +# The datadog overlay is FROM the containers base (which bakes the whole repo +# into /app/pkg), so it must be pushed first — its build `needs: containers` and +# passes BASE_VERSION so its Dockerfile can FROM containers:. +# (azure / azure-aro are pure config overlays the tofu modules configure at +# install time via NP_OVERRIDES_PATH, so they need no image of their own.) +# +# Explicit job per image on purpose: a matrixed job that calls the reusable +# workflow collapses `image_digest` to a single value (matrix outputs overwrite +# each other), which would register every artifact against the same image. +on: + push: + tags: + - 'v*' + +permissions: + id-token: write # OIDC against AWS + contents: write # create/update the GitHub release with artifact metadata + +jobs: + # ── containers (base) ────────────────────────────────────────────────────── + containers: + uses: nullplatform/actions-nullplatform/.github/workflows/docker-build-push-ecr.yml@main + with: + image_name: scopes/containers + context: . + submodules: true + dockerfile: docker/containers.Dockerfile + tag: ${{ github.ref_name }} + secrets: + aws_role_arn: ${{ secrets.AWS_ROLE_ARN_ECR_PUSH }} + + register-containers: + name: Register containers artifact + needs: containers + runs-on: ubuntu-24.04 + env: + NULLPLATFORM_API_KEY: ${{ secrets.NP_API_KEY }} + NP_ARTIFACT_NRN: ${{ vars.NP_ARTIFACT_NRN }} + steps: + - name: Install np CLI (alpha-packages build) + run: curl -s https://cli.nullplatform.com/install.sh | VERSION=alpha-packages sh + - name: Register scopes/containers image artifact (visible to everyone) + run: | + np artifact create \ + --nrn "$NP_ARTIFACT_NRN" \ + --type oci_image \ + --registry public.ecr.aws \ + --repository nullplatform/scopes/containers \ + --digest "${{ needs.containers.outputs.image_digest }}" \ + --visible-to "organization=*" + + # ── scheduled-task (standalone) ──────────────────────────────────────────── + scheduled-task: + uses: nullplatform/actions-nullplatform/.github/workflows/docker-build-push-ecr.yml@main + with: + image_name: scopes/scheduled-task + context: . + submodules: true + dockerfile: docker/scheduled-task.Dockerfile + tag: ${{ github.ref_name }} + secrets: + aws_role_arn: ${{ secrets.AWS_ROLE_ARN_ECR_PUSH }} + + register-scheduled-task: + name: Register scheduled-task artifact + needs: scheduled-task + runs-on: ubuntu-24.04 + env: + NULLPLATFORM_API_KEY: ${{ secrets.NP_API_KEY }} + NP_ARTIFACT_NRN: ${{ vars.NP_ARTIFACT_NRN }} + steps: + - name: Install np CLI (alpha-packages build) + run: curl -s https://cli.nullplatform.com/install.sh | VERSION=alpha-packages sh + - name: Register scopes/scheduled-task image artifact (visible to everyone) + run: | + np artifact create \ + --nrn "$NP_ARTIFACT_NRN" \ + --type oci_image \ + --registry public.ecr.aws \ + --repository nullplatform/scopes/scheduled-task \ + --digest "${{ needs.scheduled-task.outputs.image_digest }}" \ + --visible-to "organization=*" + + # ── containers-datadog (overlay) ─────────────────────────────────────────── + containers-datadog: + needs: containers + uses: nullplatform/actions-nullplatform/.github/workflows/docker-build-push-ecr.yml@main + with: + image_name: scopes/containers-datadog + context: . + submodules: true + dockerfile: docker/containers-datadog.Dockerfile + tag: ${{ github.ref_name }} + build_args: BASE_VERSION=${{ github.ref_name }} + secrets: + aws_role_arn: ${{ secrets.AWS_ROLE_ARN_ECR_PUSH }} + + register-containers-datadog: + name: Register containers-datadog artifact + needs: containers-datadog + runs-on: ubuntu-24.04 + env: + NULLPLATFORM_API_KEY: ${{ secrets.NP_API_KEY }} + NP_ARTIFACT_NRN: ${{ vars.NP_ARTIFACT_NRN }} + steps: + - name: Install np CLI (alpha-packages build) + run: curl -s https://cli.nullplatform.com/install.sh | VERSION=alpha-packages sh + - name: Register scopes/containers-datadog image artifact (visible to everyone) + run: | + np artifact create \ + --nrn "$NP_ARTIFACT_NRN" \ + --type oci_image \ + --registry public.ecr.aws \ + --repository nullplatform/scopes/containers-datadog \ + --digest "${{ needs.containers-datadog.outputs.image_digest }}" \ + --visible-to "organization=*" + + # ── GitHub release with artifact metadata ────────────────────────────────── + # Tags here are human-pushed and previously produced no GitHub release at + # all, so the published digests were invisible to consumers. Upsert a release + # for the tag whose body carries every image's digest and copyable pinned + # reference. Runs after the registrations so the table reflects what was + # actually published; the digest check keeps re-runs idempotent. + finalize-release: + name: Publish release with artifact metadata + needs: [containers, scheduled-task, containers-datadog, register-containers, register-scheduled-task, register-containers-datadog] + runs-on: ubuntu-24.04 + env: + GH_TOKEN: ${{ github.token }} + TAG: ${{ github.ref_name }} + REGISTRY: public.ecr.aws/nullplatform + DIGEST_CONTAINERS: ${{ needs.containers.outputs.image_digest }} + DIGEST_SCHEDULED: ${{ needs.scheduled-task.outputs.image_digest }} + DIGEST_DATADOG: ${{ needs.containers-datadog.outputs.image_digest }} + steps: + - name: Upsert release with artifact table + run: | + SECTION=$(printf '## Artifacts\n\n| Image | Digest | Pinned reference |\n|---|---|---|\n| `%s:%s` | `%s` | `%s@%s` |\n| `%s:%s` | `%s` | `%s@%s` |\n| `%s:%s` | `%s` | `%s@%s` |' \ + "$REGISTRY/scopes/containers" "$TAG" "$DIGEST_CONTAINERS" "$REGISTRY/scopes/containers" "$DIGEST_CONTAINERS" \ + "$REGISTRY/scopes/scheduled-task" "$TAG" "$DIGEST_SCHEDULED" "$REGISTRY/scopes/scheduled-task" "$DIGEST_SCHEDULED" \ + "$REGISTRY/scopes/containers-datadog" "$TAG" "$DIGEST_DATADOG" "$REGISTRY/scopes/containers-datadog" "$DIGEST_DATADOG") + + # Drafts are not resolvable via releases/tags/:tag — list and filter. + RELEASE_ID=$(gh api "repos/$GITHUB_REPOSITORY/releases" --paginate \ + --jq "[.[] | select(.tag_name==\"$TAG\")][0].id // empty") + + if [ -z "$RELEASE_ID" ]; then + gh release create "$TAG" --title "$TAG" --notes "$SECTION" --verify-tag + echo "created release $TAG" + else + BODY=$(gh api "repos/$GITHUB_REPOSITORY/releases/$RELEASE_ID" --jq '.body // ""') + if printf '%s' "$BODY" | grep -qF "$DIGEST_CONTAINERS"; then + echo "release $TAG already carries these digests" + else + printf '%s\n\n%s' "$BODY" "$SECTION" > body.md + gh release edit "$TAG" --draft=false --notes-file body.md + echo "updated release $TAG" + fi + fi 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/CHANGELOG.md b/CHANGELOG.md index 3ad5d4f6..85d10fb7 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -5,8 +5,21 @@ All notable changes to this project will be documented in this file. The format is based on [Keep a Changelog](https://keepachangelog.com/en/1.0.0/), and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.html). -## [Unreleased] +## [1.16.0] - 2026-09-02 +- k8s scopes now show live, step-by-step progress in the dashboard when a scope is created, updated or deleted, and for every deployment action (deploy, switch traffic, finalize, rollback, delete, diagnose, kill instance, restart pods, pause/resume autoscaling, set instance count): each step with its duration, and long waits (load balancer, DNS, instance health) saying what they are waiting for. Requires `NP_API_KEY` on the agent; without it everything works as before +- Failed k8s deployments now explain why on the step that failed, and what to do about it: image pull errors with the registry's message, out-of-memory kills, crash exit codes with the application's last log lines, and failing health checks with the path and response detected +- k8s **diagnose** now shows what each check found (summary, severity, affected pods, recommended action) instead of a list of green steps +- k8s scopes can now pin the traffic-manager sidecar version cluster-wide via the container-orchestration provider's `traffic_manager.version`, instead of only per-scope +- Publish containers and scheduled task scopes as docker images - Remove unused cloudwatch annotations from deployment objects +- Fix: log queries on k8s scopes now return the time range that was selected, instead of the most recent lines whatever range was chosen +- Fix: paging through logs on k8s scopes no longer repeats lines already shown, and now reaches the end of the selected range +- Fix: diagnose on k8s scopes no longer fails to publish its results when a check collects application logs + +## [1.15.1] - 2026-08-12 +- Fix: gRPC additional ports on k8s scopes now leave the declared port free for the application, so a gRPC server can bind the port configured in the scope instead of failing to start with "address already in use". gRPC ports now work the same way HTTP ones already did +- k8s scopes now reject an additional port above 55535 at deploy time, with a message explaining the limit, instead of starting a deployment whose traffic sidecar could never come up +- k8s scopes with gRPC additional ports now require traffic-manager image `1.7.0` or newer; on older images the gRPC sidecar never starts and the deployment stays unhealthy ## [1.15.0] - 2026-08-10 - Fix: **finalize** and **rollback** on blue/green k8s scopes now wait until the load balancer sends all traffic to the surviving deployment before deleting the other one, preventing the 5xx window that happened when it was deleted mid-switch (these actions may take slightly longer as a result) diff --git a/azure-aro/specs/service-spec.json.tpl b/azure-aro/specs/service-spec.json.tpl index 6c62ab40..8de657f9 100644 --- a/azure-aro/specs/service-spec.json.tpl +++ b/azure-aro/specs/service-spec.json.tpl @@ -564,9 +564,9 @@ "port":{ "type":"integer", "title":"Port Number", - "maximum":65535, + "maximum":55535, "minimum":1024, - "description":"The port number to expose (1024-65535)" + "description":"The port number your application binds and the scope exposes (1024-55535). Its traffic-manager sidecar takes this port plus 10000." }, "type":{ "enum":[ 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/specs/service-spec.json.tpl b/azure/specs/service-spec.json.tpl index 4a182823..1a4e705d 100644 --- a/azure/specs/service-spec.json.tpl +++ b/azure/specs/service-spec.json.tpl @@ -566,9 +566,9 @@ "port":{ "type":"integer", "title":"Port Number", - "maximum":65535, + "maximum":55535, "minimum":1024, - "description":"The port number to expose (1024-65535)" + "description":"The port number your application binds and the scope exposes (1024-55535). Its traffic-manager sidecar takes this port plus 10000." }, "type":{ "enum":[ 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/docker/containers-datadog.Dockerfile b/docker/containers-datadog.Dockerfile new file mode 100644 index 00000000..bd157826 --- /dev/null +++ b/docker/containers-datadog.Dockerfile @@ -0,0 +1,11 @@ +# syntax=docker/dockerfile:1 +# +# containers-datadog — the containers scope with the datadog overlay baked in +# (the datadog/ folder overrides the metric step). The containers base already +# COPYied the whole repo into /app/pkg (incl. datadog/), so this only layers the +# overlay onto the service-path. datadog uses jq + curl, already in the base. +ARG BASE_VERSION +FROM public.ecr.aws/nullplatform/scopes/containers:${BASE_VERSION} + +ENV NP_PACKAGE_NAME=containers-datadog \ + NP_OVERRIDES_PATH=/app/pkg/datadog diff --git a/docker/containers.Dockerfile b/docker/containers.Dockerfile new file mode 100644 index 00000000..19d1d553 --- /dev/null +++ b/docker/containers.Dockerfile @@ -0,0 +1,37 @@ +# syntax=docker/dockerfile:1 +# +# containers (k8s) scope image — the full Kubernetes scope on the lean gRPC +# worker bridge. The bridge dials over gRPC and runs the repo's bash entrypoint +# on each action; this image adds the cloud tooling the k8s steps call and bakes +# the whole repo in, so the package-exec channel needs no cmdline. +# +# NP_SERVICE_PATH=k8s + NP_SCOPE_ENTRYPOINT=/entrypoint mirrors the classic +# `.../scopes/entrypoint --service-path=k8s` the git-clone model used. +FROM public.ecr.aws/nullplatform/scopes/worker-bridge:1.0.0 + +# apk tooling the k8s steps call. bash, jq, np, base64, curl, ca-certs ship in +# the base. aws-cli 2.x, gomplate and yq are packaged on alpine. +RUN apk add --no-cache aws-cli gomplate yq + +# Pinned binaries not reliably packaged on alpine: OpenTofu, kubectl, helm. +# NOTE: review/pin these versions to what the scopes actually target. +ARG TARGETARCH +ARG TOFU_VERSION=1.10.6 +ARG KUBECTL_VERSION=1.30.4 +ARG HELM_VERSION=3.15.4 +RUN set -eux; \ + curl -fsSL "https://github.com/opentofu/opentofu/releases/download/v${TOFU_VERSION}/tofu_${TOFU_VERSION}_linux_${TARGETARCH}.tar.gz" \ + | tar -xz -C /usr/local/bin tofu; \ + curl -fsSL -o /usr/local/bin/kubectl "https://dl.k8s.io/release/v${KUBECTL_VERSION}/bin/linux/${TARGETARCH}/kubectl"; \ + chmod +x /usr/local/bin/kubectl; \ + curl -fsSL "https://get.helm.sh/helm-v${HELM_VERSION}-linux-${TARGETARCH}.tar.gz" | tar -xz -C /tmp; \ + mv "/tmp/linux-${TARGETARCH}/helm" /usr/local/bin/helm; \ + rm -rf "/tmp/linux-${TARGETARCH}"; \ + tofu version && kubectl version --client && helm version --short + +# Bake the whole repo in; the overlays (containers-azure, -datadog, -aro) are +# FROM this image and only flip NP_OVERRIDES_PATH — no re-copy needed. +COPY . /app/pkg +ENV NP_PACKAGE_NAME=containers \ + NP_SERVICE_PATH=/app/pkg/k8s \ + NP_SCOPE_ENTRYPOINT=/app/pkg/entrypoint diff --git a/docker/scheduled-task.Dockerfile b/docker/scheduled-task.Dockerfile new file mode 100644 index 00000000..1ece0e96 --- /dev/null +++ b/docker/scheduled-task.Dockerfile @@ -0,0 +1,18 @@ +# syntax=docker/dockerfile:1 +# +# scheduled-task scope image — the scheduled_task scope. Leaner than containers: +# its steps only reach for kubectl + gomplate (bash/jq/np ship in the base). +FROM public.ecr.aws/nullplatform/scopes/worker-bridge:1.0.0 + +RUN apk add --no-cache gomplate + +ARG TARGETARCH +ARG KUBECTL_VERSION=1.30.4 +RUN curl -fsSL -o /usr/local/bin/kubectl "https://dl.k8s.io/release/v${KUBECTL_VERSION}/bin/linux/${TARGETARCH}/kubectl" \ + && chmod +x /usr/local/bin/kubectl \ + && kubectl version --client + +COPY . /app/pkg +ENV NP_PACKAGE_NAME=scheduled-task \ + NP_SERVICE_PATH=/app/pkg/scheduled_task \ + NP_SCOPE_ENTRYPOINT=/app/pkg/entrypoint 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/build_context b/k8s/deployment/build_context index 370287e8..c0340487 100755 --- a/k8s/deployment/build_context +++ b/k8s/deployment/build_context @@ -139,10 +139,13 @@ fi SCOPE_TRAFFIC_PROTOCOL=$(echo "$CONTEXT" | jq -r .scope.capabilities.protocol) -TRAFFIC_CONTAINER_VERSION="latest" - if [[ "$SCOPE_TRAFFIC_PROTOCOL" == "web_sockets" ]]; then TRAFFIC_CONTAINER_VERSION="websocket2" +else + TRAFFIC_CONTAINER_VERSION=$(get_config_value \ + --provider '.providers["container-orchestration"].traffic_manager.version' \ + --default "latest" + ) fi TRAFFIC_CONTAINER_IMAGE=$(get_config_value \ @@ -269,12 +272,41 @@ log debug "🔍 main_http_port resolved to ${MAIN_HTTP_PORT}" # which application port at a glance (e.g. app 8081 -> sidecar 18081). Keeping # the math here (instead of in every template) means consumers just read # .traffic_manager_port and never re-derive it. +# +# The offset applies to GRPC as well as HTTP: nginx terminates the protocol on +# the sidecar port and proxies to the application on , so the application +# binds exactly the port it declared, whatever the type. CONTEXT=$(echo "$CONTEXT" | jq ' if (.scope.capabilities.additional_ports | type) == "array" then .scope.capabilities.additional_ports |= map(. + {traffic_manager_port: (.port + 10000)}) else . end ') +# The +10000 offset has to land on a valid TCP port, so anything above 55535 is +# unusable. Without this check nginx renders `listen 70000;` and refuses to +# start — and because start.sh does not check nginx's exit code, the sidecar +# stays Running with no proxy inside it. Catching it here turns a silent +# dead-sidecar into a deploy-time error. +OVERFLOWING_PORT=$(echo "$CONTEXT" | jq -r ' + [ (.scope.capabilities.additional_ports // [])[] + | select(.traffic_manager_port > 65535) + | .port + ] | first // empty +') + +if [[ -n "$OVERFLOWING_PORT" ]]; then + log error "❌ Additional port $OVERFLOWING_PORT is too high: its traffic-manager sidecar would need port $((OVERFLOWING_PORT + 10000))" + log error "" + log error "💡 Possible causes:" + log error " - Every additional port reserves both (application) and +10000 (its sidecar)" + log error " - Ports above 55535 push the sidecar past the maximum TCP port 65535" + log error "" + log error "🔧 How to fix:" + log error " • Choose an additional port of 55535 or lower" + log error "" + exit 1 +fi + # Port the main traffic-manager sidecar binds inside the pod. Default 80 # preserves historical behaviour. Operators can move it to another port # (10080 recommended — the same +10000 convention used for additional_ports @@ -287,7 +319,7 @@ CONTEXT=$(echo "$CONTEXT" | jq ' MAIN_TRAFFIC_MANAGER_PORT=$(get_config_value \ --env MAIN_TRAFFIC_MANAGER_PORT \ --provider '.providers["scope-configurations"].deployment.main_traffic_manager_port' \ - --provider '.providers["container-orchestration"].cluster.main_traffic_manager_port' \ + --provider '.providers["container-orchestration"].traffic_manager.port' \ --default "80" ) 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/templates/deployment.yaml.tpl b/k8s/deployment/templates/deployment.yaml.tpl index 92c08298..0e513c1e 100644 --- a/k8s/deployment/templates/deployment.yaml.tpl +++ b/k8s/deployment/templates/deployment.yaml.tpl @@ -183,9 +183,11 @@ spec: runAsUser: 0 image: {{ $.traffic_image }} ports: - - containerPort: {{ .port }} + - containerPort: {{ .traffic_manager_port }} protocol: TCP env: + - name: UPSTREAM_PORT + value: '{{ .port }}' - name: HEALTH_CHECK_TYPE value: grpc - name: GRACE_PERIOD @@ -193,7 +195,7 @@ spec: - name: LISTENER_PROTOCOL value: grpc - name: LISTENER_PORT - value: '{{ .port }}' + value: '{{ .traffic_manager_port }}' resources: limits: cpu: {{ $.container_cpu_in_millicores }}m @@ -202,7 +204,7 @@ spec: cpu: 31m livenessProbe: grpc: - port: {{ .port }} + port: {{ .traffic_manager_port }} timeoutSeconds: 5 periodSeconds: 10 initialDelaySeconds: {{ $.scope.capabilities.health_check.initial_delay_seconds }} @@ -210,7 +212,7 @@ spec: failureThreshold: 9 readinessProbe: grpc: - port: {{ .port }} + port: {{ .traffic_manager_port }} timeoutSeconds: 5 periodSeconds: 10 initialDelaySeconds: {{ $.scope.capabilities.health_check.initial_delay_seconds }} @@ -218,7 +220,7 @@ spec: failureThreshold: 3 startupProbe: grpc: - port: {{ .port }} + port: {{ .traffic_manager_port }} timeoutSeconds: 5 periodSeconds: 10 initialDelaySeconds: {{ $.scope.capabilities.health_check.initial_delay_seconds }} @@ -310,12 +312,10 @@ spec: protocol: TCP {{ if .scope.capabilities.additional_ports }} {{ range .scope.capabilities.additional_ports }} - {{ if eq .type "HTTP" }} - containerPort: {{ .port }} protocol: TCP {{ end }} {{ end }} - {{ end }} resources: limits: cpu: {{ .scope.capabilities.cpu_millicores_limit }}m diff --git a/k8s/deployment/templates/service.yaml.tpl b/k8s/deployment/templates/service.yaml.tpl index 96cf9ccd..a5af3a57 100644 --- a/k8s/deployment/templates/service.yaml.tpl +++ b/k8s/deployment/templates/service.yaml.tpl @@ -196,7 +196,7 @@ spec: ports: - protocol: TCP port: {{ .port }} - targetPort: {{ .port }} + targetPort: {{ .traffic_manager_port }} selector: nullplatform: "true" account: {{ $.account.slug }} diff --git a/k8s/deployment/tests/build_context.bats b/k8s/deployment/tests/build_context.bats index 09605911..72f95cc6 100644 --- a/k8s/deployment/tests/build_context.bats +++ b/k8s/deployment/tests/build_context.bats @@ -213,22 +213,50 @@ teardown() { # ============================================================================= # Traffic Container Image Version Tests # ============================================================================= -@test "traffic container: uses websocket2 for web_sockets, latest for http" { - # web_sockets protocol - SCOPE_TRAFFIC_PROTOCOL="web_sockets" - TRAFFIC_CONTAINER_VERSION="latest" - if [[ "$SCOPE_TRAFFIC_PROTOCOL" == "web_sockets" ]]; then - TRAFFIC_CONTAINER_VERSION="websocket2" +resolve_traffic_container_version() { + local protocol="$1" + if [[ "$protocol" == "web_sockets" ]]; then + echo "websocket2" + else + get_config_value \ + --provider '.providers["container-orchestration"].traffic_manager.version' \ + --default "latest" fi - assert_equal "$TRAFFIC_CONTAINER_VERSION" "websocket2" +} - # http protocol - SCOPE_TRAFFIC_PROTOCOL="http" - TRAFFIC_CONTAINER_VERSION="latest" - if [[ "$SCOPE_TRAFFIC_PROTOCOL" == "web_sockets" ]]; then - TRAFFIC_CONTAINER_VERSION="websocket2" - fi - assert_equal "$TRAFFIC_CONTAINER_VERSION" "latest" +@test "traffic container: uses websocket2 for web_sockets, latest for http" { + result=$(resolve_traffic_container_version "web_sockets") + assert_equal "$result" "websocket2" + + result=$(resolve_traffic_container_version "http") + assert_equal "$result" "latest" +} + +@test "traffic container: http protocol uses container-orchestration provider version when set" { + export CONTEXT=$(echo "$CONTEXT" | jq '.providers["container-orchestration"] = {"traffic_manager": {"version": "1.8.0"}}') + + result=$(resolve_traffic_container_version "http") + assert_equal "$result" "1.8.0" +} + +@test "traffic container: web_sockets protocol ignores container-orchestration provider version" { + export CONTEXT=$(echo "$CONTEXT" | jq '.providers["container-orchestration"] = {"traffic_manager": {"version": "1.8.0"}}') + + result=$(resolve_traffic_container_version "web_sockets") + assert_equal "$result" "websocket2" +} + +@test "traffic container: provider version flows into the default image when no full-image override is set" { + export CONTEXT=$(echo "$CONTEXT" | jq '.providers["container-orchestration"] = {"traffic_manager": {"version": "1.8.0"}}') + unset TRAFFIC_CONTAINER_IMAGE + + TRAFFIC_CONTAINER_VERSION=$(resolve_traffic_container_version "http") + result=$(get_config_value \ + --env TRAFFIC_CONTAINER_IMAGE \ + --provider '.providers["scope-configurations"].deployment.traffic_container_image' \ + --default "public.ecr.aws/nullplatform/k8s-traffic-manager:$TRAFFIC_CONTAINER_VERSION" + ) + assert_equal "$result" "public.ecr.aws/nullplatform/k8s-traffic-manager:1.8.0" } # ============================================================================= @@ -947,6 +975,51 @@ set_additional_ports() { assert_equal "$(echo "$CONTEXT" | jq -c '.scope.capabilities.additional_ports')" "[]" } +# ----------------------------------------------------------------------------- +# Additional port ceiling: port + 10000 has to stay a valid TCP port. +# ----------------------------------------------------------------------------- + +@test "additional port ceiling: rejects a port whose sidecar would exceed 65535" { + setup_full_build_context + set_additional_ports '[{"port":60000,"type":"HTTP"}]' + + run source "$SCRIPT" + + [ "$status" -ne 0 ] + local expected + expected=$(cat <<'EOF' +❌ Additional port 60000 is too high: its traffic-manager sidecar would need port 70000 + +💡 Possible causes: + - Every additional port reserves both (application) and +10000 (its sidecar) + - Ports above 55535 push the sidecar past the maximum TCP port 65535 + +🔧 How to fix: + • Choose an additional port of 55535 or lower +EOF +) + assert_contains "$output" "$expected" +} + +@test "additional port ceiling: applies to GRPC entries too" { + setup_full_build_context + set_additional_ports '[{"port":9090,"type":"HTTP"},{"port":60001,"type":"GRPC"}]' + + run source "$SCRIPT" + + [ "$status" -ne 0 ] + assert_contains "$output" "❌ Additional port 60001 is too high: its traffic-manager sidecar would need port 70001" +} + +@test "additional port ceiling: accepts the boundary value 55535" { + setup_full_build_context + set_additional_ports '[{"port":55535,"type":"GRPC"}]' + + source "$SCRIPT" + + assert_equal "$(echo "$CONTEXT" | jq -r '.scope.capabilities.additional_ports[0].traffic_manager_port')" "65535" +} + # ============================================================================= # Capability limits normalization # These tests source the real deployment/build_context and assert on the @@ -1064,7 +1137,7 @@ set_capabilities() { @test "main_traffic_manager_port: read from container-orchestration provider" { setup_full_build_context - CONTEXT=$(echo "$CONTEXT" | jq '.providers["container-orchestration"].cluster.main_traffic_manager_port = 10080') + CONTEXT=$(echo "$CONTEXT" | jq '.providers["container-orchestration"].traffic_manager.port = 10080') source "$SCRIPT" @@ -1074,7 +1147,7 @@ set_capabilities() { @test "main_traffic_manager_port: scope-configurations takes priority over container-orchestration" { setup_full_build_context CONTEXT=$(echo "$CONTEXT" | jq ' - .providers["container-orchestration"].cluster.main_traffic_manager_port = 10080 + .providers["container-orchestration"].traffic_manager.port = 10080 | .providers["scope-configurations"].deployment.main_traffic_manager_port = 11080 ') @@ -1094,7 +1167,7 @@ set_capabilities() { @test "main_traffic_manager_port: rejects non-numeric value" { setup_full_build_context - CONTEXT=$(echo "$CONTEXT" | jq '.providers["container-orchestration"].cluster.main_traffic_manager_port = "not-a-port"') + CONTEXT=$(echo "$CONTEXT" | jq '.providers["container-orchestration"].traffic_manager.port = "not-a-port"') run source "$SCRIPT" @@ -1112,7 +1185,7 @@ EOF @test "main_traffic_manager_port: accepts a privileged port other than 80" { setup_full_build_context - CONTEXT=$(echo "$CONTEXT" | jq '.providers["container-orchestration"].cluster.main_traffic_manager_port = 90') + CONTEXT=$(echo "$CONTEXT" | jq '.providers["container-orchestration"].traffic_manager.port = 90') source "$SCRIPT" @@ -1121,7 +1194,7 @@ EOF @test "main_traffic_manager_port: rejects port above 65535" { setup_full_build_context - CONTEXT=$(echo "$CONTEXT" | jq '.providers["container-orchestration"].cluster.main_traffic_manager_port = 70000') + CONTEXT=$(echo "$CONTEXT" | jq '.providers["container-orchestration"].traffic_manager.port = 70000') run source "$SCRIPT" @@ -1139,7 +1212,7 @@ EOF @test "main_traffic_manager_port: rejects port 0" { setup_full_build_context - CONTEXT=$(echo "$CONTEXT" | jq '.providers["container-orchestration"].cluster.main_traffic_manager_port = 0') + CONTEXT=$(echo "$CONTEXT" | jq '.providers["container-orchestration"].traffic_manager.port = 0') run source "$SCRIPT" @@ -1159,7 +1232,7 @@ EOF setup_full_build_context CONTEXT=$(echo "$CONTEXT" | jq ' .scope.capabilities.main_http_port = 10080 - | .providers["container-orchestration"].cluster.main_traffic_manager_port = 10080 + | .providers["container-orchestration"].traffic_manager.port = 10080 ') run source "$SCRIPT" @@ -1181,7 +1254,7 @@ EOF @test "main_traffic_manager_port: rejects collision with an additional port" { setup_full_build_context set_additional_ports '[{"port":10080,"type":"HTTP"}]' - CONTEXT=$(echo "$CONTEXT" | jq '.providers["container-orchestration"].cluster.main_traffic_manager_port = 10080') + CONTEXT=$(echo "$CONTEXT" | jq '.providers["container-orchestration"].traffic_manager.port = 10080') run source "$SCRIPT" @@ -1202,7 +1275,7 @@ EOF @test "main_traffic_manager_port: rejects collision with an additional port's sidecar port" { setup_full_build_context set_additional_ports '[{"port":8081,"type":"HTTP"}]' - CONTEXT=$(echo "$CONTEXT" | jq '.providers["container-orchestration"].cluster.main_traffic_manager_port = 18081') + CONTEXT=$(echo "$CONTEXT" | jq '.providers["container-orchestration"].traffic_manager.port = 18081') run source "$SCRIPT" @@ -1223,7 +1296,7 @@ EOF @test "main_traffic_manager_port: accepts 10080 alongside unrelated additional ports" { setup_full_build_context set_additional_ports '[{"port":9090,"type":"HTTP"},{"port":9014,"type":"GRPC"}]' - CONTEXT=$(echo "$CONTEXT" | jq '.providers["container-orchestration"].cluster.main_traffic_manager_port = 10080') + CONTEXT=$(echo "$CONTEXT" | jq '.providers["container-orchestration"].traffic_manager.port = 10080') source "$SCRIPT" diff --git a/k8s/deployment/tests/grpc_port_shape.bats b/k8s/deployment/tests/grpc_port_shape.bats new file mode 100644 index 00000000..bf3a055a --- /dev/null +++ b/k8s/deployment/tests/grpc_port_shape.bats @@ -0,0 +1,167 @@ +#!/usr/bin/env bats +# ============================================================================= +# Structural + rendering tests for GRPC additional ports. +# +# A GRPC additional port follows the same convention as an HTTP one: the +# application binds the port it declared, and its traffic-manager sidecar binds +# +10000. Before this was aligned the sidecar bound itself, so the +# application could not open its own gRPC listener — every container in a pod +# shares one network namespace, so it got EADDRINUSE. +# +# That bug stayed invisible for months because the traffic-manager image used +# to ignore LISTENER_PORT: nginx fell back to port 80, collided with the main +# sidecar, died, and start.sh (which never checks nginx's exit code) kept the +# container alive. Traffic went straight from the Service to the application. +# These tests pin the pieces that have to move together. +# ============================================================================= + +setup() { + export PROJECT_ROOT="$(cd "$BATS_TEST_DIRNAME/../../.." && pwd)" + source "$PROJECT_ROOT/testing/assertions.sh" + export TPL_DIR="$PROJECT_ROOT/k8s/deployment/templates" + export DEPLOYMENT="$TPL_DIR/deployment.yaml.tpl" + export SERVICE="$TPL_DIR/service.yaml.tpl" +} + +# ----------------------------------------------------------------------------- +# Structural — grep the template sources +# ----------------------------------------------------------------------------- + +@test "deployment: grpc sidecar binds traffic_manager_port, not the declared port" { + # The gRPC probes are the only `grpc:` blocks in the template. + count=$(grep -A1 '^ grpc:' "$DEPLOYMENT" | grep -c 'port: {{ .traffic_manager_port }}') + [ "$count" -eq 3 ] + ! grep -A1 '^ grpc:' "$DEPLOYMENT" | grep -q 'port: {{ .port }}' +} + +@test "deployment: grpc sidecar receives UPSTREAM_PORT pointing at the application port" { + # Without it the image falls back to its own default of 8080, which silently + # breaks any scope whose gRPC server does not happen to listen there. + grpc_branch=$(awk '/{{ if eq .type "GRPC" }}/,/{{ else if eq .type "HTTP" }}/' "$DEPLOYMENT") + assert_contains "$grpc_branch" "name: UPSTREAM_PORT" + assert_contains "$grpc_branch" "value: '{{ .port }}'" +} + +@test "deployment: application container ports block does not filter by type" { + # Both HTTP and GRPC entries are bound by the application now, so a type + # guard here would drop the gRPC port from the rendered spec. + app_ports=$(awk '/- containerPort: {{ .main_http_port }}/,/resources:/' "$DEPLOYMENT") + assert_contains "$app_ports" "containerPort: {{ .port }}" + if echo "$app_ports" | grep -q 'eq .type'; then + echo "application ports block still filters on port type" + return 1 + fi +} + +@test "service: grpc service targets the sidecar port" { + # port stays the declared one (external contract), targetPort moves. + ! grep -qE 'targetPort: \{\{ \.port \}\}' "$SERVICE" + count=$(grep -c 'targetPort: {{ .traffic_manager_port }}' "$SERVICE") + [ "$count" -eq 2 ] +} + +# ----------------------------------------------------------------------------- +# Rendering — real gomplate against the templates +# ----------------------------------------------------------------------------- + +_grpc_context() { + cat <<'JSON' +{ + "account": {"id": "acc1", "slug": "acct"}, + "namespace": {"id": "ns1", "slug": "nsps"}, + "application": {"id": "app1", "slug": "appslug"}, + "release": {"semver": "1.0.0"}, + "scope": { + "id": "scope-123", + "slug": "scopeslug", + "domain": "x.example.com", + "domains": [], + "dimensions": {"env": "dev"}, + "capabilities": { + "cpu_millicores": 100, + "ram_memory": 128, + "cpu_millicores_limit": 200, + "ram_memory_limit": 256, + "additional_ports": [{"port": 9090, "type": "GRPC", "traffic_manager_port": 19090}], + "scaling_type": "fixed", + "autoscaling": { + "min_replicas": 1, + "max_replicas": 3, + "target_cpu_utilization": 80, + "target_memory_enabled": false, + "target_memory_utilization": 80 + }, + "health_check": {"path": "/health", "timeout_seconds": 1, "period_seconds": 5, "initial_delay_seconds": 5} + } + }, + "deployment": {"id": "deploy-456"}, + "k8s_namespace": "ns-test", + "k8s_modifiers": {}, + "asset": {"url": "example.com/app:latest"}, + "main_http_port": 8080, + "main_traffic_manager_port": 80, + "traffic_image": "example.com/traffic:latest", + "container_cpu_in_millicores": 50, + "container_memory_in_memory": 64, + "pull_secrets": {"ENABLED": false, "SECRETS": []}, + "region": "us-east-1", + "component": "app", + "service_account_name": "", + "traffic_manager_config_map": "", + "replicas": 1, + "parameters": {"results": []} +} +JSON +} + +_render() { + local tpl="$1" + local ctx="$BATS_TEST_TMPDIR/ctx.json" + _grpc_context > "$ctx" + gomplate -c .="$ctx" -f "$tpl" +} + +@test "render: grpc sidecar listens on 19090 and proxies to 9090" { + run _render "$DEPLOYMENT" + [ "$status" -eq 0 ] + + # The sidecar container block, from its name down to its probes. + sidecar=$(echo "$output" | awk '/- name: grpc-9090/,/imagePullPolicy/') + + assert_contains "$sidecar" "containerPort: 19090" + assert_contains "$sidecar" "name: UPSTREAM_PORT" + assert_contains "$sidecar" "value: '9090'" + assert_contains "$sidecar" "name: LISTENER_PORT" + assert_contains "$sidecar" "value: '19090'" + assert_contains "$sidecar" "port: 19090" + + # The application port must never appear as the sidecar's listener. + if echo "$sidecar" | grep -q "containerPort: 9090"; then + echo "sidecar still binds the application port 9090" + return 1 + fi +} + +@test "render: application container declares the gRPC port it binds" { + run _render "$DEPLOYMENT" + [ "$status" -eq 0 ] + + app=$(echo "$output" | awk '/- name: application/,/lifecycle:/') + assert_contains "$app" "containerPort: 8080" + assert_contains "$app" "containerPort: 9090" + + # The sidecar port belongs to the sidecar, not the application. + if echo "$app" | grep -q "containerPort: 19090"; then + echo "application container should not declare the sidecar port" + return 1 + fi +} + +@test "render: grpc Service exposes 9090 and targets the sidecar on 19090" { + run _render "$SERVICE" + [ "$status" -eq 0 ] + + svc=$(echo "$output" | awk '/d-scope-123-deploy-456-grpc-9090/,0') + assert_contains "$svc" "port: 9090" + assert_contains "$svc" "targetPort: 19090" +} 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 bb218b81..a0d0fbd2 100644 --- a/k8s/diagnose/tests/diagnose_utils.bats +++ b/k8s/diagnose/tests/diagnose_utils.bats @@ -419,3 +419,113 @@ strip_ansi() { local clean=$(strip_ansi "$output") 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 + line=$(printf 'x%.0s' {1..1000}) + jq -nc --arg line "$line" \ + '{category: "logs", status: "success", evidence: {}, logs: [range(2000) | $line]}' \ + > "$NP_OUTPUT_DIR/big.json" + + local body_file="$(mktemp)" + export BODY_CAPTURE="$body_file" + # Mirror np: --body is read from disk only when the value ends in .json, + # otherwise it is sent verbatim. Resolved here because the caller cleans up. + np() { + local prev="" + for arg in "$@"; do + if [[ "$prev" == "--body" ]]; then + if [[ "$arg" == *.json ]]; then cat "$arg" > "$BODY_CAPTURE"; else printf '%s' "$arg" > "$BODY_CAPTURE"; fi + fi + prev="$arg" + done + return 0 + } + export -f np + + run notify_results + [ "$status" -eq 0 ] + + assert_equal "$(jq -r '.results.categories[0].category' "$body_file")" "logs" + assert_equal "$(jq -r '.results.categories[0].checks[0].logs | length' "$body_file")" "2000" + + rm -f "$body_file" + unset BODY_CAPTURE +} + +# ============================================================================= +# lines_to_json_array +# ============================================================================= +@test "lines_to_json_array: passes short lines through untouched" { + local out + out=$(printf 'alpha\n\nbeta\n' | lines_to_json_array) + + assert_equal "$(echo "$out" | jq -r 'length')" "2" + assert_equal "$(echo "$out" | jq -r '.[0]')" "alpha" + assert_equal "$(echo "$out" | jq -r '.[1]')" "beta" +} + +@test "lines_to_json_array: truncates a line past the character cap" { + local out + out=$(printf 'x%.0s' {1..5000} | EVIDENCE_LOG_LINE_MAX_CHARS=100 lines_to_json_array) + + assert_equal "$(echo "$out" | jq -r 'length')" "1" + assert_contains "$(echo "$out" | jq -r '.[0]')" "[truncated]" + # 100 kept characters plus the marker, nowhere near the original 5000. + [ "$(echo "$out" | jq -r '.[0] | length')" -lt 200 ] +} diff --git a/k8s/diagnose/utils/diagnose_utils b/k8s/diagnose/utils/diagnose_utils index 94bac3b8..43557c3c 100644 --- a/k8s/diagnose/utils/diagnose_utils +++ b/k8s/diagnose/utils/diagnose_utils @@ -123,8 +123,16 @@ read_log_tail() { # Convert newline-delimited stdin into a JSON array of non-empty strings. # Used by read_log_tail and update_check_result to share one canonical # tail-text-to-JSON pipeline. +# +# Lines are truncated at $EVIDENCE_LOG_LINE_MAX_CHARS (default 2000): kubectl's +# --tail bounds line count, not line length. lines_to_json_array() { - jq -R -s 'split("\n") | map(select(length > 0))' + local max="${EVIDENCE_LOG_LINE_MAX_CHARS:-2000}" + jq -R -s --argjson max "$max" ' + split("\n") + | map(select(length > 0)) + | map(if length > $max then .[:$max] + "…[truncated]" else . end) + ' } # Append a JSON object to a bash indexed array (passed by name). Avoids the @@ -321,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() { @@ -333,10 +362,18 @@ notify_results() { exit 1 fi - # Generate grouped results directly in memory - # Use xargs to avoid "Argument list too long" error - local grouped_results - grouped_results=$(echo "$json_files" | xargs jq -s ' + # The payload must never travel through argv: Linux caps a single execve + # argument at 128 KiB, and ulimit does not lift it. Hence xargs, then + # --slurpfile, then a file path for np --body. + # + # The .json suffix is required: np reads --body from disk only when the + # value ends in .json, otherwise it sends the string itself. + local work_dir results_file body_file rc + work_dir="$(mktemp -d)" + results_file="$work_dir/results.json" + body_file="$work_dir/body.json" + + if ! echo "$json_files" | xargs jq -s ' # category helper def cat: .category // "unknown"; @@ -355,19 +392,31 @@ notify_results() { }, checks: . }) - ') + ' > "$results_file"; then + print_error "Failed to group check results from $NP_OUTPUT_DIR" + rm -rf "$work_dir" + return 1 + fi # Extract action and service IDs ACTION_ID=$(echo "$NP_ACTION_CONTEXT" | jq -r '.notification.id') SERVICE_ID=$(echo "$NP_ACTION_CONTEXT" | jq -r '.notification.service.id') # Build action body with grouped results - ACTION_BODY=$(jq -nc \ - --argjson result "$grouped_results" \ - '{ - results: { categories: $result } - }') + if ! jq -nc \ + --slurpfile result "$results_file" \ + '{ + results: { categories: $result[0] } + }' > "$body_file"; then + print_error "Failed to build the action body" + rm -rf "$work_dir" + return 1 + fi # Send to np service - np service action patch --id "$ACTION_ID" --serviceId "$SERVICE_ID" --body "$ACTION_BODY" --no-output -} \ No newline at end of file + np service action patch --id "$ACTION_ID" --serviceId "$SERVICE_ID" --body "$body_file" --no-output + rc=$? + + rm -rf "$work_dir" + return $rc +} diff --git a/k8s/docs/configurable-http-ports.md b/k8s/docs/configurable-http-ports.md index 9cb1d6c3..2ce32143 100644 --- a/k8s/docs/configurable-http-ports.md +++ b/k8s/docs/configurable-http-ports.md @@ -34,7 +34,9 @@ The port your application binds to inside the container. When set, the following - **Default:** `80` - **Valid values:** `1`–`65535` - **Configured via:** `container-orchestration` provider at - `.cluster.main_traffic_manager_port`, the `scope-configurations` provider at + `.traffic_manager.port` (exposed in the EKS provider spec as the + `Traffic Manager Port` field, mapped to the NRN key + `k8s.mainTrafficManagerPort`), the `scope-configurations` provider at `.deployment.main_traffic_manager_port`, or the `MAIN_TRAFFIC_MANAGER_PORT` env var in `values.yaml`. Precedence follows the usual order — `scope-configurations`, then `container-orchestration`, then env, then default. @@ -77,7 +79,8 @@ To adopt a different port, in this order: 1. Allow the port (`10080` recommended) inbound on the security group attached to the pod ENIs. -2. Set `main_traffic_manager_port` in the `container-orchestration` provider. +2. Set `traffic_manager.port` in the `container-orchestration` provider (the + `Traffic Manager Port` field on the EKS provider). 3. Deploy. The order matters. Setting the knob before opening the port yields a green @@ -98,12 +101,12 @@ not survive. `additional_ports` is a list of extra ports the scope exposes alongside the main HTTP listener. Each item has: -- `port`: integer 1024–65535 +- `port`: integer 1024–55535 - `type`: `"GRPC"` or `"HTTP"` For each additional port (HTTP or GRPC), the deployment generates a traffic-manager sidecar that handles external traffic. The sidecar is **always** in the request path: it adds nginx-level metrics, graceful-shutdown handling, and body-size limits. -The architecture differs slightly between HTTP and GRPC because of how the application is expected to bind ports: +**Both types follow the same port model:** the application binds the port it declared, and the sidecar binds `port + 10000`. The only difference is the protocol nginx speaks on each side. ### HTTP additional port — same model as `main_http_port` @@ -126,23 +129,41 @@ Application container binds 9090 (and also 8081 for the main listener) The application sees two real listeners: `8081` (main) and `9090` (additional). External traffic to either flows through its respective sidecar (the main `http` sidecar for `8081`, the `http-9090` sidecar for `9090`). -**Constraint:** because the sidecar uses `port + 10000`, the additional port must be `≤ 55535` for HTTP. Above that the offset overflows the 65535 max TCP port. +**Constraint:** because the sidecar uses `port + 10000`, the additional port must be `≤ 55535`. Above that the offset overflows the 65535 max TCP port; `build_context` rejects it at deploy time. -### GRPC additional port — sidecar terminates protocol +### GRPC additional port — nginx terminates HTTP/2 -The application does **NOT** bind GRPC additional ports. The `grpc-{port}` sidecar binds `{port}` directly and translates gRPC into HTTP, proxying to `localhost:main_http_port`. The application speaks only HTTP on `main_http_port` and serves both main HTTP traffic and any incoming gRPC requests (received already translated to HTTP). +A GRPC additional port works exactly like an HTTP one, with a gRPC-aware nginx config: the `grpc-{port}` sidecar listens on `port + 10000` with `http2 on` and forwards with `grpc_pass grpc://127.0.0.1:{port}`. + +`grpc_pass` does **not** transcode. The upstream has to speak gRPC — so the application's gRPC server binds `{port}` (h2c, plaintext; TLS is terminated at the ALB). + +``` +gRPC client + │ :9090 (dedicated ALB HTTPS listener, backend-protocol-version GRPC) + ▼ +K8s Service "d-{scope}-{deploy}-grpc-9090" port: 9090, targetPort: 19090 + │ + ▼ +Sidecar container "grpc-9090" listens on 19090, http2 on + │ grpc_pass grpc://127.0.0.1:9090 + ▼ +Application container gRPC server binds 9090 (and 8080 for the main HTTP listener) +``` + +The ALB health check for a gRPC target group hits `/grpc.health.v1.Health/Check` and expects gRPC status `0`, so the application must implement the standard gRPC health service. The sidecar's three kubelet probes use the native `grpc:` probe against `port + 10000`, which nginx forwards to the application — so they check the pair end to end. ### Summary | | HTTP additional port | GRPC additional port | |---|---|---| -| App binds the port | yes, directly | no (sidecar binds it) | -| Sidecar internal port | `port + 10000` | `port` | +| App binds the port | yes, directly | yes, directly | +| Sidecar internal port | `port + 10000` | `port + 10000` | | Service `port` (external) | `port` | `port` | -| Service `targetPort` | `port + 10000` (sidecar) | `port` (sidecar) | -| Sidecar `UPSTREAM_PORT` | `port` (the app's same port) | `main_http_port` (default in image) | -| Protocol translation | none | gRPC → HTTP | -| Max valid `port` | 55535 | 65535 | +| Service `targetPort` | `port + 10000` (sidecar) | `port + 10000` (sidecar) | +| Sidecar `UPSTREAM_PORT` | `port` | `port` | +| nginx directive | `proxy_pass http://` | `grpc_pass grpc://` | +| App protocol on `port` | HTTP/1.1 | gRPC (h2c) | +| Max valid `port` | 55535 | 55535 | ## ALB capacity and listener lifecycle @@ -188,6 +209,23 @@ This means deleting a deployment (which deletes its Ingresses) is sufficient to - The `traffic-manager` image's `start.sh` defaults `UPSTREAM_PORT` to `8080` when the env is not provided, so an upgraded image with un-upgraded scope templates continues to behave like the old image. - Adding `HTTP` to the `additional_ports.type` enum is strictly additive — existing entries with `"GRPC"` remain valid. +### Moving GRPC sidecars to `port + 10000` + +GRPC additional ports used to give the declared port to the *sidecar*, leaving the application unable to bind it. That was masked for a long time: traffic-manager images built before [`1e2b2f8`](https://github.com/nullplatform/k8s-tools/commit/1e2b2f82bbb9614bed076e1714ac12b4e5d0ec39) ignored `LISTENER_PORT` and fell back to port 80, where the sidecar collided with the main `http` sidecar and nginx exited. Because `start.sh` never checks nginx's exit code, the container stayed `Running` with no proxy inside it and traffic went straight from the `Service` to the application. Upgrading the image made the sidecar actually claim the port, and applications started failing with `address already in use`. + +Aligning GRPC with the `port + 10000` convention restores what those applications were already doing — binding the port they declared — and puts a working sidecar in front of them for the first time. + +**Minimum image: traffic-manager `1.7.0`.** The sidecar only binds `port + 10000` on an image that honours `LISTENER_PORT`, and the gRPC nginx config shipped an invalid buffer combination (`proxy_busy_buffers_size 8m` against `proxy_buffers 8 1m`, which violates nginx's `busy < (N-1) × buffer_size`) until [`5430906`](https://github.com/nullplatform/k8s-tools/commit/5430906) landed in `1.7.0`. On an older image nginx exits with `[emerg]` and never listens — and because `start.sh` does not check nginx's exit code, the container stays `Running` with no proxy inside it, so the only symptom is `Startup probe failed: ... failed to connect service`. + +Note that `TRAFFIC_CONTAINER_VERSION` still defaults to `latest`, which is not a released tag. Scopes with gRPC additional ports should pin `traffic_container_image` explicitly. + +Two more cases need attention when rolling this out: + +- **Applications that moved their gRPC server to `main_http_port`** to work around the collision must move it back to the declared port. This is the only breaking case, and it can only exist on scopes already running a `LISTENER_PORT`-aware image. +- **gRPC ports above 55535** are no longer valid, because the sidecar's `port + 10000` would overflow the TCP range. `build_context` now rejects them at deploy time instead of rendering an nginx config that cannot start. + +The platform cannot detect either case automatically — it has no way to know which port an application binds — so there is no pre-flight check for them. + ## Implementation Map - JSON Schema and UI Schema: `k8s/specs/service-spec.json.tpl` @@ -195,14 +233,17 @@ This means deleting a deployment (which deletes its Ingresses) is sufficient to - Templates that consume `main_http_port`: `k8s/deployment/templates/{service,deployment,initial-ingress,blue-green-ingress}.yaml.tpl` and `k8s/deployment/templates/istio/*.tpl` - `main_traffic_manager_port` resolution and validation: `k8s/deployment/build_context` (look for `MAIN_TRAFFIC_MANAGER_PORT`) - Templates that consume `main_traffic_manager_port`: `k8s/deployment/templates/{deployment,service}.yaml.tpl`, `k8s/deployment/templates/istio/service.yaml.tpl`, and `k8s/deployment/templates/aro/{initial,blue-green}-httproute.yaml.tpl` -- HTTP additional_ports sidecar: `k8s/deployment/templates/deployment.yaml.tpl` (look for `else if eq .type "HTTP"`) -- traffic-manager image: `nullplatform/k8s-tools/traffic-manager` — `UPSTREAM_PORT` and `LISTENER_PORT` envs handled in `start.sh` +- additional_ports sidecars (both types): `k8s/deployment/templates/deployment.yaml.tpl` (look for `eq .type "GRPC"` and `else if eq .type "HTTP"`) +- `traffic_manager_port` derivation and the 55535 ceiling: `k8s/deployment/build_context` (look for `traffic_manager_port`) +- traffic-manager image: `nullplatform/k8s-tools/traffic-manager` — `UPSTREAM_PORT` and `LISTENER_PORT` envs handled in `start.sh`; the gRPC nginx config is `configuration/default.conf.tpl.grpc` ## Tests - `k8s/deployment/tests/build_context.bats` covers `main_http_port` extraction with present, absent, and `null` cases, and verifies the `tonumber` cast. - `k8s/deployment/tests/build_context.bats` also covers `main_traffic_manager_port` resolution: the provider precedence order, the env-var override, and the numeric, range and port-collision rejections. - `k8s/deployment/tests/traffic_manager_port_shape.bats` pins the main sidecar's `containerPort`, its `LISTENER_PORT` env var, its three probes and every `targetPort` to the same value, so they cannot drift apart — a drift would leave the pod reporting `Ready` while traffic never reaches it. +- `k8s/deployment/tests/build_context.bats` also covers the additional-port ceiling: a port whose `+ 10000` sidecar would exceed 65535 is rejected for both types, and 55535 is accepted as the boundary. +- `k8s/deployment/tests/grpc_port_shape.bats` pins the GRPC sidecar to `traffic_manager_port` and renders the templates with real gomplate to assert the full triple — sidecar on `port + 10000`, `UPSTREAM_PORT` on `port`, `Service.targetPort` on `port + 10000` — plus that the application container declares the port it binds. - `k8s/deployment/tests/ingress_template_shape.bats` verifies the per-port HTTPS listener annotation on each ingress branch and pins the absence of `ssl-redirect` on additional-port ingresses. - `k8s/deployment/tests/verify_ingress_reconciliation.bats` covers the weight-dedupe behavior introduced because a shared ALB listener used to surface multiple matching rules (the multi-rule scenario is no longer reachable now that each additional port has its own listener, but the dedupe is kept defensively). - `k8s/deployment/tests/validate_alb_target_group_capacity.bats` covers both target-group capacity and the listener-capacity validation (`ALB_MAX_LISTENERS`). diff --git a/k8s/log/build_context b/k8s/log/build_context index a1a7697e..e73d79e7 100755 --- a/k8s/log/build_context +++ b/k8s/log/build_context @@ -3,6 +3,7 @@ export SCOPE_ID=$(echo "$NP_ACTION_CONTEXT" | jq -r '.notification.arguments.scope_id // empty') export NEXT_PAGE_TOKEN=$(echo "$NP_ACTION_CONTEXT" | jq -r '.notification.arguments.next_page_token // empty') export START_TIME=$(echo "$NP_ACTION_CONTEXT" | jq -r '.notification.arguments.start_time // empty') +export END_TIME=$(echo "$NP_ACTION_CONTEXT" | jq -r '.notification.arguments.end_time // empty') export APPLICATION_ID=$(echo "$NP_ACTION_CONTEXT" | jq -r '.notification.arguments.application_id // empty') export DEPLOYMENT_ID=$(echo "$NP_ACTION_CONTEXT" | jq -r '.notification.arguments.deployment_id // .notification.arguments.deploy_id // empty') export FILTER_PATTERN=$(echo "$NP_ACTION_CONTEXT" | jq -r '.notification.arguments.filter_pattern // empty') diff --git a/k8s/log/kube-logger-go/bin/linux/exec-amd64 b/k8s/log/kube-logger-go/bin/linux/exec-amd64 index 21a4dd3e..8de72b2e 100755 Binary files a/k8s/log/kube-logger-go/bin/linux/exec-amd64 and b/k8s/log/kube-logger-go/bin/linux/exec-amd64 differ diff --git a/k8s/log/kube-logger-go/bin/linux/exec-arm64 b/k8s/log/kube-logger-go/bin/linux/exec-arm64 index 5e1ead90..08f60254 100755 Binary files a/k8s/log/kube-logger-go/bin/linux/exec-arm64 and b/k8s/log/kube-logger-go/bin/linux/exec-arm64 differ diff --git a/k8s/log/kube-logger-go/bin/linux/exec-x86_64 b/k8s/log/kube-logger-go/bin/linux/exec-x86_64 index 21a4dd3e..8de72b2e 100755 Binary files a/k8s/log/kube-logger-go/bin/linux/exec-x86_64 and b/k8s/log/kube-logger-go/bin/linux/exec-x86_64 differ diff --git a/k8s/log/kube-logger-go/cmd/main.go b/k8s/log/kube-logger-go/cmd/main.go index 6fea1ec6..307dccb2 100644 --- a/k8s/log/kube-logger-go/cmd/main.go +++ b/k8s/log/kube-logger-go/cmd/main.go @@ -4,7 +4,6 @@ import ( "encoding/json" "fmt" "os" - "sort" corev1 "k8s.io/api/core/v1" @@ -24,6 +23,13 @@ func main() { os.Exit(1) } + for flagName, bound := range map[string]string{"start-time": cfg.StartTime, "end-time": cfg.EndTime} { + if bound != "" && !logs.ValidTimestamp(bound) { + fmt.Fprintf(os.Stderr, "Error: %s must be RFC3339, e.g. 2026-08-17T23:59:59Z (got %q)\n", flagName, bound) + os.Exit(1) + } + } + // Create Kubernetes client clientset, err := kubernetes.NewClient() if err != nil { @@ -62,21 +68,7 @@ func main() { fetcher := logs.NewFetcher(clientset) allLogs := fetcher.FetchConcurrently(pods, cfg) - // Sort logs by datetime - sort.Slice(allLogs, func(i, j int) bool { - return allLogs[i].DateTime < allLogs[j].DateTime - }) - - // Limit results - if len(allLogs) > cfg.Limit { - allLogs = allLogs[:cfg.Limit] - } - if len(allLogs) == 0 { - allLogs = []types.LogEntry{} - } - - // Generate next page token - token := pagination.GenerateToken(allLogs) + allLogs, token := pagination.Page(allLogs, cfg.Limit, pagination.DecodeToken(cfg.NextPageToken)) response := types.Response{ Results: allLogs, diff --git a/k8s/log/kube-logger-go/go.mod b/k8s/log/kube-logger-go/go.mod index a767988a..548a6200 100644 --- a/k8s/log/kube-logger-go/go.mod +++ b/k8s/log/kube-logger-go/go.mod @@ -1,6 +1,6 @@ module kube-logger-go -go 1.25.5 +go 1.25.13 require ( k8s.io/api v0.35.0 @@ -28,11 +28,11 @@ require ( github.com/x448/float16 v0.8.4 // indirect go.yaml.in/yaml/v2 v2.4.3 // indirect go.yaml.in/yaml/v3 v3.0.4 // indirect - golang.org/x/net v0.47.0 // indirect + golang.org/x/net v0.56.0 // indirect golang.org/x/oauth2 v0.30.0 // indirect - golang.org/x/sys v0.38.0 // indirect - golang.org/x/term v0.37.0 // indirect - golang.org/x/text v0.31.0 // indirect + golang.org/x/sys v0.46.0 // indirect + golang.org/x/term v0.44.0 // indirect + golang.org/x/text v0.39.0 // indirect golang.org/x/time v0.9.0 // indirect google.golang.org/protobuf v1.36.8 // indirect gopkg.in/evanphx/json-patch.v4 v4.13.0 // indirect diff --git a/k8s/log/kube-logger-go/go.sum b/k8s/log/kube-logger-go/go.sum index b5f9dbe2..3622ca2d 100644 --- a/k8s/log/kube-logger-go/go.sum +++ b/k8s/log/kube-logger-go/go.sum @@ -77,24 +77,24 @@ go.yaml.in/yaml/v2 v2.4.3 h1:6gvOSjQoTB3vt1l+CU+tSyi/HOjfOjRLJ4YwYZGwRO0= go.yaml.in/yaml/v2 v2.4.3/go.mod h1:zSxWcmIDjOzPXpjlTTbAsKokqkDNAVtZO0WOMiT90s8= go.yaml.in/yaml/v3 v3.0.4 h1:tfq32ie2Jv2UxXFdLJdh3jXuOzWiL1fo0bu/FbuKpbc= go.yaml.in/yaml/v3 v3.0.4/go.mod h1:DhzuOOF2ATzADvBadXxruRBLzYTpT36CKvDb3+aBEFg= -golang.org/x/mod v0.29.0 h1:HV8lRxZC4l2cr3Zq1LvtOsi/ThTgWnUk/y64QSs8GwA= -golang.org/x/mod v0.29.0/go.mod h1:NyhrlYXJ2H4eJiRy/WDBO6HMqZQ6q9nk4JzS3NuCK+w= -golang.org/x/net v0.47.0 h1:Mx+4dIFzqraBXUugkia1OOvlD6LemFo1ALMHjrXDOhY= -golang.org/x/net v0.47.0/go.mod h1:/jNxtkgq5yWUGYkaZGqo27cfGZ1c5Nen03aYrrKpVRU= +golang.org/x/mod v0.37.0 h1:vF1DjpVEshcIqoEaauuHebaLk1O1forxjxBaVn884JQ= +golang.org/x/mod v0.37.0/go.mod h1:m8S8VeM9r4dzDwjrKO0a1sZP3YjeMamRRlD+fmR2Q/0= +golang.org/x/net v0.56.0 h1:Rw8j/hFzGvJUZwNBXnAtf5sVDVt+65SK2C7IxCxZt5o= +golang.org/x/net v0.56.0/go.mod h1:D3Ku6r+V6JROoZK144D2XfMHFcMq/0zSfLelVTCFKec= golang.org/x/oauth2 v0.30.0 h1:dnDm7JmhM45NNpd8FDDeLhK6FwqbOf4MLCM9zb1BOHI= golang.org/x/oauth2 v0.30.0/go.mod h1:B++QgG3ZKulg6sRPGD/mqlHQs5rB3Ml9erfeDY7xKlU= -golang.org/x/sync v0.18.0 h1:kr88TuHDroi+UVf+0hZnirlk8o8T+4MrK6mr60WkH/I= -golang.org/x/sync v0.18.0/go.mod h1:9KTHXmSnoGruLpwFjVSX0lNNA75CykiMECbovNTZqGI= -golang.org/x/sys v0.38.0 h1:3yZWxaJjBmCWXqhN1qh02AkOnCQ1poK6oF+a7xWL6Gc= -golang.org/x/sys v0.38.0/go.mod h1:OgkHotnGiDImocRcuBABYBEXf8A9a87e/uXjp9XT3ks= -golang.org/x/term v0.37.0 h1:8EGAD0qCmHYZg6J17DvsMy9/wJ7/D/4pV/wfnld5lTU= -golang.org/x/term v0.37.0/go.mod h1:5pB4lxRNYYVZuTLmy8oR2BH8dflOR+IbTYFD8fi3254= -golang.org/x/text v0.31.0 h1:aC8ghyu4JhP8VojJ2lEHBnochRno1sgL6nEi9WGFGMM= -golang.org/x/text v0.31.0/go.mod h1:tKRAlv61yKIjGGHX/4tP1LTbc13YSec1pxVEWXzfoeM= +golang.org/x/sync v0.21.0 h1:HLII4xRRTtCRkxYp4HNFF0Js/Og6q2i++KXbg0gHCwM= +golang.org/x/sync v0.21.0/go.mod h1:9xrNwdLfx4jkKbNva9FpL6vEN7evnE43NNNJQ2LF3+0= +golang.org/x/sys v0.46.0 h1:noSf2Fq6F8DBgS+LysIkx7rIExoNHJsxOAtPp4rthXw= +golang.org/x/sys v0.46.0/go.mod h1:4GL1E5IUh+htKOUEOaiffhrAeqysfVGipDYzABqnCmw= +golang.org/x/term v0.44.0 h1:0rLvDRCtNj0gZkyIXhCyOb2OAzEhLVqc4B+hrsBhrmc= +golang.org/x/term v0.44.0/go.mod h1:7ze4MdzUzLXpSAoFP1H0bOI9aXDqveSvatT5vKcFh2Y= +golang.org/x/text v0.39.0 h1:UbZz4pLOvn600D6Oh6GGEI6VAmndrEBLv8/6BEXzyus= +golang.org/x/text v0.39.0/go.mod h1:3UwRclnC2g0TU9x8PZiyfOajCd1zaUNHF9cvqcQZ+ZM= golang.org/x/time v0.9.0 h1:EsRrnYcQiGH+5FfbgvV4AP7qEZstoyrHB0DzarOQ4ZY= golang.org/x/time v0.9.0/go.mod h1:3BpzKBy/shNhVucY/MWOyx10tF3SFh9QdLuxbVysPQM= -golang.org/x/tools v0.38.0 h1:Hx2Xv8hISq8Lm16jvBZ2VQf+RLmbd7wVUsALibYI/IQ= -golang.org/x/tools v0.38.0/go.mod h1:yEsQ/d/YK8cjh0L6rZlY8tgtlKiBNTL14pGDJPJpYQs= +golang.org/x/tools v0.47.0 h1:7Kn5x/d1svx/PzryTsqeoZN4TZwqeH5pGWjefhLi/1Q= +golang.org/x/tools v0.47.0/go.mod h1:dFHnyTvFWY212G+h7ZY4Vsp/K3U4/7W9TyVaAul8uCA= google.golang.org/protobuf v1.36.8 h1:xHScyCOEuuwZEc6UtSOvPbAT4zRh0xcNRYekJwfqyMc= google.golang.org/protobuf v1.36.8/go.mod h1:fuxRtAxBytpl4zzqUh6/eyUujkJdNiuEkXntxiD/uRU= gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0= diff --git a/k8s/log/kube-logger-go/internal/config/config.go b/k8s/log/kube-logger-go/internal/config/config.go index 747731d3..a48844f2 100644 --- a/k8s/log/kube-logger-go/internal/config/config.go +++ b/k8s/log/kube-logger-go/internal/config/config.go @@ -19,6 +19,7 @@ func ParseFlags() types.Config { flag.StringVar(&config.NextPageToken, "next-page-token", "", "Pagination token") flag.StringVar(&config.FilterPattern, "filter", "", "Filter pattern") flag.StringVar(&config.StartTime, "start-time", "", "Start time (ISO format)") + flag.StringVar(&config.EndTime, "end-time", "", "End time (ISO format)") flag.StringVar(&config.InstanceID, "instance-id", "", "Instance ID") // Short flags diff --git a/k8s/log/kube-logger-go/internal/logs/fetcher.go b/k8s/log/kube-logger-go/internal/logs/fetcher.go index 576aaffa..f42ecac2 100644 --- a/k8s/log/kube-logger-go/internal/logs/fetcher.go +++ b/k8s/log/kube-logger-go/internal/logs/fetcher.go @@ -57,15 +57,18 @@ func (f *Fetcher) FetchConcurrently(pods []corev1.Pod, config types.Config) []ty // Determine since time for this pod sinceTime := determineSinceTime(podUID, lastReadTimes, config.StartTime) - // Get pod logs + // Cancelling releases the producer when the processor stops at the end of the window. + ctx, cancel := context.WithCancel(context.Background()) + defer cancel() + logCh := make(chan string, 100) go func() { defer close(logCh) - f.streamPodLogs(&p, config.Namespace, sinceTime, int64(podLimit*3072), logCh) + f.streamPodLogs(ctx, &p, config.Namespace, sinceTime, int64(podLimit*3072), logCh) }() processor := NewProcessor() - processedLogs := processor.ProcessLinesFromChannel(logCh, config.FilterPattern, p.Name, podUID, getLastReadTime(podUID, lastReadTimes)) + processedLogs := processor.ProcessLinesFromChannel(logCh, config.FilterPattern, p.Name, podUID, getLastReadTime(podUID, lastReadTimes), config.EndTime) if len(processedLogs) > 0 { mu.Lock() @@ -114,8 +117,7 @@ func (f *Fetcher) getPodLogs(pod *corev1.Pod, namespace, sinceTime string, limit return logContent.String() } -func (f *Fetcher) streamPodLogs(pod *corev1.Pod, namespace, sinceTime string, limitBytes int64, logCh chan<- string) { - ctx := context.Background() +func (f *Fetcher) streamPodLogs(ctx context.Context, pod *corev1.Pod, namespace, sinceTime string, limitBytes int64, logCh chan<- string) { opts := &corev1.PodLogOptions{ Container: types.DefaultContainerName, Timestamps: true, @@ -136,7 +138,11 @@ func (f *Fetcher) streamPodLogs(pod *corev1.Pod, namespace, sinceTime string, li scanner := bufio.NewScanner(podLogs) for scanner.Scan() { - logCh <- scanner.Text() + select { + case logCh <- scanner.Text(): + case <-ctx.Done(): + return + } } } diff --git a/k8s/log/kube-logger-go/internal/logs/pagination_test.go b/k8s/log/kube-logger-go/internal/logs/pagination_test.go new file mode 100644 index 00000000..31ba0586 --- /dev/null +++ b/k8s/log/kube-logger-go/internal/logs/pagination_test.go @@ -0,0 +1,125 @@ +package logs + +import ( + "strings" + "testing" + "time" + + "kube-logger-go/internal/pagination" + "kube-logger-go/internal/types" +) + +// podLogs stands in for the Kubernetes API: chronological lines, bounded from below only. +type podLogs map[string][]string + +func (l podLogs) stream(t *testing.T, podUID, sinceTime string) <-chan string { + t.Helper() + + lines := l[podUID] + ch := make(chan string, len(lines)) + since := mustParse(t, sinceTime) + + for _, line := range lines { + if at := mustParse(t, strings.SplitN(line, " ", 2)[0]); !at.Before(since) { + ch <- line + } + } + close(ch) + + return ch +} + +func mustParse(t *testing.T, timestamp string) time.Time { + t.Helper() + + if timestamp == "" { + return time.Time{} + } + at, err := time.Parse(time.RFC3339Nano, timestamp) + if err != nil { + t.Fatalf("test data has a non-RFC3339 timestamp %q: %v", timestamp, err) + } + + return at +} + +// fetchPage mirrors what cmd/main.go does for one request. +func fetchPage(t *testing.T, store podLogs, podUIDs []string, cfg types.Config) ([]types.LogEntry, string) { + t.Helper() + + cursors := pagination.DecodeToken(cfg.NextPageToken) + processor := NewProcessor() + + var collected []types.LogEntry + for _, podUID := range podUIDs { + sinceTime := determineSinceTime(podUID, cursors, cfg.StartTime) + collected = append(collected, processor.ProcessLinesFromChannel( + store.stream(t, podUID, sinceTime), + cfg.FilterPattern, + "pod-"+podUID, + podUID, + getLastReadTime(podUID, cursors), + cfg.EndTime, + )...) + } + + return pagination.Page(collected, cfg.Limit, cursors) +} + +// A pod that loses its cursor restarts from start_time, and with more than one pod the +// pages take turns evicting each other and never reach the end of the window. Pod c has no +// lines in the window at all, so it never earns a cursor and is re-read on every page. +func TestPaginationDeliversEveryLineInTheWindowExactlyOnce(t *testing.T) { + store := podLogs{ + "a": { + "2026-08-17T10:00:01.000000000Z a first", + "2026-08-17T10:00:03.000000000Z a second", + "2026-08-17T10:00:05.000000000Z a third", + }, + "b": { + "2026-08-17T10:00:02.000000000Z b first", + "2026-08-17T10:00:04.000000000Z b second", + }, + "c": { + "2026-08-18T09:00:00.000000000Z c past the window", + }, + } + cfg := types.Config{ + Limit: 2, + StartTime: "2026-08-17T10:00:00Z", + EndTime: "2026-08-17T10:00:59Z", + } + + delivered := map[string]int{} + token := "" + + for page := 1; ; page++ { + if page > 10 { + t.Fatalf("pagination did not terminate after 10 pages, delivered: %v", delivered) + } + + cfg.NextPageToken = token + entries, next := fetchPage(t, store, []string{"a", "b", "c"}, cfg) + + for i, entry := range entries { + if i > 0 && entries[i-1].DateTime > entry.DateTime { + t.Errorf("page %d is out of order: %s before %s", page, entries[i-1].DateTime, entry.DateTime) + } + delivered[entry.Message]++ + } + + if next == "" { + break + } + token = next + } + + for _, message := range []string{"a first", "a second", "a third", "b first", "b second"} { + if delivered[message] != 1 { + t.Errorf("expected %q delivered exactly once, got %d", message, delivered[message]) + } + } + if delivered["c past the window"] != 0 { + t.Errorf("a line past end_time was delivered %d times", delivered["c past the window"]) + } +} diff --git a/k8s/log/kube-logger-go/internal/logs/processor.go b/k8s/log/kube-logger-go/internal/logs/processor.go index 73ebdb8d..88a2a635 100644 --- a/k8s/log/kube-logger-go/internal/logs/processor.go +++ b/k8s/log/kube-logger-go/internal/logs/processor.go @@ -16,8 +16,9 @@ func NewProcessor() *Processor { return &Processor{} } -// ProcessLinesFromChannel processes log lines received from a channel and returns structured log entries -func (p *Processor) ProcessLinesFromChannel(logCh <-chan string, filterPattern, podName, podUID, lastReadTime string) []types.LogEntry { +// ProcessLinesFromChannel processes log lines received from a channel and returns structured log entries. +// endTime is applied here because the Kubernetes API only accepts a lower bound (SinceTime). +func (p *Processor) ProcessLinesFromChannel(logCh <-chan string, filterPattern, podName, podUID, lastReadTime, endTime string) []types.LogEntry { var entries []types.LogEntry var terms []string @@ -48,6 +49,11 @@ func (p *Processor) ProcessLinesFromChannel(logCh <-chan string, filterPattern, } } + // The stream is chronological, so the first line past the window ends it. + if endTime != "" && timestamp > endTime { + break + } + if len(terms) > 0 { matches := true for _, term := range terms { @@ -144,6 +150,11 @@ func (p *Processor) ProcessLines(logs, filterPattern, podName, podUID, lastReadT // isValidTimestamp checks if a timestamp string is in a valid format func (p *Processor) isValidTimestamp(timestamp string) bool { + return ValidTimestamp(timestamp) +} + +// ValidTimestamp reports whether a string is an RFC3339 timestamp. +func ValidTimestamp(timestamp string) bool { // Check RFC3339 format (e.g., 2025-09-04T15:24:34.944759409Z) _, err := time.Parse(time.RFC3339Nano, timestamp) if err != nil { diff --git a/k8s/log/kube-logger-go/internal/logs/processor_test.go b/k8s/log/kube-logger-go/internal/logs/processor_test.go new file mode 100644 index 00000000..06ea6c79 --- /dev/null +++ b/k8s/log/kube-logger-go/internal/logs/processor_test.go @@ -0,0 +1,100 @@ +package logs + +import "testing" + +// A bound that is not RFC3339 compares below every timestamp, leaving the window unbounded. +func TestValidTimestamp(t *testing.T) { + valid := []string{ + "2026-08-17T23:59:59Z", + "2026-08-17T10:00:00.000000000Z", + "2026-08-17T10:00:00+02:00", + } + for _, timestamp := range valid { + if !ValidTimestamp(timestamp) { + t.Errorf("expected %q to be accepted", timestamp) + } + } + + invalid := []string{"", "garbage", "1786924800000", "2026-08-17", "17/08/2026"} + for _, timestamp := range invalid { + if ValidTimestamp(timestamp) { + t.Errorf("expected %q to be rejected", timestamp) + } + } +} + +func linesChannel(lines ...string) <-chan string { + ch := make(chan string, len(lines)) + for _, line := range lines { + ch <- line + } + close(ch) + return ch +} + +// The Kubernetes API only bounds reads from below, so the upper bound is applied here. +func TestProcessLinesFromChannelAppliesEndTime(t *testing.T) { + lines := []string{ + "2026-08-17T10:00:00.000000000Z inside the window", + "2026-08-18T09:00:00.000000000Z after the window", + } + + entries := NewProcessor().ProcessLinesFromChannel( + linesChannel(lines...), "", "pod-a", "uid-a", "", "2026-08-17T23:59:59Z", + ) + + if len(entries) != 1 { + t.Fatalf("expected 1 entry within the window, got %d", len(entries)) + } + if entries[0].Message != "inside the window" { + t.Errorf("unexpected entry retained: %q", entries[0].Message) + } +} + +// Leftovers in the channel are what distinguishes stopping from filtering to the end. +func TestProcessLinesFromChannelStopsReadingPastEndTime(t *testing.T) { + ch := make(chan string, 10) + ch <- "2026-08-17T10:00:00.000000000Z inside the window" + ch <- "2026-08-18T09:00:00.000000000Z first line past the window" + ch <- "2026-08-18T10:00:00.000000000Z should never be read" + close(ch) + + entries := NewProcessor().ProcessLinesFromChannel(ch, "", "pod-a", "uid-a", "", "2026-08-17T23:59:59Z") + + if len(entries) != 1 { + t.Fatalf("expected 1 entry within the window, got %d", len(entries)) + } + if len(ch) != 1 { + t.Errorf("expected the processor to stop at the first out-of-window line, leaving 1 unread; %d left", len(ch)) + } +} + +// A filtered-out line must not be mistaken for the end of the window. +func TestProcessLinesFromChannelKeepsReadingThroughFilteredLines(t *testing.T) { + ch := make(chan string, 10) + ch <- "2026-08-17T10:00:00.000000000Z keep me" + ch <- "2026-08-17T11:00:00.000000000Z drop me" + ch <- "2026-08-17T12:00:00.000000000Z keep me too" + close(ch) + + entries := NewProcessor().ProcessLinesFromChannel(ch, "keep", "pod-a", "uid-a", "", "2026-08-17T23:59:59Z") + + if len(entries) != 2 { + t.Fatalf("expected both matching entries, got %d", len(entries)) + } +} + +func TestProcessLinesFromChannelWithoutEndTimeKeepsEverything(t *testing.T) { + lines := []string{ + "2026-08-17T10:00:00.000000000Z first", + "2026-08-18T09:00:00.000000000Z second", + } + + entries := NewProcessor().ProcessLinesFromChannel( + linesChannel(lines...), "", "pod-a", "uid-a", "", "", + ) + + if len(entries) != 2 { + t.Fatalf("expected both entries when no upper bound is set, got %d", len(entries)) + } +} diff --git a/k8s/log/kube-logger-go/internal/pagination/token.go b/k8s/log/kube-logger-go/internal/pagination/token.go index a5d99b34..623f515d 100644 --- a/k8s/log/kube-logger-go/internal/pagination/token.go +++ b/k8s/log/kube-logger-go/internal/pagination/token.go @@ -3,6 +3,7 @@ package pagination import ( "encoding/base64" "encoding/json" + "sort" "kube-logger-go/internal/types" ) @@ -40,16 +41,38 @@ func encodeToken(data map[string]string) string { return base64.StdEncoding.EncodeToString(jsonData) } -// GenerateToken creates a pagination token from log entries -func GenerateToken(logs []types.LogEntry) string { +// Page orders the entries, cuts them to the limit and returns the token that resumes after +// the cut. The token records the newest entry kept per pod, so the cut keeps the oldest. +func Page(entries []types.LogEntry, limit int, previous map[string]string) ([]types.LogEntry, string) { + sort.Slice(entries, func(i, j int) bool { + return entries[i].DateTime < entries[j].DateTime + }) + + if len(entries) > limit { + entries = entries[:limit] + } + if len(entries) == 0 { + entries = []types.LogEntry{} + } + + return entries, GenerateToken(entries, previous) +} + +// GenerateToken creates a pagination token from log entries. previous keeps the cursor of a +// pod that contributed nothing to this page, so the next page resumes it instead of reading +// it again from start_time. An empty page returns an empty token, which ends pagination. +func GenerateToken(logs []types.LogEntry, previous map[string]string) string { if len(logs) == 0 { return "" } - tokenData := make(map[string]string) + tokenData := make(map[string]string, len(previous)+len(logs)) + for podID, lastRead := range previous { + tokenData[podID] = lastRead + } for _, entry := range logs { tokenData[entry.Pod.ID] = entry.DateTime } return encodeToken(tokenData) -} \ No newline at end of file +} diff --git a/k8s/log/kube-logger-go/internal/pagination/token_test.go b/k8s/log/kube-logger-go/internal/pagination/token_test.go new file mode 100644 index 00000000..465db409 --- /dev/null +++ b/k8s/log/kube-logger-go/internal/pagination/token_test.go @@ -0,0 +1,92 @@ +package pagination + +import ( + "testing" + + "kube-logger-go/internal/types" +) + +func entry(timestamp, podID string) types.LogEntry { + return types.LogEntry{ + Message: "line at " + timestamp, + DateTime: timestamp, + Pod: types.PodInfo{Name: "pod-" + podID, ID: podID}, + } +} + +// The token resumes where the cut landed, which only holds if the cut keeps the oldest. +func TestPageKeepsTheOldestEntriesAndTokensTheCut(t *testing.T) { + entries := []types.LogEntry{ + entry("2026-08-17T10:00:03Z", "a"), + entry("2026-08-17T10:00:01Z", "a"), + entry("2026-08-17T10:00:04Z", "b"), + entry("2026-08-17T10:00:02Z", "b"), + } + + page, token := Page(entries, 2, map[string]string{}) + + if len(page) != 2 { + t.Fatalf("expected the page to be cut to the limit, got %d entries", len(page)) + } + if page[0].DateTime != "2026-08-17T10:00:01Z" || page[1].DateTime != "2026-08-17T10:00:02Z" { + t.Errorf("expected the two oldest entries, got %s and %s", page[0].DateTime, page[1].DateTime) + } + + cursors := DecodeToken(token) + if cursors["a"] != "2026-08-17T10:00:01Z" || cursors["b"] != "2026-08-17T10:00:02Z" { + t.Errorf("token does not point at the cut: %v", cursors) + } +} + +// Dropping the cursor of a pod that contributed nothing makes the next page re-read it. +func TestPageCarriesForwardPodsThatContributedNothing(t *testing.T) { + incoming := map[string]string{ + "a": "2026-08-17T10:00:01Z", + "b": "2026-08-17T10:00:02Z", + } + + _, token := Page([]types.LogEntry{entry("2026-08-17T10:00:05Z", "a")}, 100, incoming) + + cursors := DecodeToken(token) + if cursors["a"] != "2026-08-17T10:00:05Z" { + t.Errorf("expected pod a to advance to its newest kept entry, got %q", cursors["a"]) + } + if cursors["b"] != "2026-08-17T10:00:02Z" { + t.Errorf("expected pod b to keep its cursor, got %q", cursors["b"]) + } +} + +// An empty page ends pagination, so the cursors must not survive it. +func TestPageWithNoEntriesEndsPagination(t *testing.T) { + page, token := Page(nil, 100, map[string]string{"a": "2026-08-17T10:00:01Z"}) + + if page == nil { + t.Error("expected an empty slice rather than nil, it is serialized as results") + } + if len(page) != 0 { + t.Errorf("expected no entries, got %d", len(page)) + } + if token != "" { + t.Errorf("expected an empty token to end pagination, got %q", token) + } +} + +func TestTokenRoundTrip(t *testing.T) { + cursors := map[string]string{"a": "2026-08-17T10:00:01Z", "b": "2026-08-17T10:00:02.5Z"} + + decoded := DecodeToken(encodeToken(cursors)) + + for podID, want := range cursors { + if decoded[podID] != want { + t.Errorf("pod %s: expected %q, got %q", podID, want, decoded[podID]) + } + } +} + +func TestDecodeTokenToleratesGarbage(t *testing.T) { + for _, token := range []string{"", "not base64!", "bm90IGpzb24="} { + if cursors := DecodeToken(token); len(cursors) != 0 { + t.Errorf("token %q: expected no cursors, got %v", token, cursors) + } + } +} diff --git a/k8s/log/kube-logger-go/internal/types/types.go b/k8s/log/kube-logger-go/internal/types/types.go index 1aede49e..cf89e56e 100644 --- a/k8s/log/kube-logger-go/internal/types/types.go +++ b/k8s/log/kube-logger-go/internal/types/types.go @@ -35,5 +35,6 @@ type Config struct { NextPageToken string FilterPattern string StartTime string + EndTime string InstanceID string } \ No newline at end of file diff --git a/k8s/log/log b/k8s/log/log index e32aba89..59648610 100644 --- a/k8s/log/log +++ b/k8s/log/log @@ -41,34 +41,54 @@ if [ -n "$LIMIT" ]; then CMD="$CMD --limit $LIMIT" fi -# Add optional start time (convert from milliseconds to ISO format) -if [ -n "$START_TIME" ]; then - SECONDS=$(echo "$START_TIME/1000" | bc) - +# Convert an epoch-milliseconds value to ISO-8601 UTC. Fails rather than falling back to now. +epoch_ms_to_iso() { + # bc reads bare words as variables, so a non-numeric value would convert to 1970. + case "$1" in + ''|*[!0-9]*) + echo "Error: timestamp '$1' is not epoch milliseconds" >&2 + return 1 + ;; + esac + + # Not named SECONDS: bash keeps overwriting that one with elapsed time. + local epoch_seconds ISO_DATE + epoch_seconds=$(echo "$1/1000" | bc 2>/dev/null) + + if [ -z "$epoch_seconds" ]; then + echo "Error: could not convert timestamp '$1' (bc unavailable?)" >&2 + return 1 + fi + # Handle different date command versions for Alpine/busybox - # Try different approaches for Alpine busybox date - if ISO_DATE=$(date -u -d "@$SECONDS" +"%Y-%m-%dT%H:%M:%SZ" 2>/dev/null); then - # GNU date worked + if ISO_DATE=$(date -u -d "@$epoch_seconds" +"%Y-%m-%dT%H:%M:%SZ" 2>/dev/null); then : - elif ISO_DATE=$(date -u -r "$SECONDS" +"%Y-%m-%dT%H:%M:%SZ" 2>/dev/null); then - # BSD date worked + elif ISO_DATE=$(date -u -r "$epoch_seconds" +"%Y-%m-%dT%H:%M:%SZ" 2>/dev/null); then : else - # Alpine busybox date - manual conversion - # Use awk for the conversion since busybox date is limited - ISO_DATE=$(awk -v ts="$SECONDS" 'BEGIN { - # Manual epoch conversion - this is a simplified version - # For a more robust solution, we would need a full date calculation + ISO_DATE=$(awk -v ts="$epoch_seconds" 'BEGIN { print strftime("%Y-%m-%dT%H:%M:%SZ", ts) }' 2>/dev/null) - - # If awk strftime failed, use a different approach - if [ -z "$ISO_DATE" ] || [ "$ISO_DATE" = "" ]; then - ISO_DATE=$(date -u +"%Y-%m-%dT%H:%M:%SZ") - fi fi - - CMD="$CMD --start-time $ISO_DATE" + + if [ -z "$ISO_DATE" ]; then + echo "Error: no usable date conversion for timestamp '$1'" >&2 + return 1 + fi + + echo "$ISO_DATE" +} + +# Add optional start time (convert from milliseconds to ISO format) +if [ -n "$START_TIME" ]; then + START_ISO=$(epoch_ms_to_iso "$START_TIME") || exit 1 + CMD="$CMD --start-time $START_ISO" +fi + +# Add optional end time (convert from milliseconds to ISO format) +if [ -n "$END_TIME" ]; then + END_ISO=$(epoch_ms_to_iso "$END_TIME") || exit 1 + CMD="$CMD --end-time $END_ISO" fi eval "$CMD" diff --git a/k8s/log/tests/build_context.bats b/k8s/log/tests/build_context.bats new file mode 100644 index 00000000..9cecff97 --- /dev/null +++ b/k8s/log/tests/build_context.bats @@ -0,0 +1,69 @@ +#!/usr/bin/env bats +# ============================================================================= +# Unit tests for log/build_context +# Tests filter extraction from NP_ACTION_CONTEXT, including both ends of the time range +# ============================================================================= + +setup() { + export PROJECT_ROOT="$(cd "$BATS_TEST_DIRNAME/../../.." && pwd)" + source "$PROJECT_ROOT/testing/assertions.sh" + BUILD_CONTEXT="$PROJECT_ROOT/k8s/log/build_context" +} + +# Runs build_context with the given context and echoes one exported variable. +# build_context exits when APPLICATION_ID is missing, so it runs in a subshell. +extract() { + local context="$1" variable="$2" + NP_ACTION_CONTEXT="$context" bash -c "source '$BUILD_CONTEXT' >/dev/null 2>&1; echo \"\$$variable\"" +} + +full_context() { + echo '{"notification":{"arguments":{ + "application_id":"26611171", + "scope_id":"2075362883", + "limit":100, + "start_time":1786924800000, + "end_time":1787011199000 + }}}' +} + +# ============================================================================= +# Time range extraction +# ============================================================================= +@test "build_context: extracts both ends of the requested time range" { + run extract "$(full_context)" START_TIME + assert_equal "$output" "1786924800000" + + run extract "$(full_context)" END_TIME + assert_equal "$output" "1787011199000" +} + +@test "build_context: leaves END_TIME empty when the request has no upper bound" { + local context='{"notification":{"arguments":{"application_id":"26611171","start_time":1786924800000}}}' + + run extract "$context" END_TIME + assert_empty "$output" + + run extract "$context" START_TIME + assert_equal "$output" "1786924800000" +} + +# ============================================================================= +# Remaining filters +# ============================================================================= +@test "build_context: extracts the non-time filters" { + run extract "$(full_context)" APPLICATION_ID + assert_equal "$output" "26611171" + + run extract "$(full_context)" SCOPE_ID + assert_equal "$output" "2075362883" + + run extract "$(full_context)" LIMIT + assert_equal "$output" "100" +} + +@test "build_context: fails when application_id is missing" { + run bash -c "NP_ACTION_CONTEXT='{\"notification\":{\"arguments\":{}}}' source '$BUILD_CONTEXT'" + [ "$status" -ne 0 ] + assert_contains "$output" "Missing required parameters: APPLICATION_ID" +} diff --git a/k8s/log/tests/log.bats b/k8s/log/tests/log.bats new file mode 100644 index 00000000..c5bb156e --- /dev/null +++ b/k8s/log/tests/log.bats @@ -0,0 +1,88 @@ +#!/usr/bin/env bats +# ============================================================================= +# Unit tests for log/log +# Tests the epoch-to-ISO conversion and the flags handed to kube-logger, which is stubbed +# ============================================================================= + +setup() { + export PROJECT_ROOT="$(cd "$BATS_TEST_DIRNAME/../../.." && pwd)" + source "$PROJECT_ROOT/testing/assertions.sh" + LOG_SCRIPT="$PROJECT_ROOT/k8s/log/log" + + # Stand in for the kube-logger binary at the path the script derives + STUB_ROOT="$(mktemp -d)" + local platform arch + platform="$(uname | tr '[:upper:]' '[:lower:]')" + arch="$(uname -m)" + [ "$arch" = "aarch64" ] && arch="arm64" + mkdir -p "$STUB_ROOT/log/kube-logger-go/bin/$platform" + printf '#!/usr/bin/env bash\necho "$@"\n' > "$STUB_ROOT/log/kube-logger-go/bin/$platform/exec-$arch" + chmod +x "$STUB_ROOT/log/kube-logger-go/bin/$platform/exec-$arch" + + export SERVICE_PATH="$STUB_ROOT" + export APPLICATION_ID="26611171" + export SCOPE_ID="2075362883" + + # epoch_ms_to_iso is defined inside the script; extract it for isolated testing + eval "$(sed -n '/^epoch_ms_to_iso()/,/^}/p' "$LOG_SCRIPT")" +} + +teardown() { + unset -f epoch_ms_to_iso 2>/dev/null || true + unset SERVICE_PATH APPLICATION_ID SCOPE_ID START_TIME END_TIME 2>/dev/null || true + [ -n "$STUB_ROOT" ] && rm -rf "$STUB_ROOT" +} + +# ============================================================================= +# epoch_ms_to_iso +# ============================================================================= +@test "epoch_ms_to_iso: converts epoch milliseconds to ISO-8601 UTC" { + run epoch_ms_to_iso 1786924800000 + [ "$status" -eq 0 ] + assert_equal "$output" "2026-08-17T00:00:00Z" +} + +@test "epoch_ms_to_iso: rejects a non-numeric timestamp" { + # bc evaluates bare words to 0, which used to convert to 1970 instead of failing. + run epoch_ms_to_iso "not-a-timestamp" + [ "$status" -ne 0 ] + assert_contains "$output" "not epoch milliseconds" + [[ "$output" != *"1970-"* ]] +} + +@test "epoch_ms_to_iso: never answers with the current time" { + # A bound that cannot be converted must not silently become "now". + run epoch_ms_to_iso "" + [ "$status" -ne 0 ] + [[ "$output" != *"$(date -u +%Y-%m-%d)"* ]] +} + +# ============================================================================= +# Flags handed to kube-logger +# ============================================================================= +@test "log: passes both ends of the range to kube-logger" { + export START_TIME=1786924800000 + export END_TIME=1787011199000 + + run bash "$LOG_SCRIPT" + [ "$status" -eq 0 ] + assert_contains "$output" "--start-time 2026-08-17T00:00:00Z" + assert_contains "$output" "--end-time 2026-08-17T23:59:59Z" +} + +@test "log: omits --end-time when the request has no upper bound" { + export START_TIME=1786924800000 + + run bash "$LOG_SCRIPT" + [ "$status" -eq 0 ] + assert_contains "$output" "--start-time 2026-08-17T00:00:00Z" + [[ "$output" != *"--end-time"* ]] +} + +@test "log: fails when a supplied bound cannot be converted" { + export START_TIME="not-a-timestamp" + + run bash "$LOG_SCRIPT" + [ "$status" -ne 0 ] + [[ "$output" != *"--start-time"* ]] +} diff --git a/k8s/logging b/k8s/logging index d0df55d7..171c670d 100644 --- a/k8s/logging +++ b/k8s/logging @@ -38,4 +38,317 @@ 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" +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/specs/service-spec.json.tpl b/k8s/specs/service-spec.json.tpl index b0186186..60763b89 100644 --- a/k8s/specs/service-spec.json.tpl +++ b/k8s/specs/service-spec.json.tpl @@ -631,9 +631,9 @@ "port":{ "type":"integer", "title":"Port Number", - "maximum":65535, + "maximum":55535, "minimum":1024, - "description":"The port number to expose (1024-65535)" + "description":"The port number your application binds and the scope exposes (1024-55535). Its traffic-manager sidecar takes this port plus 10000." }, "type":{ "enum":[ 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/scheduled_task/logging b/scheduled_task/logging index d0df55d7..171c670d 100644 --- a/scheduled_task/logging +++ b/scheduled_task/logging @@ -38,4 +38,317 @@ 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" +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