diff --git a/.github/scripts/fhir-bench/capacity-gate.sh b/.github/scripts/fhir-bench/capacity-gate.sh index d1fa92424..038969407 100755 --- a/.github/scripts/fhir-bench/capacity-gate.sh +++ b/.github/scripts/fhir-bench/capacity-gate.sh @@ -108,6 +108,63 @@ read_host_mem() { [ -n "$HOSTMEM_AVAIL_MB" ] || HOSTMEM_AVAIL_MB=unknown } +# capture_holders [TOP_N]: best-effort, never-fatal record of which containers +# hold the host's memory (the gate only sees host-wide MemAvailable). Appends a +# timestamped block to ${BENCH_RESULTS_DIR:-bench-results}/capacity-gate-holders.txt: +# docker stats sorted by used memory (descending, top 15) plus docker ps +# image/age/labels. Runs in a subshell with `|| true` everywhere so it can +# never change the script's exit status. +holders_stats_sorted() { + # Prints "MiB\tID\tName\tMemUsage", biggest first. + timeout 60 docker stats --no-stream --format '{{.ID}}\t{{.Name}}\t{{.MemUsage}}' 2>/dev/null \ + | awk -F'\t' '{ + u=$3; sub(/ *\/.*/, "", u); v=u+0 + if (u ~ /[Gg]i?[Bb]$/) v*=1024; else if (u ~ /[Kk]i?[Bb]$/) v/=1024; else if (u ~ /[Mm]i?[Bb]$/) v=v; else if (u ~ /[Bb]$/) v/=1048576 + printf "%.1f\t%s\t%s\t%s\n", v, $1, $2, $3 }' \ + | sort -t$'\t' -k1,1 -rn || true +} + +capture_holders() { + ( + set +e + dir="${BENCH_RESULTS_DIR:-bench-results}" + mkdir -p "$dir" 2>/dev/null || exit 0 + out="$dir/capacity-gate-holders.txt" + { + echo "=== $(date -u +%Y-%m-%dT%H:%M:%SZ) capacity-gate holders (backend=${BACKEND:-?}) ===" + echo "--- docker stats, top 15 by memory (MiB, id, name, usage) ---" + holders_stats_sorted | head -n 15 || true + echo "--- docker ps (id, image, running-for, hfs-ci, hfs-bench-run, testcontainers sessionId) ---" + timeout 60 docker ps --no-trunc=false --format '{{.ID}}\t{{.Image}}\t{{.RunningFor}}\t{{.Label "hfs-ci"}}\t{{.Label "hfs-bench-run"}}\t{{.Label "org.testcontainers.sessionId"}}' 2>&1 | head -n 15 || true + echo + } >> "$out" 2>/dev/null + ) || true + return 0 +} + +# report_holders: final-failure only — top 10 to the job log and, when +# $GITHUB_STEP_SUMMARY is set, as a markdown table. Never fatal. +report_holders() { + ( + set +e + top=$(holders_stats_sorted | head -n 10) + [ -n "$top" ] || { echo "Top memory holders: unavailable (docker stats returned nothing)"; exit 0; } + echo "── Top 10 container memory holders ──" + printf '%s\n' "$top" | awk -F'\t' '{ printf " %8s MiB %s %s (%s)\n", $1, $2, $3, $4 }' + if [ -n "${GITHUB_STEP_SUMMARY:-}" ]; then + { + echo "### Capacity gate: top memory holders (${BACKEND:-?})" + echo + echo "| MiB | Container ID | Name | MemUsage |" + echo "|---:|---|---|---|" + printf '%s\n' "$top" | awk -F'\t' '{ printf "| %s | %s | %s | %s |\n", $1, $2, $3, $4 }' + echo + } >> "$GITHUB_STEP_SUMMARY" 2>/dev/null + fi + ) || true + return 0 +} + read_host_mem MEM_TOTAL_MB="$HOSTMEM_TOTAL_MB" case "$MEM_TOTAL_MB" in ''|*[!0-9]*) MEM_TOTAL_MB=0 ;; esac @@ -156,6 +213,7 @@ while :; do # (CAPACITY_AVAIL_MB blanked by the numeric guard) — keep waiting and # let the 600s budget below be the only thing that fails the leg. echo " t=${CAPACITY_WAIT_S}s MemAvailable=${CAPACITY_AVAIL_MB:-unknown}MB (source=${CAPACITY_MEM_SOURCE}), need $(( CAPACITY_NEED_MB + 2048 ))MB — waiting" + capture_holders # Never sleep past the 600s budget: a plain `sleep 60` here could # carry the last iteration well beyond it (e.g. wait_s=590 -> next # check at 650s). Cap the sleep to whatever is actually left. @@ -177,5 +235,7 @@ done if [ "$CAPACITY_OK" -ne 1 ]; then echo "::error::Docker host still short of memory for $BACKEND after ${CAPACITY_WAIT_S}s (needed $(( CAPACITY_NEED_MB + 2048 ))MB, last MemAvailable=${CAPACITY_AVAIL_MB:-unknown}MB). Failing this leg rather than risk an OOM on the shared host." + capture_holders + report_holders exit 1 fi diff --git a/.github/scripts/fhir-bench/compare_legs.py b/.github/scripts/fhir-bench/compare_legs.py index 2dd57b17a..2dbfcd20a 100644 --- a/.github/scripts/fhir-bench/compare_legs.py +++ b/.github/scripts/fhir-bench/compare_legs.py @@ -15,7 +15,7 @@ # and indexing.txt instead of a k6 summary; bulk-import also adds a bulk # detail table after the leg-health table. The Throughput table also splits the # bulk-import row into its two phases, directly under it: ingest (resources/s and -# seconds, how long loading the corpus takes) and initial index (seconds of the +# seconds, how long loading the corpus takes) and index rebuild (seconds of the # deferred search-index rebuild after it, `inline (during ingest)` when the # backend indexed while ingesting; BULK_PHASES_NOTE). Display only: it never # decides anything, it always exits 0 and every problem goes out as a `::warning` @@ -88,6 +88,8 @@ # is opt-in and not in it; its row still shows when `tests` names it or a leg # wrote indexing.txt (_render's extras). CANONICAL_SUITES = ["prewarm", "import", "crud", "search", "insert", "bulk-import"] +# Shown in every comparison, as n/a (not requested) when the run did not ask for them. +CORE_ROWS = ("crud", "search") # bulk-import is not a k6 suite: bulk-import.sh writes bulk-import.txt (key=value), # and it runs after search against its own fresh database. BULK_SUITE = "bulk-import" @@ -117,14 +119,14 @@ LEGEND = ( "`†` crud/search/reindex ran on an incomplete corpus (import below 1000/1000 bundles or not " - "run before it, or the ES index not drained); on bulk-import and its initial index, search " + "run before it, or the ES index not drained); on Bulk Import and its index rebuild, search " "did not return every resource it ingested · `‡` more than 1% errors or failed checks in " - "that suite (on bulk-import and its ingest, any resource not ingested; on its initial " + "that suite (on Bulk Import and its ingest, any resource not ingested; on its initial " "index, a rebuild that did not complete or reported errors; on reindex, any reindex error " "or a failed job) · `⚠` contended host (postgres crud above 3 ms/call) or a backend " "container died · **bold** = best in its row, shown only when no leg in that row carries a " - "marker or `(partial)` (on the bulk-import ingest and initial index rows, also only when " - "every leg indexed the same way) · bulk-import is resources/s through `$bulk-submit` into a " + "marker or `(partial)` (on the Bulk Import ingest and index rebuild rows, also only when " + "every leg indexed the same way) · Bulk Import is resources/s through `$bulk-submit` into a " "fresh database, kick-off until the search index covers it, and its ingest and initial " "index rows split that time (see the note below the tables); reindex is resources/s of one " "`$reindex` of the " @@ -143,15 +145,15 @@ # The loading rows also name the operation they time, in every table: HFS has # no `$import`, and `import` is k6 POSTing transaction Bundles to the base URL. ROW_LABELS = { - ("import", "rps"): "import, `POST /` transaction Bundles (resources/s)", - ("import", "p95"): "import, `POST /` transaction Bundles (per Bundle)", - ("import", "err"): "import, `POST /` transaction Bundles", + ("import", "rps"): "Batch/Transaction Import, `POST /` Bundles (resources/s)", + ("import", "p95"): "Batch/Transaction Import, `POST /` Bundles (per Bundle)", + ("import", "err"): "Batch/Transaction Import, `POST /` Bundles", # every insert.js request is one create ("insert", "rps"): "insert (creates/s)", # one $bulk-submit job: resources ingested per second until searchable - ("bulk-import", "rps"): "bulk-import, `$bulk-submit` (resources/s)", - ("bulk-import", "p95"): "bulk-import, `$bulk-submit`", - ("bulk-import", "err"): "bulk-import, `$bulk-submit`", + ("bulk-import", "rps"): "Bulk Import, `$bulk-submit` (resources/s)", + ("bulk-import", "p95"): "Bulk Import, `$bulk-submit`", + ("bulk-import", "err"): "Bulk Import, `$bulk-submit`", # one $reindex job; %s is " " when every leg reindexed the same type (_reindex_type) ("indexing", "rps"): "reindex, `$reindex`%s (resources/s)", ("indexing", "p95"): "reindex, `$reindex`%s", @@ -159,25 +161,27 @@ } # The two phases of the bulk-import job, as Throughput rows right under the # combined bulk-import row (_bulk_phase_lines). -BULK_INGEST_LABEL = "bulk-import ingest (resources/s, seconds)" -BULK_INDEX_LABEL = "bulk-import initial index (seconds)" +BULK_INGEST_LABEL = "Bulk Import: ingest (resources/s, seconds)" +BULK_INDEX_LABEL = "Bulk Import: index rebuild (seconds)" # index_seconds is 0 when HFS indexed while ingesting; that is not a free index. INLINE_INDEX = "inline (during ingest)" # bulk_import.py index_status values that mean the deferred rebuild did not finish cleanly. _BULK_INDEX_BAD = ("failed", "permanent-errors", "cancelled") IMPORT_NOTE = ( - "Import row: **resources/s** = entries of the transaction Bundles that committed (k6 " + "Batch/Transaction Import row (suite `import`): **resources/s** = entries of the transaction Bundles that committed (k6 " "`bundle_size`) per second of the import scenario's own clock, which starts after k6 " "setup() has loaded the two seed Bundles (that time is in Leg health) — the unit " "upstream's report uses. Its p95 is **per Bundle**: one k6 iteration, the corpus fetch " "plus the transaction POST. k6's `http_reqs` is not used for import: it counts a corpus " - "GET beside every Bundle POST. Bundles/s is in Leg health." + "GET beside every Bundle POST. Bundles/s is in Leg health. Its resources/s is not " + "comparable with the Bulk Import row's: committed Bundle entries per second of the k6 " + "scenario, against resources until the search index covers them." ) BULK_PHASES_NOTE = ( - "Bulk-import ingest and initial index rows: the same `$bulk-submit` load as the " - "`bulk-import` row, split into the two times a user waits for. **Ingest** = resources " + "Bulk Import ingest and index rebuild rows: the same `$bulk-submit` load as the " + "Bulk Import row, split into the two times a user waits for. **Ingest** = resources " "ingested ÷ seconds from kick-off until the status manifest is final, those seconds in " - "brackets: how long loading the corpus takes. **Initial index** = seconds from then until " + "brackets: how long loading the corpus takes. **Index rebuild** = seconds from then until " "HFS's deferred search-index rebuild of that freshly loaded data has finished " "(HFS_BULK_SUBMIT_DEFER_INDEXING, the default); the Search check in the Bulk import table " "then confirms it is searchable. `inline (during ingest)` = the backend indexed each batch " @@ -185,7 +189,7 @@ "— it is not a zero-second index; `+ N s rebuild` is a follow-up rebuild of the types the " "index rejected. No best is marked on either row when legs indexed differently. Both rows " "are in the Throughput table only (one asynchronous job: no p95; failed resources are in " - "the bulk-import Errors row)." + "the Bulk Import Errors row)." ) INSERT_NOTE = ( "`insert` is HFS's own suite (`.github/scripts/fhir-bench/k6/insert.js`, load shape " @@ -201,8 +205,8 @@ "parameters and rewrites the index that serves search (the primary's own index on " "sqlite/postgres/mongodb, Elasticsearch on the +ES legs). **resources/s** = processed ÷ " "(completedAt − startedAt) from `$reindex-status`. This is not the index cost paid inside " - "import, which stays in the import row, nor the initial index time of freshly loaded " - "data, which is the bulk-import initial index row; it rewrites the index right before " + "import, which stays in the Batch/Transaction Import row, nor the index rebuild time of freshly loaded " + "data, which is the Bulk Import index rebuild row; it rewrites the index right before " "`insert` and `bulk-import`, so a run that includes it may skew both. A job still running " "at the budget (`budget_s` in indexing.txt) is cancelled and its rate covers the part that " "ran (`(partial)`). Its seconds, resources reindexed, index entries per resource and phase " @@ -1021,12 +1025,12 @@ def _health_row(d, rows): "per-resource-type NDJSON) through `$bulk-submit`, in a fresh database served by a second HFS, " "after the search suite. **Ingest** is kick-off until the status manifest is final; **Index** " "is the deferred search-index rebuild that follows (followed in the second HFS's log); " - "**Total** is both, and is what the `bulk-import` row above divides the ingested resources " - "by; the ingest and initial index rows above show **Ingest** and **Index** on their own. " + "**Total** is both, and is what the Bulk Import row above divides the ingested resources " + "by; the ingest and index rebuild rows above show **Ingest** and **Index** on their own. " "**Index** reads `inline (during ingest)` when HFS indexed while ingesting, so that time is " "inside **Ingest**. **Search check** compares Patient and Observation totals and two " "indexed queries with the " - "converted corpus. It counts the 3,349 seed resources the `import` row's entries do not." + "converted corpus. It counts the 3,349 seed resources the Batch/Transaction Import row's entries do not." ) _BULK_CHECKS = (("patient", "Patient"), ("observation", "Observation"), @@ -1281,6 +1285,13 @@ def _render(root, env, warn, zips): if INDEXING_FILE in names and INDEXING_SUITE not in requested: extras.add(INDEXING_SUITE) rows = requested + sorted(extras) + # crud and search are what a run is compared on: a run that did not ask for + # them still shows their rows, as n/a (not requested), so a trimmed run + # does not read as a report that lost them. + not_requested = [x for x in CORE_ROWS if x not in rows] + for x in not_requested: + after = [r for r in CANONICAL_SUITES[:CANONICAL_SUITES.index(x)] if r in rows] + rows.insert(rows.index(after[-1]) + 1 if after else 0, x) datas = [] for leg in legs: @@ -1297,6 +1308,10 @@ def _render(root, env, warn, zips): d = {"leg": leg, "status": "unreadable"} else: d = {"leg": leg, "status": "no-artifact"} + for x in not_requested: + sx = d.get("suites", {}).get(x) + if sx is not None and sx.get("reason") == "not run": + sx["reason"] = "not requested" datas.append(d) loaded = [d for d in datas if d["status"] in ("ok", "no-summaries")] k = sum(1 for d in datas if d["status"] == "ok") diff --git a/.github/scripts/fhir-bench/summary_backends.py b/.github/scripts/fhir-bench/summary_backends.py index 22a3ec36a..efdb8509d 100755 --- a/.github/scripts/fhir-bench/summary_backends.py +++ b/.github/scripts/fhir-bench/summary_backends.py @@ -146,10 +146,10 @@ def import_rate(ic, bundles_ok, entries): except ValueError: imp_entries = 0 imp_warn = "" if imp_ok >= 1000 else ( - " ⚠ **import incomplete — crud/search on this leg ran on a smaller corpus " - "and are not comparable to a 1000/1000 leg** (and abandoned import requests " + " ⚠ **Batch/Transaction Import incomplete — crud/search on this leg ran on a smaller corpus " + "and are not comparable to a 1000/1000 leg** (and abandoned Batch/Transaction Import requests " "may still have been running server-side)") - print(f"\n**Import:** {imp_ok:,}/1000 bundles, {imp_entries:,} entries in " + print(f"\n**Batch/Transaction Import** (`POST /` Bundles): {imp_ok:,}/1000 bundles, {imp_entries:,} entries in " f"{ic.get('wall_seconds', '?')} s{import_rate(ic, imp_ok, imp_entries)}.{imp_warn}") # Bulk import ($bulk-submit into a fresh database, bulk-import.sh): the @@ -171,16 +171,16 @@ def bi_n(key): if bi_status == "complete": # index_seconds=0 with index_status=inline means HFS indexed while ingesting, # not that indexing was free; say so instead of printing a zero-second rebuild. - bi_ingest = f"ingest {bi.get('ingest_seconds', '?')} s" + bi_ingest = f"Bulk Import: ingest {bi.get('ingest_seconds', '?')} s" if bi.get("index_status") == "inline" or bi.get("defer_indexing") == "false": bi_phases = f"{bi_ingest}, search index built inline during ingest" if bi.get("index_status") not in ("inline", "", None): bi_phases += (f" + {bi.get('index_seconds', '?')} s rebuild of rejected types, " f"`{bi.get('index_status')}`") else: - bi_phases = (f"{bi_ingest} + search-index rebuild {bi.get('index_seconds', '?')} s, " + bi_phases = (f"{bi_ingest} + Bulk Import: index rebuild {bi.get('index_seconds', '?')} s, " f"`{bi.get('index_status', '?')}`") - print(f"\n**Bulk import (`$bulk-submit`):** {bi_n('resources_ok')}/{bi_n('resources_submitted')} " + print(f"\n**Bulk Import (`$bulk-submit`):** {bi_n('resources_ok')}/{bi_n('resources_submitted')} " f"resources in {bi.get('total_seconds', '?')} s ({bi_phases}) = " f"**{bi.get('resources_per_s', '?')} resources/s** end to end, " f"{bi.get('ingest_resources_per_s', '?')} resources/s ingest only; fresh database, " @@ -193,7 +193,7 @@ def bi_n(key): f"`Encounter?class=AMB,EMER` {bi_n('check_encounter_class')}/{bi_n('expect_encounter_class')} " + ("✓" if bi_ok else "⚠ **not every ingested resource is searchable**")) else: - print(f"\n⚠ **Bulk import (`$bulk-submit`):** `{bi_status}` — {bi.get('reason') or 'no reason recorded'} " + print(f"\n⚠ **Bulk Import (`$bulk-submit`):** `{bi_status}` — {bi.get('reason') or 'no reason recorded'} " f"(reached phase `{bi.get('phase', '?')}`; {bi_n('resources_ok')} of " f"{bi_n('resources_submitted')} resources ingested). Details in `bulk-import.log` / " "`bulk-import-hfs.log`.") @@ -292,7 +292,7 @@ def ix_s(key): print("\n**How to read this leg.** Every search is answered by Elasticsearch; the primary's " "own search index is not written. In `synchronous` mode a write returns only after " "Elasticsearch has indexed it — bundles go through a per-resource-type `_bulk` request " - "with `refresh=wait_for` against a 200ms `refresh_interval`, so **import/crud/insert latency " + "with `refresh=wait_for` against a 200ms `refresh_interval`, so **Batch/Transaction Import/crud/insert latency " "on this leg includes Elasticsearch indexing plus that refresh wait**, not just the " "primary. Every update and delete also runs a `_delete_by_query` with a forced refresh " "across all of the tenant's indices. Cluster health `yellow` is expected (1 replica per " @@ -303,13 +303,13 @@ def ix_s(key): "own search index is not written. Writes commit on the primary first. In `asynchronous` " "mode ONE background worker then forwards each resource to Elasticsearch individually " "(an index-exists check plus an index request per resource) through a 1,000-event queue " - "that blocks writers when full, so **import, crud and insert throughput on this leg is " + "that blocks writers when full, so **Batch/Transaction Import, crud and insert throughput on this leg is " "that worker's rate, not the primary's**. Every update and delete also runs a " "`_delete_by_query` with a forced refresh across all of the tenant's indices. Cluster " "health `yellow` is expected (1 replica per index, 1 node). Compare search latency with " "another leg only if both imported the same entry count and the ES drain above says " - "`drained`. **This worker's rate is expected to make import hit k6's 60-minute cap " - "before the corpus finishes, leaving the index incomplete** (see the Import and ES " + "`drained`. **This worker's rate is expected to make Batch/Transaction Import hit k6's 60-minute cap " + "before the corpus finishes, leaving the index incomplete** (see the Batch/Transaction Import and ES " "drain lines above / `es-drain.txt`; run 36412022609 imported 313/1000 bundles and " "the drain gate reported status=incomplete with 194,664 resources never indexed).") if backend.startswith("mongodb"): @@ -319,7 +319,7 @@ def ix_s(key): f"{pg_shared_buffers}; both also use the host page cache). Each FHIR " "transaction bundle is one multi-document transaction (lifetime " f"{ri.get('mongo_txn_lifetime_s', '900')} s); an aborted transaction fails that bundle's " - "`Bundle import` check — see Checks ✗ on the import row (in Results, below) and " + "`Bundle import` check — see Checks ✗ on the Batch/Transaction Import row (in Results, below) and " "`txn.aborted` in `import-mongostat.txt`.") # Result-size cross-check (F5): a composite search that silently @@ -352,7 +352,7 @@ def ix_s(key): residue_total = 0 patient_residue = cr.get("Patient", "0") print(f"\n_totals include {residue_total} crud/prewarm leftovers " - f"(Patient: {patient_residue}) and any import shortfall; a composite " + f"(Patient: {patient_residue}) and any Batch/Transaction Import shortfall; a composite " "total equal to the Observation total means the name-only fallback; " "seconds after a 000 row overlap the previous query (HFS keeps " "executing after curl's --max-time)._") @@ -421,7 +421,7 @@ def _ins_check(rt, key): if mte_n > 0: print(f"\n⚠ **Mongo transaction errors (heuristic):** {mte_n} HFS log line(s) matching " "WriteConflict/TransientTransactionError/TransactionTooLargeForCache/NoSuchTransaction/" - "commit-failed — bundle failures are the import row's Checks ✗ (in Results, below), " + "commit-failed — bundle failures are the Batch/Transaction Import row's Checks ✗ (in Results, below), " "not this count.") # Final ES sync failures (spec §15d): composite_secondary_sync_failures_total diff --git a/.github/scripts/fhir-bench/test_compare_legs.py b/.github/scripts/fhir-bench/test_compare_legs.py index 7b5fc0992..67d8ca089 100644 --- a/.github/scripts/fhir-bench/test_compare_legs.py +++ b/.github/scripts/fhir-bench/test_compare_legs.py @@ -21,12 +21,12 @@ RUN = "100" SUITES = ("prewarm", "import", "crud", "search") INSERT_ROW = "insert (creates/s)" -IMPORT = "import, `POST /` transaction Bundles" # Errors label; Throughput and p95 add a unit +IMPORT = "Batch/Transaction Import, `POST /` Bundles" # Errors label; Throughput and p95 add a unit IMPORT_ROW = IMPORT + " (resources/s)" -BULK = "bulk-import, `$bulk-submit`" +BULK = "Bulk Import, `$bulk-submit`" BULK_ROW = BULK + " (resources/s)" -INGEST_ROW = "bulk-import ingest (resources/s, seconds)" -INDEX_ROW = "bulk-import initial index (seconds)" +INGEST_ROW = "Bulk Import: ingest (resources/s, seconds)" +INDEX_ROW = "Bulk Import: index rebuild (seconds)" REINDEX = "reindex, `$reindex` Encounter" REINDEX_ROW = REINDEX + " (resources/s)" _guard = {"on": False} @@ -261,7 +261,22 @@ def test_insert_row_label_crown_and_no_corpus_marker(self): put_dir(only, "postgres", {"insert.json": summary(640.0, 120.0), "insert.log": "k6\n"}) md = render(only, ["sqlite", "postgres"], tests="insert") self.assertEqual(row(md, "Throughput", INSERT_ROW), "| insert (creates/s) | **812** | 640 |") - self.assertNotIn("| crud", md) + # crud and search are always listed, so a trimmed run does not look like a report + # that lost them + self.assertEqual(row(md, "Throughput", "crud"), + "| crud | n/a (not requested) | n/a (not requested) |") + self.assertEqual(row(md, "Throughput", "search"), + "| search | n/a (not requested) | n/a (not requested) |") + + def test_bulk_import_only_run_still_lists_crud_and_search(self): + for leg in ("sqlite", "postgres"): + put_dir(self.root, leg, {"bulk-import.txt": bulk_txt(), "bulk-import.log": "x\n"}) + md = render(self.root, ["sqlite", "postgres"], tests="bulk-import") + for table in ("Throughput", "p95", "Errors"): + for suite in ("crud", "search"): + self.assertTrue(row(md, table, suite).endswith( + "| n/a (not requested) | n/a (not requested) |"), (table, suite)) + self.assertIn(BULK_ROW, md) def test_insert_not_run_and_not_requested(self): put_dir(self.root, "sqlite", leg_files("sqlite")) diff --git a/.github/scripts/fhir-bench/test_summary_backends.py b/.github/scripts/fhir-bench/test_summary_backends.py index c813ff3f5..4e29518c2 100644 --- a/.github/scripts/fhir-bench/test_summary_backends.py +++ b/.github/scripts/fhir-bench/test_summary_backends.py @@ -48,14 +48,14 @@ def bulk_txt(**kv): class SummaryBulkImportTest(SummaryRunMixin, unittest.TestCase): def test_bulk_line_deferred_unchanged(self): out = self.summary({"bulk-import.txt": bulk_txt()}) - self.assertIn("resources in 2400 s (ingest 600 s + search-index rebuild 1800 s, " + self.assertIn("resources in 2400 s (Bulk Import: ingest 600 s + Bulk Import: index rebuild 1800 s, " "`completed`) = **679.5 resources/s** end to end, 2717.8 resources/s " "ingest only; fresh database, `defer_indexing=true`.", out) def test_bulk_line_inline(self): out = self.summary({"bulk-import.txt": bulk_txt( defer_indexing="false", index_status="inline", index_seconds=0, total_seconds=600)}) - self.assertIn("(ingest 600 s, search index built inline during ingest)", out) + self.assertIn("(Bulk Import: ingest 600 s, search index built inline during ingest)", out) self.assertNotIn("rebuild 0 s", out) self.assertNotIn("search-index rebuild", out) @@ -63,7 +63,7 @@ def test_bulk_line_inline_with_rebuild_of_rejected_types(self): out = self.summary({"bulk-import.txt": bulk_txt( defer_indexing="false", index_status="completed", index_seconds=12, total_seconds=612)}) - self.assertIn("(ingest 600 s, search index built inline during ingest + 12 s rebuild " + self.assertIn("(Bulk Import: ingest 600 s, search index built inline during ingest + 12 s rebuild " "of rejected types, `completed`)", out) self.assertNotIn("search-index rebuild", out) diff --git a/.github/workflows/fhir-benchmark.yml b/.github/workflows/fhir-benchmark.yml index fc13792c8..1c7011260 100644 --- a/.github/workflows/fhir-benchmark.yml +++ b/.github/workflows/fhir-benchmark.yml @@ -60,10 +60,11 @@ name: FHIR Server Benchmark # search-index rebuild has finished, capped by BULK_IMPORT_TIMEOUT_S and by # what is left of the leg budget; the bulk database is dropped afterwards. # The comparison reports the one load as three Throughput rows: -# `bulk-import` (resources/s over both phases), `bulk-import ingest` -# (resources/s and the seconds from kick-off until the status manifest is -# final: how long loading the corpus takes) and `bulk-import initial -# index` (seconds of the deferred search-index rebuild that follows: how +# `Bulk Import, $bulk-submit (resources/s)` (over both phases), +# `Bulk Import: ingest (resources/s, seconds)` (resources/s and the +# seconds from kick-off until the status manifest is final: how long +# loading the corpus takes) and `Bulk Import: index rebuild (seconds)` +# (seconds of the deferred search-index rebuild that follows: how # long until that freshly loaded data is indexed; `inline (during ingest)` # when HFS indexed while ingesting, HFS_BULK_SUBMIT_DEFER_INDEXING=false). # It starts no containers, so the capacity gate is unchanged. Logic in @@ -100,11 +101,16 @@ name: FHIR Server Benchmark # *-elasticsearch legs). Users never run a $reindex when they load data, and it # rewrites the search index right before insert and bulk-import, so a run that # includes it may skew both. How long freshly loaded data takes to become -# indexed is bulk-import's `initial index` row instead. Past a 240 s budget the +# indexed is the `Bulk Import: index rebuild (seconds)` row instead. Past a 240 s budget the # job is cancelled and reported partial, so it adds at most ~5 min to a leg. See # run_indexing_suite in .github/scripts/fhir-bench/suite-lib.sh. Its matrix row # is labelled `reindex, $reindex Encounter` (resources/s) and sits with the -# import (`POST /` transaction Bundles) and bulk-import (`$bulk-submit`) rows. +# Batch/Transaction Import (`POST /` Bundles; suite `import`) and Bulk Import +# (`$bulk-submit`; suite `bulk-import`) rows. +# +# The Batch/Transaction Import and Bulk Import rows are not comparable: they +# differ in numerator and denominator (committed Bundle entries per second of +# the k6 scenario vs resources until the search index covers them). # # Prerequisites on the self-hosted runner (same as hts-benchmark.yml): # • Rust toolchain buildable (clang + lld linker, configured below). @@ -139,7 +145,7 @@ on: - postgres-elasticsearch - mongodb-elasticsearch tests: - description: "Suites to run: 'all' = prewarm,import,crud,search,insert,bulk-import | comma-separated from those plus indexing (a timed $reindex; opt-in only, never part of 'all', list it after search; it rewrites the index before insert and bulk-import and may skew both). insert runs after the other k6 suites; bulk-import ($bulk-submit into a fresh database: total, ingest and initial-index rows) always runs last and can add up to ~70 min per leg; 'prewarm,import,crud,search,insert' skips it" + description: "Suites to run: 'all' = prewarm,import,crud,search,insert,bulk-import | comma-separated from those plus indexing (a timed $reindex; opt-in only, never part of 'all', list it after search; it rewrites the index before insert and bulk-import and may skew both). insert runs after the other k6 suites; bulk-import ($bulk-submit into a fresh database: total, ingest and index-rebuild rows) always runs last and can add up to ~70 min per leg; 'prewarm,import,crud,search,insert' skips it" required: false default: "all" vus: @@ -1335,7 +1341,7 @@ jobs: # 'indexing' (a timed $reindex, not a k6 suite — run_indexing_suite) # is opt-in and not in CANONICAL, so 'all' never runs it: users do # not run $reindex when they load data, and rewriting the index here - # would skew insert and bulk-import, whose initial-index row measures + # would skew insert and bulk-import, whose Bulk Import index-rebuild row measures # indexing instead. Named explicitly, it runs where `tests` lists it # (put it after search so it cannot disturb crud/search) and always # before insert and bulk-import, which are moved last below. @@ -2027,7 +2033,7 @@ jobs: print("### Results\n\n_No summary files were produced._") sys.exit(0) - # The import row is reported as upstream's report and the "Compare legs" + # The Batch/Transaction Import row (suite `import`) is reported as upstream's report and the "Compare legs" # matrix report it: resources/s, the entries of committed Bundles over the # import scenario's own seconds (import-completeness.txt `entries` and # `scenario_seconds`, k6 setup() excluded; see suite-lib.sh @@ -2078,13 +2084,13 @@ jobs: chk_fmt = f"**{chk_fmt}**" label = suite if suite == "import": - label = "import (resources/s; latency per Bundle)" + label = "Batch/Transaction Import, `POST /` Bundles (resources/s; latency per Bundle)" rps, p50, p95, p99 = import_row(m) has_import = True rps_fmt = "n/a" if rps is None else f"{rps:,.0f}" print(f"| {label} | {rps_fmt} | {p50:.1f} | {p95:.1f} | {p99:.1f} | {err_fmt} | {chk_fmt} |") if has_import: - print("\n_Throughput is requests/s and latency is per request, except on the import row " + print("\n_Throughput is requests/s and latency is per request, except on the Batch/Transaction Import row " "(resources/s and per-Bundle latency, see the **Import** line above)._") # ── How loaded the shared Docker host was ────────────────────────── @@ -2177,9 +2183,9 @@ jobs: # ──────────────────────────────────────────────────────────────────────────── # Cross-leg comparison: suites as rows, legs as columns (throughput, p95, - # errors; the import, bulk-import and reindex rows name the operation each - # times and sit together; the Throughput table also splits bulk-import into - # its ingest and initial-index rows right under it; the reindex row appears + # errors; the Batch/Transaction Import, Bulk Import and reindex rows name the + # operation each times and sit together; the Throughput table also splits + # Bulk Import into its ingest and index-rebuild rows right under it; the reindex row appears # only when a leg ran the opt-in indexing suite) and a leg-health table, so # a reader does not have to scroll six stacked per-leg summaries. # Display only: the job is continue-on-error and