diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index 39563eb..17f655f 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -49,12 +49,12 @@ jobs: - name: Start services run: docker compose up -d - # Ports now bind before the DB opens and answer 503 until it is ready, so - # we must wait on actual readiness (/healthz → 200), not just a bound port. - - name: Wait for readiness (max 60 s) - run: | - timeout 60 bash -c \ - 'until curl -sf -o /dev/null http://localhost:8080/healthz; do sleep 1; done' + # Ports bind before the DB opens and answer 503 until it is ready, so we + # must wait on actual readiness, not just a bound port. This runs the same + # gate as the deploy, so a break in it surfaces on a PR instead of on a + # deploy to production. + - name: Wait for healthy + run: scripts/wait-for-healthy.sh cotel 120 - name: POST sample OTLP payload run: | diff --git a/.github/workflows/deploy.yml b/.github/workflows/deploy.yml index d2d398c..a384e22 100644 --- a/.github/workflows/deploy.yml +++ b/.github/workflows/deploy.yml @@ -4,6 +4,11 @@ on: push: branches: [main] workflow_dispatch: + inputs: + health_timeout: + description: "Seconds to wait for the container to report healthy. Raise it for a deploy that has to replay a large WAL (i.e. one following a hard kill)." + required: false + default: "120" concurrency: group: deploy-main @@ -26,6 +31,17 @@ jobs: - name: Recreate container run: docker compose up -d --remove-orphans + # `up -d` returns once the container has started, not once it works, so + # without this the job reports success on a container that is still — or + # forever — `health: starting`. The script dumps container logs on failure. + - name: Wait for healthy + env: + # Via env, not inline `${{ }}`: a dispatch input expanded straight into + # the run script is a shell-injection sink, and this runner is the + # production host. + HEALTH_TIMEOUT: ${{ github.event.inputs.health_timeout || '120' }} + run: scripts/wait-for-healthy.sh cotel "$HEALTH_TIMEOUT" + - name: Show status run: docker compose ps diff --git a/CHANGELOG.md b/CHANGELOG.md index 2ddee28..c73910a 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -12,6 +12,8 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 - A failing `GET /api/v1/bash-commands` no longer renders as the "no command detail in this data" explainer. The Bash section branched on row count alone, so a request that errored looked identical to one that legitimately returned nothing, blaming Claude Code's telemetry for what was actually a server fault. Fetch failures now show the error ### Changed +- A deploy now fails when the container does not come up. The Deploy workflow ended at `docker compose up -d`, which returns once the container has *started*, not once it works — so the last thing it observed of a deploy was `Up Less than a second (health: starting)` and it went green on that, reporting a container whose `storage.Open` had died identically to one serving traffic. It now runs `scripts/wait-for-healthy.sh`, which blocks on the container's own `HEALTHCHECK` and fails the job on `unhealthy`, on an exit, on a crash loop (in under a second, rather than waiting out the timeout — only restarts seen *during* the wait indict a deploy, since `up -d` leaves an already-current container in place and one that crashed once and recovered carries a restart count for the rest of its life, including while it legitimately replays a WAL), on a service that defines no healthcheck at all, or on a 120 s timeout — dumping `docker compose ps`, the last health-probe output and the container logs so the reason is in the run log instead of on the runner. `workflow_dispatch` takes a `health_timeout` input for the one deploy that legitimately needs longer: a start following a hard kill replays the WAL. The CI smoke job runs the same script in place of its `curl`-until-ready loop, so a break in the gate surfaces on a PR rather than on a deploy. Measured against a 109 MB copy of production, healthy at 6 s from cold with a 3.9 MB WAL to replay (the open itself 2.8 s, including the v10 migration) and 6 s on a redeploy of the warm database — the 6 s is the probe cadence, not the database +- The image `HEALTHCHECK` gains `--start-interval=5s`. `--interval=30s` also governed the probes during `start-period`, so a container that was ready in two seconds still reported `starting` for thirty, and the deploy gate above would have waited out all of it - Schema version 10 removes `spans.duration_ms`. The migration moves no row data: it drops the four secondary indexes, drops the column (DuckDB refuses to `ALTER` a table an index depends on), and the existing `CREATE INDEX IF NOT EXISTS` block rebuilds them. On the 108 MB production copy the whole upgrade added 0.4 s to a cold start already dominated by WAL replay (9.5 s → 9.8 s), and a later re-apply of `schema.sql` costs 138 ms. No downgrade path: an older binary still starts against a v10 database (`CREATE TABLE IF NOT EXISTS` cannot bring the column back) but every query naming `duration_ms` then errors, so a rollback needs the pre-upgrade database too. Exported CSVs are unaffected — the `duration_ms` column of `spans.csv` was already derived in Go, so the format version does not move - Tools page is flat: the tools table sits directly on the page instead of inside an "All Tools" card. `DataTable` already draws its own bordered surface, so the card put a box inside a box for a heading the page title already gave. Matches the Users page - The Bash commands section no longer vanishes when it has no rows — it always renders and says why it is empty. Claude Code's tool spans carry `tool_name`, `tool_use_id` and `duration_ms` only: which tool ran, not what it ran. No `command` attribute is ever sent (verified against a captured live session, including the enhanced-telemetry beta), so this breakdown stays empty against Claude Code telemetry no matter what — the DuckDB filter-pushdown fix in 0.3.0 was a real bug fix but could not, on its own, put rows in this table. The endpoint is kept for OTLP producers that do send `command` diff --git a/Dockerfile b/Dockerfile index 9ff5df4..e0496ff 100644 --- a/Dockerfile +++ b/Dockerfile @@ -67,8 +67,9 @@ ENV COTEL_DB_PATH=/data/cotel.duckdb \ # The binary self-probes /healthz, so no curl/wget is needed in the runtime # image. start-period must stay well above the worst-case storage.Open on a # large DB, or the container flaps to "unhealthy" while it is legitimately -# still opening. -HEALTHCHECK --interval=30s --timeout=5s --start-period=10m --retries=3 \ +# still opening; start-interval keeps the deploy gate from waiting a full +# interval past a start that was actually quick. +HEALTHCHECK --interval=30s --start-interval=5s --timeout=5s --start-period=10m --retries=3 \ CMD ["/usr/local/bin/cotel", "-healthcheck"] ENTRYPOINT ["/usr/local/bin/entrypoint.sh"] diff --git a/README.md b/README.md index 519386e..dd462c9 100644 --- a/README.md +++ b/README.md @@ -226,6 +226,49 @@ rather than a misleading healthy state while ingest is still dark; it flips to docker inspect --format '{{.State.Health.Status}}' cotel # starting → healthy ``` +### The deploy waits for healthy + +`docker compose up -d` returns as soon as the container has *started*, which is +not the same as working: a deploy whose `storage.Open` dies reports success +identically to one that serves traffic. So the Deploy workflow does not stop at +`up -d` — it runs `scripts/wait-for-healthy.sh`, which blocks until the +container reports `healthy` and **fails the deploy** on any of: + +| Condition | Gate result | +|-----------|-------------| +| `healthy` within the timeout | pass | +| Container exited, or is in `restarting` (crash loop) | fail, immediately | +| Container restarted *during* the wait (crash loop) | fail, immediately | +| Health probe reports `unhealthy` | fail, immediately | +| Still `starting` when the timeout expires | fail | +| Service defines no `HEALTHCHECK` | fail | + +On failure it dumps `docker compose ps`, the last health-probe output and +`docker compose logs --tail=200`, so the reason lands in the workflow run log +instead of needing shell access to the runner. The healthcheck itself is defined +in the `Dockerfile` and compose inherits it from the image; the "no `HEALTHCHECK`" +row means the gate cannot be quietly defeated by dropping it. + +Only restarts observed *during* the wait count against a deploy. A restart count +of its own does not: `up -d` leaves an already-current container in place, and a +container that crashed once and recovered carries that count for the rest of its +life — including while it legitimately replays a WAL, which is exactly when the +wait is longest and the gate most needs to hold. + +Run it by hand against a local stack the same way: + +```bash +scripts/wait-for-healthy.sh cotel 120 # service, timeout in seconds +``` + +**Timeout.** The default is 120 s, and a normal deploy is far inside it: a +graceful stop checkpoints the WAL, so the next open takes milliseconds, and +measured against a 109 MB copy of production the container reports healthy in +~6 s — that figure is the probe cadence, not the database. A start that follows +a *hard* kill replays the WAL instead and can take minutes; for that deploy use +**Run workflow** and raise the `health_timeout` input rather than widening the +default, which would blunt the gate for every other deploy. + ## Data Data lives in the named volume (`cotel-data`) at `/data/cotel.duckdb`. You can query it directly: diff --git a/scripts/wait-for-healthy.sh b/scripts/wait-for-healthy.sh new file mode 100755 index 0000000..a931dad --- /dev/null +++ b/scripts/wait-for-healthy.sh @@ -0,0 +1,128 @@ +#!/usr/bin/env bash +# +# wait-for-healthy.sh — block until a compose service reports healthy. +# +# `docker compose up -d` returns once the container is *started*, not once the +# application inside it works, so a deploy whose `storage.Open` dies looks +# exactly like one that succeeded. This gates on the container's own +# HEALTHCHECK and, on any failure, dumps the container logs so the reason is in +# the run log rather than only on the runner. +# +# Usage: +# scripts/wait-for-healthy.sh [SERVICE] [TIMEOUT_SECONDS] +# +# Defaults: SERVICE=cotel, TIMEOUT_SECONDS=120. Run from the directory holding +# the compose file. Exits 0 once healthy; 1 on unhealthy, a crash loop, an exit, +# a service that defines no HEALTHCHECK, or timeout. +# +# Timeout guidance: a graceful stop checkpoints the WAL, so a normal cold start +# is a couple of seconds. A start that follows a hard kill replays the WAL +# instead and can take minutes — pass a larger timeout for that deploy rather +# than widening the default, which would blunt the gate for every other deploy. + +set -euo pipefail + +SERVICE="${1:-cotel}" +TIMEOUT="${2:-120}" +POLL_INTERVAL="${POLL_INTERVAL:-2}" +LOG_TAIL="${LOG_TAIL:-200}" +PROGRESS_EVERY=10 + +# A non-numeric timeout would make the `-ge` test error out every iteration; +# `set -e` does not fire inside an `if`, so the gate would silently never time +# out and hang the job instead of failing it. +if ! [ "$TIMEOUT" -gt 0 ] 2>/dev/null; then + echo "wait-for-healthy: FAILED — timeout must be a positive integer, got '${TIMEOUT}'" + exit 1 +fi + +inspect() { + docker inspect -f "$1" "$CID" 2>/dev/null || true +} + +dump_diagnostics() { + echo "--- docker compose ps ---" + docker compose ps "$SERVICE" || true + echo "--- health probe output ---" + inspect '{{if .State.Health}}{{range .State.Health.Log}}exit={{.ExitCode}} {{.Output}} +{{end}}{{else}}(service defines no HEALTHCHECK){{end}}' + echo "--- docker compose logs (last ${LOG_TAIL} lines) ---" + docker compose logs --tail="$LOG_TAIL" --no-color "$SERVICE" || true +} + +fail() { + echo "wait-for-healthy: FAILED — $*" + dump_diagnostics + exit 1 +} + +CID="$(docker compose ps -q "$SERVICE" 2>/dev/null || true)" +if [ -z "$CID" ]; then + echo "wait-for-healthy: FAILED — no container for service '${SERVICE}'; did 'docker compose up -d' run?" + docker compose ps || true + exit 1 +fi + +# Read the configured probe rather than .State.Health, which is briefly null +# right after start and would otherwise read as "no healthcheck". +PROBE="$(inspect '{{if .Config.Healthcheck}}{{index .Config.Healthcheck.Test 0}}{{end}}')" +if [ -z "$PROBE" ] || [ "$PROBE" = "NONE" ]; then + fail "'${SERVICE}' defines no HEALTHCHECK, so the deploy cannot be verified" +fi + +echo "wait-for-healthy: waiting up to ${TIMEOUT}s for '${SERVICE}' (${CID:0:12}) to report healthy" +START=$SECONDS +BASELINE_RESTARTS="$(inspect '{{.RestartCount}}')" +BASELINE_RESTARTS="${BASELINE_RESTARTS:-0}" +if [ "$BASELINE_RESTARTS" -gt 0 ]; then + echo "wait-for-healthy: container carries ${BASELINE_RESTARTS} earlier restart(s); only further ones count as a crash loop" +fi + +while :; do + state="$(inspect '{{.State.Status}}')" + health="$(inspect '{{if .State.Health}}{{.State.Health.Status}}{{else}}starting{{end}}')" + restarts="$(inspect '{{.RestartCount}}')" + elapsed=$((SECONDS - START)) + + if [ "$health" = healthy ]; then + echo "wait-for-healthy: '${SERVICE}' healthy after ${elapsed}s" + exit 0 + fi + + # Checked before the probe: a restarting container also reads as + # "unhealthy", and the process that died names the fault better. + case "$state" in + exited | dead) + fail "'${SERVICE}' exited with code $(inspect '{{.State.ExitCode}}') after ${elapsed}s" + ;; + restarting) + fail "'${SERVICE}' is restarting after ${elapsed}s: the process exited on its own (crash loop)" + ;; + "") + fail "'${SERVICE}' container ${CID:0:12} disappeared after ${elapsed}s" + ;; + esac + + # Only restarts observed *during* this wait indict this deploy. A count of + # its own does not: `up -d` leaves an already-current container in place, + # and one that crashed once and recovered carries the count for the rest of + # its life — including while it legitimately replays a WAL after a hard + # kill, which is precisely when the wait is longest. + if [ "${restarts:-0}" -gt "$BASELINE_RESTARTS" ]; then + fail "'${SERVICE}' restarted $(( restarts - BASELINE_RESTARTS ))x during the wait (crash loop) after ${elapsed}s" + fi + + if [ "$health" = unhealthy ]; then + fail "'${SERVICE}' reported unhealthy after ${elapsed}s" + fi + + if [ "$elapsed" -ge "$TIMEOUT" ]; then + fail "'${SERVICE}' still '${health}' (container ${state}) after ${TIMEOUT}s" + fi + + if [ "$elapsed" -gt 0 ] && [ $((elapsed % PROGRESS_EVERY)) -lt "$POLL_INTERVAL" ]; then + echo "wait-for-healthy: ${elapsed}s — status=${state} health=${health}" + fi + + sleep "$POLL_INTERVAL" +done