From 6f1b84e1917d82f29d0a1d7f302d3ef4f31a48f3 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Mauricio=20Pe=C3=B1aranda?= Date: Thu, 30 Jul 2026 15:13:43 -0400 Subject: [PATCH 1/2] ci(benchmark): stop the FHIR benchmark from exhausting the shared Docker host MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Run 30550776427 did not just fail — it took every other job on the Docker host down with it for about three hours, and destroyed the evidence needed to explain itself. What happened, from the log: 14:30:12 import starts 14:52:20 497/1000 bundles, steady ~23/min 14:52:21 503 remaining iterations "complete" in 19 seconds 14:58:38 search setup logs the cause: HTTP 503 "error connecting to server" The `max` request duration was exactly 15m0s — `HFS_REQUEST_TIMEOUT=900` — so the in-flight requests all hit the server-side ceiling at once and the rest failed on arrival. HFS was alive and returning well-formed OperationOutcomes; PostgreSQL was gone. That also explains the search suite's 4.8M requests at 40k/s with sub-millisecond latency and 100% failures: fast 503s from a server that never reached a database. Postgres was started with no volume, so its data lived in the container's writable layer on the daemon's own storage — the filesystem that then reported `disk quota exceeded`. The runner was killed at 15:04:28, and a killed *runner* does not run `if: always()` steps, so the cleanup never executed and the containers were orphaned holding the whole import. Four changes: 1. Postgres data moves to a named, labelled volume, mounted at the image's declared VOLUME root so it survives PGDATA relocations across postgres image versions. Container-layer data cannot be reclaimed independently of the container; a named volume can be dropped by label even after the container is gone. 2. A reaper at the START of the job removes `hfs-bench-*` containers and dangling labelled volumes left by earlier runs. A cleanup step cannot defend against itself never running, so this is the compensating control for the killed-runner case. Both the name prefix and the run-id exclusion are re-checked in the loop rather than trusting `--filter name=` to anchor — a reaper that deletes someone else's container would be worse than the leak it fixes. The run-id exclusion is also what stops the concurrent sqlite and postgres matrix legs, which share a run id, from killing each other. 3. A canary creates a container and writes 256 MiB before anything is allocated. It catches an exhausted host in ~10 seconds with the remedy printed, instead of 20 minutes in with a confusing symptom and more debris. It does not catch a merely tight host; that trade is documented at the call site. 4. The artifact uploads move ahead of per-shape attribution and summary generation. Those steps are where this run died, so the server log and raw results — the only non-recomputable outputs — were lost for exactly the run that needed them. Upload first, analyse second. Not addressed here: whether the Postgres import path is genuinely slow. The median request was 120ms but 20 VUs over 22 minutes yielded 497 bundles, and "HFS is slow" cannot be separated from "the host was already degrading" without a clean run. That measurement is what these changes make possible. Also unaddressed: `crud.js:47` derefs the response body unguarded, turning a dead backend into 12,139 stack traces — that file is vendored from HealthSamurai, so it needs an upstream fix or a local patch. --- .github/workflows/fhir-benchmark.yml | 168 +++++++++++++++++++++++---- 1 file changed, 144 insertions(+), 24 deletions(-) diff --git a/.github/workflows/fhir-benchmark.yml b/.github/workflows/fhir-benchmark.yml index 4e3658011..3b6bcb3ac 100644 --- a/.github/workflows/fhir-benchmark.yml +++ b/.github/workflows/fhir-benchmark.yml @@ -228,6 +228,83 @@ jobs: echo "Runner IP: $RUNNER_IP" echo "Docker host IP: $EFFECTIVE_DOCKER_HOST_IP" + # ── Reclaim storage left behind by earlier runs, then prove we can ─── + # The cleanup steps at the end of this job are `if: always()`, which does + # NOT run when the *runner itself* is shut down mid-job. When that happened + # on run 30550776427 the Postgres and tgz containers were orphaned holding + # a full Synthea import, the Docker host filled up, and every + # testcontainers-based job in the repo failed with `disk quota exceeded` + # for hours afterwards. + # + # A step at the end cannot defend against its own step never running, so + # the durable control is here, at the *start*: reap anything a previous run + # left behind before allocating anything new. This is the compensating + # control for that GitHub limitation, not a nicety. + - name: Reap stale benchmark containers and verify Docker host storage + run: | + set -uo pipefail + RUN_ID="${{ github.run_id }}" + + # Reap by name prefix rather than by label, so containers created + # before labelling was added here are also caught. + # + # Two conditions, BOTH re-checked in the loop rather than trusting + # `--filter name=` to anchor: this deletes other people's containers if + # it is wrong, which would be far worse than the leak it fixes. The + # filter narrows the candidate set; the `case` statements decide. + # 1. the name must start with `hfs-bench-` → only ours + # 2. the name must NOT contain this run id → never a live sibling. + # The matrix legs (sqlite, postgres) share a run id and run + # concurrently, so this is what stops one leg killing the other. + echo "── Reaping hfs-bench-* containers from earlier runs ──" + REAPED=0 + for id in $(docker ps -aq --filter "name=hfs-bench-" 2>/dev/null); do + name=$(docker inspect -f '{{.Name}}' "$id" 2>/dev/null | sed 's|^/||') + case "$name" in + hfs-bench-*) ;; # ours — keep checking + *) continue ;; # not ours — never touch + esac + case "$name" in + *"$RUN_ID"*) continue ;; # this run's own — leave alone + esac + echo " removing $name ($id)" + docker rm -f -v "$id" >/dev/null 2>&1 || true + REAPED=$((REAPED + 1)) + done + echo " reaped: $REAPED" + + # `-v` above drops each container's anonymous volumes; named volumes + # from this workflow are labelled, so they can be pruned precisely + # without touching anything another workflow owns. + echo "── Pruning this workflow's dangling volumes ──" + docker volume prune -f --filter "label=hfs-bench=1" 2>/dev/null || true + + echo "── Docker host usage ──" + docker system df 2>/dev/null || true + + # Preflight. `docker system df` reports image/volume usage but not a + # filesystem *quota*, which is what actually bit us — the daemon failed + # at CreateContainer with "write .../meta.db: disk quota exceeded". + # The only reliable check is to ask the daemon to do the thing we need + # it to do: create a container and write to its layer. + # + # This detects an *exhausted* host, not a merely tight one: 256 MiB is + # a floor, and a host with 1 GB free would pass here and still fail + # during the import. That is a deliberate trade — the point is to turn + # the common case from "fails confusingly 20 minutes in, leaving more + # debris" into "fails in 10 seconds with the remedy printed". + echo "── Canary: create a container and write 256 MiB ──" + if ! docker run --rm --name "hfs-bench-canary-$RUN_ID" alpine:3 \ + sh -c 'dd if=/dev/zero of=/canary bs=1M count=256 2>&1 | tail -1'; then + echo "::error::Docker host cannot create a container or has no writable space." + echo "The benchmark writes several GB (Synthea corpus + Postgres data), so it" + echo "would fail slowly and leave more debris. Failing fast instead." + echo "Remedy on the Docker host: docker system prune -af --volumes" + docker system df 2>/dev/null || true + exit 1 + fi + echo "Canary OK — host has writable space." + # ── tgz bundle server ──────────────────────────────────────────────── # The import suite pulls the Synthea `bulk_1k` corpus from this service # (`GET /reset`, `GET /.json`). Built from the benchmark repo's @@ -240,8 +317,13 @@ jobs: echo "TGZ_CONTAINER=$TGZ_CONTAINER" >> "$GITHUB_ENV" docker build -t "$TGZ_IMAGE" fhir-benchmark/infra/tgz - docker rm -f "$TGZ_CONTAINER" 2>/dev/null || true - docker run -d --name "$TGZ_CONTAINER" -p 0:8080 "$TGZ_IMAGE" \ + docker rm -f -v "$TGZ_CONTAINER" 2>/dev/null || true + # Labelled so the start-of-job reaper and volume prune can find this + # container precisely if a killed runner ever leaves it behind. + docker run -d --name "$TGZ_CONTAINER" \ + --label hfs-bench=1 \ + --label "hfs-bench-run=${{ github.run_id }}" \ + -p 0:8080 "$TGZ_IMAGE" \ "https://storage.googleapis.com/aidbox-public/synthea/performance/bulk_1k.tar.gz" >/dev/null echo "Waiting for tgz bundle server..." @@ -273,24 +355,46 @@ jobs: echo "SQLite DB: $DB_PATH" else PG_CONTAINER="hfs-bench-pg-${{ github.run_id }}" + PG_VOLUME="hfs-bench-pgdata-${{ github.run_id }}" echo "PG_CONTAINER=$PG_CONTAINER" >> "$GITHUB_ENV" + echo "PG_VOLUME=$PG_VOLUME" >> "$GITHUB_ENV" echo "Container name: $PG_CONTAINER" + echo "Data volume: $PG_VOLUME" fi - name: Start ephemeral Postgres if: matrix.backend == 'postgres' run: | set -euo pipefail - docker rm -f "$PG_CONTAINER" 2>/dev/null || true + docker rm -f -v "$PG_CONTAINER" 2>/dev/null || true + docker volume rm -f "$PG_VOLUME" 2>/dev/null || true + docker volume create --label hfs-bench=1 \ + --label "hfs-bench-run=${{ github.run_id }}" "$PG_VOLUME" >/dev/null + # Tuning approximates the benchmark's infra/postgres/postgres.conf. # shared_buffers/effective_cache_size are scaled DOWN from the # published values (10G/25G) to fit a typical self-hosted runner; # bump them (and the runner) to match the benchmark host for numbers # that are directly comparable to the public report. `--shm-size` # must exceed shared_buffers. + # + # The data directory is a **named volume**, not the container's + # writable layer. Importing the Synthea corpus writes several GB, and + # in the layer that lands in the daemon's own storage where nothing can + # reclaim it independently of the container — so an orphaned container + # pins the space indefinitely (run 30550776427). A named volume is + # addressable: the reaper at the top of this job can drop it by label + # even when the container that created it is long gone. + # + # Mounted at `/var/lib/postgresql` (the image's declared VOLUME root) + # rather than at `$PGDATA`, so this keeps working across postgres image + # versions that relocate PGDATA within that tree. docker run -d \ --name "$PG_CONTAINER" \ + --label hfs-bench=1 \ + --label "hfs-bench-run=${{ github.run_id }}" \ --shm-size=4g \ + -v "$PG_VOLUME:/var/lib/postgresql" \ -e POSTGRES_PASSWORD=postgres \ -e POSTGRES_USER=postgres \ -e POSTGRES_DB=postgres \ @@ -506,6 +610,32 @@ jobs: "$SCRIPT" 2>&1 | tee "$RESULTS_DIR/${SUITE}.log" || true done + # ── Artifacts ──────────────────────────────────────────────────────── + # Deliberately placed immediately after the suites and BEFORE the + # post-processing steps below. When run 30550776427's runner was killed + # during per-shape attribution, these steps — which sat after it — never + # ran, so the server log and raw results were lost precisely for the run + # that most needed diagnosing. Everything after this point is derived data + # that can be recomputed from these artifacts; the artifacts cannot be + # recovered from anything. Upload first, analyse second. + - name: Upload results + if: always() + uses: actions/upload-artifact@v7 + with: + name: fhir-benchmark-${{ matrix.backend }}-${{ github.run_id }} + path: bench-results/ + retention-days: 90 + if-no-files-found: ignore + + - name: Upload server log + if: always() + uses: actions/upload-artifact@v7 + with: + name: fhir-bench-server-log-${{ matrix.backend }}-${{ github.run_id }} + path: /tmp/hfs-bench-${{ matrix.backend }}.log + retention-days: 7 + if-no-files-found: ignore + # ── Per-query-shape attribution ────────────────────────────────────── # Without this the search suite reports a single aggregate latency and we # cannot tell which of the ~21 query shapes is slow. Produces a table sorted @@ -612,25 +742,6 @@ jobs: PYEOF } >> "$GITHUB_STEP_SUMMARY" - # ── Artifacts ──────────────────────────────────────────────────────── - - name: Upload results - if: always() - uses: actions/upload-artifact@v7 - with: - name: fhir-benchmark-${{ matrix.backend }}-${{ github.run_id }} - path: bench-results/ - retention-days: 90 - if-no-files-found: ignore - - - name: Upload server log - if: always() - uses: actions/upload-artifact@v7 - with: - name: fhir-bench-server-log-${{ matrix.backend }}-${{ github.run_id }} - path: /tmp/hfs-bench-${{ matrix.backend }}.log - retention-days: 7 - if-no-files-found: ignore - # ── Cleanup ────────────────────────────────────────────────────────── - name: Stop HFS server if: always() @@ -644,12 +755,21 @@ jobs: if: always() run: | if [ -n "${TGZ_CONTAINER:-}" ]; then - docker rm -f "$TGZ_CONTAINER" 2>/dev/null || true + docker rm -f -v "$TGZ_CONTAINER" 2>/dev/null || true fi + # `-v` and the explicit `volume rm` matter: without them the Postgres data + # volume outlives the container and is never reclaimed. This is the happy + # path — the reaper at the top of the job is what covers the case where + # this step never runs at all (killed runner). - name: Stop ephemeral Postgres if: always() && matrix.backend == 'postgres' run: | if [ -n "${PG_CONTAINER:-}" ]; then - docker rm -f "$PG_CONTAINER" 2>/dev/null || true + docker rm -f -v "$PG_CONTAINER" 2>/dev/null || true + fi + if [ -n "${PG_VOLUME:-}" ]; then + docker volume rm -f "$PG_VOLUME" 2>/dev/null || true fi + echo "── Docker host usage after cleanup ──" + docker system df 2>/dev/null || true From a101d0e6a8f08f600829b977641ce7eb9a43348e Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Mauricio=20Pe=C3=B1aranda?= Date: Thu, 30 Jul 2026 15:30:40 -0400 Subject: [PATCH 2/2] ci(benchmark): add an age guard so concurrent benchmark runs cannot reap each other MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The reaper excluded this run's own containers by run id, which covers the sqlite/postgres matrix legs (they share a run id). It did not cover two *different* runs: the `concurrency` group only cancels in-progress runs on the same ref, so a dispatch on main and one on a PR branch run side by side with different run ids — and each would have reaped the other's containers mid-benchmark. Adds the age guard ci.yml already uses for the same reason. 120 minutes is comfortably longer than a full leg (import alone is ~22 min), so a running benchmark is never in range. The canary covers the window where an orphan is younger than the guard but still holding the host's space. Found by reading #452, which fixes the same class of leak repo-wide. --- .github/workflows/fhir-benchmark.yml | 42 ++++++++++++++++++++++------ 1 file changed, 34 insertions(+), 8 deletions(-) diff --git a/.github/workflows/fhir-benchmark.yml b/.github/workflows/fhir-benchmark.yml index 3b6bcb3ac..01d523a92 100644 --- a/.github/workflows/fhir-benchmark.yml +++ b/.github/workflows/fhir-benchmark.yml @@ -248,15 +248,34 @@ jobs: # Reap by name prefix rather than by label, so containers created # before labelling was added here are also caught. # - # Two conditions, BOTH re-checked in the loop rather than trusting + # THREE conditions, all re-checked in the loop rather than trusting # `--filter name=` to anchor: this deletes other people's containers if # it is wrong, which would be far worse than the leak it fixes. The - # filter narrows the candidate set; the `case` statements decide. - # 1. the name must start with `hfs-bench-` → only ours - # 2. the name must NOT contain this run id → never a live sibling. - # The matrix legs (sqlite, postgres) share a run id and run - # concurrently, so this is what stops one leg killing the other. - echo "── Reaping hfs-bench-* containers from earlier runs ──" + # filter narrows the candidate set; the checks below decide. + # + # 1. name starts with `hfs-bench-` → only ever our own containers + # 2. name does NOT contain this run id → never a live sibling. The + # matrix legs (sqlite, postgres) share a run id and run + # concurrently, so this stops one leg killing the other. + # 3. older than MAX_AGE_MIN → never a *different* run that + # is still going. + # + # (3) is not redundant with (2). The `concurrency` group at the top of + # this file only cancels in-progress runs on the SAME ref, so a + # dispatch on `main` and a dispatch on a PR branch run side by side + # with different run ids — and without an age guard each would reap the + # other's containers mid-benchmark. Same idiom as ci.yml's + # "Sweep orphaned testcontainers from dead runs". + # + # 120 minutes is comfortably longer than a full leg (the import suite + # alone runs ~22 min, plus corpus download and the other suites), so a + # legitimately-running benchmark is never in range. Debris older than + # that is unambiguously dead. The canary below is what protects us in + # the window where an orphan is younger than the guard but still + # holding the host's space. + MAX_AGE_MIN=120 + echo "── Reaping hfs-bench-* containers older than ${MAX_AGE_MIN}m ──" + NOW=$(date +%s) REAPED=0 for id in $(docker ps -aq --filter "name=hfs-bench-" 2>/dev/null); do name=$(docker inspect -f '{{.Name}}' "$id" 2>/dev/null | sed 's|^/||') @@ -267,7 +286,14 @@ jobs: case "$name" in *"$RUN_ID"*) continue ;; # this run's own — leave alone esac - echo " removing $name ($id)" + created=$(docker inspect -f '{{.Created}}' "$id" 2>/dev/null) || continue + created_s=$(date -d "$created" +%s 2>/dev/null) || continue + age_min=$(( (NOW - created_s) / 60 )) + if [ "$age_min" -lt "$MAX_AGE_MIN" ]; then + echo " keeping $name (age ${age_min}m — may be a concurrent run)" + continue + fi + echo " removing $name ($id, age ${age_min}m)" docker rm -f -v "$id" >/dev/null 2>&1 || true REAPED=$((REAPED + 1)) done