Skip to content

fix(elasticsearch): a read of an index still being created waits for its primary shard (#1402) - #1430

Merged
smunini merged 3 commits into
mainfrom
fix/1402-es-fresh-index-no-shard
Sep 22, 2026
Merged

smunini merged 3 commits into
mainfrom
fix/1402-es-fresh-index-no-shard

Conversation

@smunini

@smunini smunini commented Sep 21, 2026

Copy link
Copy Markdown
Contributor

Summary

A read of an Elasticsearch index whose creation is still in flight no longer fails with a 5xx. no_shard_available_action_exception — and only that answer — gets its own bounded retry schedule on the read path (8 retries, at most 5.5 s of waiting) instead of the general 3 attempts over ~300 ms. ensure_index now also reads the create-index response and logs when the primary shard had not started by the time the request timed out.

This removes the flake in es_integration::es_integration_composite_bad_date_stays_searchable_in_every_sync_mode. No test and no test helper was changed.

Fixes #1402

Observed pre-fix behavior

search … failed: internal error in elasticsearch: Search failed after 3 attempts (status 503): …no_shard_available_action_exception…, panicking in the found_ids helper.

Reproduction, in the order tried (all with Elasticsearch 7.17.29, 256 MB heap, as the harness uses):

Recipe pre-fix post-fix
1. The single test alone, 30 runs, 48 yes > /dev/null burners on a 32-core host (load average 45–57) 0 / 30 failed
2. The whole elasticsearch_tests binary, --test-threads 32, 32 burners 0 / 3 failed with this symptom
3. The test's ES container capped to 0.25 and 0.1 CPUs (docker update --cpus) 0 / 10 failed
4. The real test, body unmodified, against an ES container started with --device-write-iops <docker disk>:60, 30 runs 3 / 30 failed, all with the message above 0 / 30
5. The test's body in a loop (3 sync modes × 30 iterations) against the same container, recording which mode failed 4 / 30 iterations failed — every one in Asynchronous mode 0 / 30

So the trigger is disk pressure, not CPU: the window is dominated by the cluster-state write and the new shard's first translog/segment fsync. That matches where the issue saw it (six ES binaries back to back, builds running) and why a quiet machine never shows it. With curl alone against the throttled container the 503 window was 470–590 ms (one of 2.3 s); unthrottled it is under ~100–200 ms.

For recipes 4 and 5 the harness was patched locally only to take an external ES address, and the pre-fix binary is this branch with MAX_NO_SHARD_RETRIES = 2, i.e. the old schedule. Neither patch is in this PR.

Root cause

The issue guessed that the test "creates a fresh tenant and index and searches it almost immediately" and that ensure_index might not wait for the primary. That is not what happens:

  • The creator does wait. ensure_index sends a plain PUT {index}; the default wait_for_active_shards=1 holds the response until the primary is started. 40 / 40 sequential create → search runs returned shards_acknowledged: true and the search 200, throttled or not. A write or search that follows a returned ensure_index does not race the allocation. (In Synchronous and Hybrid{sync_for_search} mode that is every search in the test — and those modes never failed.)
  • A reader that is not the creator does not wait. The index is in the cluster state from the moment the create request is accepted, so it has stopped being an index_not_found_exception (which HFS reads as an empty set) while its primary shard is not started yet. 20 / 20 searches sent while a create was in flight got 503 no_shard_available_action_exception for the whole window. _count answers identically, and GET _doc with no_shard_available_action_exception caused by illegal_index_shard_state_exception [RECOVERING].
  • In the composite's Asynchronous mode the sync worker runs ensure_index + the index request behind the client's write, so the test's poll loop — and in production, any search that follows the first write of a resource type, or a second HFS instance — is exactly such a reader. Three attempts over ~300 ms do not outlast a 500 ms window.
  • It is not a glob problem: the failing call is SearchProvider::search, which addresses the single index {prefix}_{tenant}_patient, and every test has its own UUID prefix, so no neighbour's allocating index can be matched. No ignore_unavailable / allow_partial_search_results change is made; dropping an unavailable index from a tenant-scoped search would return silently incomplete results, which is worse than the 503.

Fix

  • search_impl.rs: send_read_with_retry (search, count, get — the storage-side reads go through it too) takes its budget from the failure it just saw. no_shard_available_action_exception, under any status, gets MAX_NO_SHARD_RETRIES = 8 with the doubling back-off capped at 1 s: waits of 100, 200, 400, 800, 1000 × 4 ms = 5.5 s worst case, plus the requests themselves. Every other transient answer (429, 502, 503, 504, rejected execution, circuit breaker, transport failure) keeps 3 attempts / 300 ms, and a read that is already past that general budget stops as soon as the cluster answers with one of those instead.
  • schema.rs: ensure_index reads the create response and logs a warning on shards_acknowledged: false (the create request's own 30 s wait expired). Still a success: the index exists, the index request waits for the primary again, and reads now retry. The hunk sits after the existing error handling and does not touch the fix(persistence): reconcile ES index mappings at startup and retry search_count (#1335) #1347 reconcile code.
  • The write-side retry (storage.rs) is unchanged: index requests wait for the primary by themselves and do not see this answer.

Not done, deliberately: no _cluster/health?wait_for_status=yellow poll in ensure_index (the creator already waits; the racing party is a different task, which such a poll would not help), and no test-only sleep or harness wait.

Behavior changes clients can observe

  • A search / count / read that meets an index still being created waits up to ~5.5 s and answers, instead of failing with a 500 after ~300 ms.
  • A read of an index whose primary shard is genuinely lost (red index) now takes up to ~5.5 s longer to fail. The error is the same, with after 9 attempts in the message.
  • Nothing else: budgets for 429 / 5xx / unreachable are unchanged, and no result can become partial.

Verification

Ran and passed (after merging origin/main):

  • cargo test -p helios-persistence --features elasticsearch,sqlite --test elasticsearch_tests — 140 passed
  • same for elasticsearch_search_wiremock (12, 3 new), elasticsearch_bulk_wiremock (20), elasticsearch_schema_reconcile (7), elasticsearch_storage_read_wiremock (15), elasticsearch_storage_write_wiremock (19, 1 new), composite_polyglot_tests (14), composite_routing_tests (25), composite_read_your_writes (5)
  • cargo test -p helios-persistence --lib --features elasticsearch,sqlite — 1399 passed (1 new: the schedule and its 5.5 s bound)
  • cargo fmt -p helios-persistence -- --check
  • cargo +1.98.1 clippy -p helios-persistence --features elasticsearch,sqlite,postgres,mongodb --all-targets -- -D warnings with the CI allow-list
  • cargo +1.98.1 check -p helios-persistence --all-features --all-targets (every FHIR version and every backend, all test targets of the crate this PR touches)

Not completed: cargo +1.98.1 test --workspace --all-features --no-run --exclude pysof. It was attempted twice and both times died with No space left on device on the shared build disk (the second attempt's target/ reached 414 GB before the disk filled; it has been removed). Every error in the log is an I/O error — no error[E…] — and the helios-persistence test binaries this PR touches (elasticsearch_tests, elasticsearch_search_wiremock) had linked under --all-features before it stopped. The touched files contain no cfg(all(feature…)) code. CI's own run of that command is the remaining check.

New wiremock tests assert exact request counts and no timings: a read that gets four no_shard answers (one more than the general budget) then 200 succeeds with 5 requests, for both _search and _count; a shard that never starts is an Internal error after exactly 9 requests; three no_shard answers followed by a plain 503 stop at 4 requests. The 503 body is a real 7.17.29 capture. With the old schedule (MAX_NO_SHARD_RETRIES = 2) all three fail.

Found, not fixed

  • es_integration::es_system_qualified_tokens_in_chains failed once in 3 full-binary runs under CPU load, on the unmodified pre-fix binary: token_code_system_suite.rs:481 positive control subject:Patient.gender=female returned {}. An empty result, not an error — a different flake (write visibility on the chained path, at a guess; not investigated).
  • Under the 60-iops throttle one asynchronous iteration out of 90 (post-fix) never found its resource inside the test's own 10 s poll loop. That is the throttle being harsher than the test's budget, not this bug.

Stacking

Based on main; no other PR's commits.

…path

A read (`_search`, `_count`, `GET _doc`) of an index whose creation is
still in flight is answered `503 no_shard_available_action_exception`:
the index is in the cluster state from the moment the create request is
accepted - so it is no longer an `index_not_found_exception`, which reads
as an empty set - but its primary shard is started only later. The
request that creates the index waits for the primary
(`wait_for_active_shards=1`); a read from anyone else does not. In the
composite's asynchronous sync mode that "anyone else" is every search
that follows the first write of a resource type, because the sync worker
creates the index behind the write.

The read path retried that answer on the general transient schedule,
3 attempts over ~300 ms. Creation takes ~100-200 ms on an idle single
node and longer than that on a loaded one, so the search failed with a
5xx. `es_integration_composite_bad_date_stays_searchable_in_every_sync_mode`
polls a search right behind an asynchronous write and failed about one
run in five under load.

Give `no_shard_available_action_exception` alone its own bounded
schedule: 8 retries, doubling from 100 ms and capped at 1 s, at most
5.5 s of waiting. 429/502/503/504 and the other transient answers keep
the 3-attempt schedule, and a read that is past the general budget stops
as soon as the cluster answers with one of those instead.

Fixes #1402
…t started

`ensure_index` never read the create-index response. The request waits
for the primary shard by itself (`wait_for_active_shards=1` is the
default, verified: 40 of 40 sequential create-then-search runs on
7.17.29 answered `shards_acknowledged: true` and the search `200`), so
the write that follows does not race the allocation. When the wait
passes the request's 30 s `timeout`, Elasticsearch still creates the
index and answers `shards_acknowledged: false`; reads of that index then
fail until the shard starts, with nothing in the log to say why.

Log that case. It stays a success: the index exists, the index request
waits for the primary again, and the read path now retries an unstarted
shard.

Refs #1402
@codecov

codecov Bot commented Sep 21, 2026

Copy link
Copy Markdown

Codecov Report

✅ All modified and coverable lines are covered by tests.

📢 Thoughts on this report? Let us know!

@smunini
smunini merged commit 3c09d6a into main Sep 22, 2026
19 checks passed
@smunini
smunini deleted the fix/1402-es-fresh-index-no-shard branch September 22, 2026 15:10
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

Flaky ES test under load: fresh index answers 503 no_shard_available (composite_bad_date_stays_searchable_in_every_sync_mode)

1 participant