Skip to content

STAC-25639: fix false-success on elasticsearch restore, plus port-forward retry - #36

Open
viliakov wants to merge 7 commits into
mainfrom
STAC-25639-elasticsearch-restore-completion
Open

STAC-25639: fix false-success on elasticsearch restore, plus port-forward retry#36
viliakov wants to merge 7 commits into
mainfrom
STAC-25639-elasticsearch-restore-completion

Conversation

@viliakov

@viliakov viliakov commented Aug 28, 2026

Copy link
Copy Markdown
Contributor

elasticsearch restore reported success while the restore had barely started, finalized, released the lock and scaled e2es/receiver-* back up mid-restore. In run 33158861069 that verdict came 11ms after _restore was accepted, and run-validation failed afterwards.

The cause was structural. Completion was inferred from the absence of active shard recoveries, which cannot separate not started, finished and failed. A longer poll interval would not have helped: the wait loop was never entered.

What changed

Completion is now positive — every index the snapshot restores must be present with all its primary shards active. The expected list is the snapshot's indices filtered by the configured STS prefixes, re-read via GetSnapshot so check-and-finalize works from a snapshot name alone.

Replicas are deliberately excluded. Requiring unassigned_shards == 0 would never finish on a cluster with fewer nodes than configured replicas, and even on the healthy 3-node nightly cluster 257 replica shards were still unassigned at the moment every primary was active — so it would also delay completion well past the point the data is queryable.

_cat/recovery cannot express this: shards queued behind the per-node recovery throttle are unassigned and absent from its output. Mid-restore it listed 14 shards while _cluster/health reported 522 unassigned. GetRestoreStatus and RecoveryInfo are replaced by GetIndicesHealth.

The wait is now bounded and survives a dropped tunnel. Polling spans the whole restore, so it must tolerate losing its port-forward — an end-to-end run lost its ES pod to infra activity and would otherwise have failed after nine good polls. Transient status errors are tolerated and the port-forward rebuilt; a one-shot check without --wait still surfaces them rather than reading a dead tunnel as a running restore.

A no-progress deadline (--no-progress-timeout, default 2h, 0 waits indefinitely) stops a stuck restore from polling until the caller's timeout with the lock held. It bounds inactivity, not total restore time, and progress is counted per primary shard so a slow multi-shard index is not mistaken for a stall.

A stall is reported as stalled, not failed. It only establishes that no progress was seen locally — the restore may still be running server-side. That distinction matters because verify-backup's retry deletes every STS index before restoring, so a "failed" verdict on a merely slow restore destroys work in flight.

check-and-finalize --finalize-only scales the deployments back up and releases the lock without reading status, for when the snapshot is gone or Elasticsearch is unreachable. It needs Kubernetes only, and is the escape hatch that replaces the unreachable NOT_FOUND branch.

Also included: the port-forward setup retry cherry-picked unchanged from stac-24630 (#35).

Reviewer notes

  • The predicate lives in cmd/elasticsearch because it needs filterSTSIndices and the configured prefixes, which the client layer cannot import; validateSnapshotState already sits there.
  • reconnectingHealthClient must never close a port-forward it did not open, or the caller's deferred close double-closes a channel. Pinned by test.
  • ClickHouse's poll loop has the same mid-flight port-forward exposure. Not touched here.
  • The two port-forward nits from review (deterministic errors are retried; the unreachable tail return) sit inside the cherry-picked commit, left byte-identical to what is merged on stac-24630.

Validation

go build ./..., go vet ./..., go test ./..., golangci-lint run --config=.golangci.yml ./... (v2.11.3, as CI pins) — all clean.

Exercised end to end against the nightly instance: a 109-index restore tracked from 0 to complete, then check-and-finalize --wait finalized it, leaving all three deployments at 1/1 with no restore-in-progress or pre-restore-replicas annotations. Response shapes and hidden .ds- index visibility were confirmed against that cluster.

https://stackstate.atlassian.net/browse/STAC-25639

…ry stages

Treating "no active recovery" as done reported success 11ms after _restore was accepted, before Elasticsearch had registered any shard recovery, so the restore was finalized and the workloads scaled back up mid-restore.

@ai-collaboration-app ai-collaboration-app Bot left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Direction is right and the tests cover the case that broke. Two things before merge.

1. Throttled allocation leaves the same false-success window. _cat/recovery never lists shards still queued for allocation, and primaries restored from a snapshot are throttled per node by cluster.routing.allocation.node_initial_primaries_recoveries (default 4). With sts*,.ds-sts_k8s_logs* well past 4 primaries per node there are instants where every registered snapshot recovery is done while further shards are still unassigned — internal/clients/elasticsearch/client.go:438-456 then returns SUCCESS and finalizes mid-restore. It is a race rather than a certainty (a reroute follows each completed recovery, so the gaps are short), but the poll runs every 10s across dozens of gaps.

The fallback you offered closes it and does not need local pattern matching — pass the pattern to ES: GET <indicesPattern>/_cluster/health, complete only when initializing_shards and unassigned_shards are 0. Queued shards are visible there and structurally invisible to _cat/recovery.

2. The trade-off you flagged is an infinite hang, not a misleading status. WaitForAPIRestore (internal/orchestration/restore/apirestore.go:29) has no deadline, and both foreground restore and check-and-finalize --wait route through it. Any permanent IN_PROGRESS — restore failed and indices dropped, or shards relocated so the recoveries become peer recoveries — now polls forever instead of terminating with a wrong success. In verify-backup that is the 12h job timeout with e2es/receiver-* still scaled down and the restore lock held. Related: NOT_FOUND in cmd/elasticsearch/check_and_finalize.go:78 is unreachable by construction now, so recovering by re-running check-and-finalize only works while the done entries persist. The health check in (1) fixes both cases; if you keep the fix minimal instead, a no-progress deadline belongs in this PR since this is what makes the state reachable.

Nits, non-blocking:

  • The retry now covers deterministic failures too (failed to get service, no pods found, no running pods); combined with the 60s readiness timeout, a hard-down service takes ~3min to fail.
  • internal/orchestration/portforward/portforward.go:80 — the tail return is unreachable for maxAttempts >= 1; a lastErr variable is the usual shape.
  • The three deleted SetupPortForward tests were the only coverage of the k8s service/pod error paths.
  • Both new comments in GetRestoreStatus explain real non-obvious why, but each is longer than the code it guards.

@ai-collaboration-app

Copy link
Copy Markdown

Follow-up on the completion signal, raised offline: check that the snapshot's indices are all present with active primaries, instead of deriving completion from recoveries.

The expected list does not need storing — GetSnapshot already returns Snapshot.Indices (client.go:68), and for Elasticsearch --operation-id is the snapshot name, so check-and-finalize can re-derive it cold. Snapshots are immutable, so there is no drift.

Local pattern matching is already solved here too: deleteAllSTSIndices filters ListIndices("*") through filterSTSIndices with the configured IndexPrefix/DatastreamIndexPrefix (cmd/elasticsearch/restore.go:206-211). Reuse that on the snapshot's index list rather than re-matching indicesPattern.

Predicate:

  • expected = snapshot indices filtered by the same STS prefixes
  • in progress while any expected index is missing, red, or initializing
  • complete when every expected index is present with all primaries active
  • error once there has been no forward progress for a bounded period

Do not require green — yellow is the steady state whenever replicas cannot be allocated (single-node nightly ES), so a green gate would never finish. Require primaries active: health != red, or per-index _cluster/health?level=indices with active_primary_shards == number_of_shards and initializing_shards == 0.

This subsumes both points in my review. Queued-but-unallocated shards are visible as unassigned primaries and structurally invisible to _cat/recovery, and "recoveries aged out after a relocation" stops mattering because presence plus active primaries is true whether the restore finished a minute or a week ago — which also removes the trade-off in the description and gives the FAILED branch something real to report.

Worth confirming two things first: that _cat/indices returns the hidden .ds- backing indices without expand_wildcards=hidden (the existing datastream handling suggests it does on your version), and that a restoring index reads as red rather than absent, since that is what separates in-progress from stuck.

…lled restores

Shard recovery is throttled per node, so queued shards are unassigned and absent from _cat/recovery: at a batch boundary every registered recovery reads done while shards remain, which still reported success early. Completion now requires each restored index to be present with all primaries active, and a no-progress deadline fails a stuck restore instead of holding the lock until the caller times out.
@viliakov

Copy link
Copy Markdown
Contributor Author

Both blocking points accepted and fixed in f21a3ac, which replaces the recovery-stage approach in c48510e.

Throttled allocation — you're right, and thanks. Queued shards are unassigned and absent from _cat/recovery entirely, so at a batch boundary every registered recovery reads done while shards remain. That run restored 87 snapshot shards, so there were several such boundaries. I had considered this and talked myself out of it by reasoning that ES creates all restored indices up front — true, but assignment is throttled, which is the part I got wrong.

Unbounded wait — agreed, and I understated it by calling it a misleading status. Added a 30-minute no-progress deadline; a stalled restore now fails instead of holding the lock with workloads down until the caller's timeout.

Completion is now: every expected index present with active_primary_shards == number_of_shards. GetRestoreStatus/RecoveryInfo are gone in favour of GetIndicesHealth.

One correction, on the unassigned_shards == 0 gate. I checked the nightly cluster before implementing:

status: green, number_of_nodes: 3, number_of_data_nodes: 3
active_primary_shards: 263, active_shards: 526
unassigned_shards: 0, initializing_shards: 0

Every index is rep: 1 at green, so that gate would in fact have completed here — the follow-up's "single-node nightly ES, yellow is the steady state" premise is wrong for this environment. I implemented the follow-up's conclusion anyway, for a different reason: this is a customer-facing CLI, and a single-node customer cluster with a replica configured would sit at unassigned_shards > 0 forever and hang on that gate. Requiring only primaries active is correct in both topologies and still closes the throttling hole, since a queued primary is not active.

Your two open questions, both confirmed against the live cluster:

  • Hidden .ds- backing indices are returned by plain _cat/indices without expand_wildcards=hidden — 76 of them. (_cat/indices/sts* also expands the data stream, so the pattern covers them twice.)
  • filterSTSIndices is exactly equivalent to indicesPattern: the real config is indexPrefix: sts / datastreamIndexPrefix: .ds-sts_k8s_logs against indicesPattern: sts*,.ds-sts_k8s_logs* — both prefix globs, so no local glob matching is needed. That retracts the objection I had put in the description.

Also worth recording: type: snapshot, stage: done rows had persisted (87 of them, hours later), so the ageing-out trade-off I flagged was narrower than I described. Moot now.

One nit is incorrect. The deleted SetupPortForward tests were not the only coverage of the k8s service/pod error paths — internal/clients/k8s/client_test.go:353,364,391 has TestClient_PortForwardService_{ServiceNotFound,NoPodsFound,NoRunningPods}, covering the same paths at the layer that owns them. The deleted ones were duplicates one layer up.

The other two port-forward nits (retrying deterministic errors, the unreachable tail return where a lastErr is the usual shape) are both fair, but they live inside the cherry-picked commit. I've left it byte-identical to what is merged on stac-24630 so it stays verifiable — happy to fix them in a separate PR.

NOT_FOUND remains unreachable, and is now redundant too: a late check-and-finalize returns SUCCESS and finalizing is idempotent. Left alone rather than widening the diff.

…earch restore

Status polling now spans the whole restore, so the tunnel dying mid-wait aborted a restore that was still running server-side: an end-to-end run lost its ES pod to infra activity and failed after nine successful polls. Transient status errors are now tolerated and the port-forward rebuilt, the unreachable NOT_FOUND branch is gone, and the interrupt hint includes the --wait it needs to finalize.
@viliakov

Copy link
Copy Markdown
Contributor Author

Validated end to end against the nightly instance, which found one more problem. 0e492e7 fixes it.

The completion fix works. A real restore of 109 indices, with --debug:

Restored 0 of 109 indices     <- first check, IN_PROGRESS (old code finalized in 11ms)
Restored 0 → 1 → 3 → 4 → 5 → 6 → 8 → 9 of 109

The counter matched an independent probe of the cluster at the same moments, and the restore finished at ready=109/109. check-and-finalize --wait then finalized correctly: all three deployments back to 1/1, no restore-in-progress or pre-restore-replicas annotations left.

What it exposed. The ES pod was restarted by infra activity mid-wait and the restore died on the next poll:

port-forward error: lost connection to pod
❌ Error: failed to check restore status: failed to get cluster health:
   dial tcp 127.0.0.1:35927: connect: connection refused

A single transient failure ended a restore that was still running server-side. This is the mid-flight tunnel death that #35 does not cover, since it only retries setup — and it never mattered before, because the buggy check finished in 11ms so there was no exposure window. Making ES actually wait created it. Status errors are now tolerated (5 consecutive) and the port-forward is rebuilt on failure; the client is bound to a fixed local port, so a dead tunnel needs a new forward and a new client. ClickHouse has the same gap on its own poll loop — not touched here.

On the throttling window — your mechanism is confirmed, the timing is not. Directly observed mid-restore:

_cat/recovery active rows: 12   (all stage=index, type=snapshot)
_cat/recovery all rows:    14
_cluster/health unassigned: 522

12 concurrent recoveries — 4 per node across 3 nodes — while ~520 shards sat queued and invisible to _cat/recovery. So the superseded approach was judging completion from a ~3% view of the work, which settles the point on its own. But in 20 samples at 15s I caught no instant where all registered recoveries were done with shards outstanding: undone sat at 12 → 8 → 4 and hit 0 only when the restore genuinely finished. So the window is real by construction but narrower than my sampling could resolve — I'm not claiming to have caught it firing.

One data point that does settle the green-vs-primaries question. At the moment all primaries were active, 257 shards were still unassigned (replicas). Gating on unassigned_shards == 0 would have kept waiting well past the point the data was queryable, on a healthy 3-node cluster — so primaries-only is the right predicate for reasons beyond the single-node case.

Also in this commit: the unreachable NOT_FOUND branch and attemptScaleUp are removed — unparam flagged the dead error return once the status values became a closed set, and deleting beat reshaping unreachable code. And PrintAPIWaitingMessage now prints --wait in its interrupt hint; without it the suggested recovery command prints status and exits without finalizing, which I hit during this run.

Full suite and golangci-lint v2.11.3 clean.

… index

Counting fully-restored indices is too coarse for stall detection: a large multi-shard index restores for a long time without completing, so a healthy restore could look stalled. Progress is now active primary shards, and the deadline is generous because a spurious failure aborts a working restore while waiting too long only delays a failure.
…urable

Restore durations vary enough per environment that a compiled-in value cannot fit all of them. Adds --no-progress-timeout to restore and check-and-finalize, defaulting to the previous 2h, where 0 waits indefinitely.
@ai-collaboration-app

Copy link
Copy Markdown

Re-reviewed through 248d4cf. The completion rewrite, the bounded wait, the per-shard stall detection (primariesActive) and the mid-flight port-forward recovery all look right, and splitting completion from liveness is the correct shape — a slow multi-shard tail no longer reads as a stall. Two smaller items left over from my earlier read that I had not posted.

1. A stall is reported as FAILED, which points the caller at the destructive action. The warning log is accurate, but the returned error is restore failed with status: FAILED. What the deadline actually establishes is "no local progress observed in the window" — the restore may still be running server-side. That matters because in verify-backup the error propagates to restore-backup.sh, whose retry runs sts-backup elasticsearch restore, which deletes all STS indices before restoring; if the restore was merely slow, the retry destroys work in flight. Worth a distinct error that says stalled and warns the restore may still be running, rather than reusing StatusFailed.

2. There is no way to release the restore lock if the snapshot cannot be read. expectedRestoredIndices fails hard when GetSnapshot fails, on the caller's client and outside the 5-error tolerance — so a transient blip at startup, or a snapshot aged out by SLM retention, ends the command. With attemptScaleUp and the NOT_FOUND branch removed, check-and-finalize is the only command in the tree that scales the deployments back up and clears restore-in-progress/pre-restore-replicas, so in that state an operator has to do it by hand. Either route that call through reconnectingHealthClient, or keep an escape hatch that finalizes without needing the snapshot.

Neither is a blocker for the bug this PR fixes. Also two optional notes: reconnectingHealthClient has no test, and its correctness rests on only closing a port-forward it opened itself (so the caller's deferred close cannot double-close) — an invariant that a later refactor breaks silently. And without --wait, a health error is now absorbed into "Restore is still in progress" and exits 0; narrow, since GetSnapshot runs first, but a dead tunnel reads as a running restore.

…iled

A stall only establishes that no local progress was seen, and verify-backup's retry deletes every STS index first.
@viliakov

Copy link
Copy Markdown
Contributor Author

All four addressed in 5c48332.

1. Stall no longer reports as FAILED. Agreed, and this was the one worth catching — I traced the chain and it lands where you said: non-zero exit → restore-backup.sh retry → sts-backup elasticsearch restoredeleteAllSTSIndices before restoring. A merely slow restore would have lost work in flight. It now returns a distinct error saying stalled and warning the restore may still be running server-side.

Implementation note: I put it through the error channel rather than adding a STALLED status, because a status still emerges from WaitForAPIRestore as restore failed with status: STALLED — the exact wording to avoid. That left StatusFailed with no producer, so it and its switch case are gone. I also changed the wait loop's wrapper from failed to check restore status: to stopped waiting for restore:, since a status function may now stop the wait deliberately; it reads correctly for ClickHouse's genuine check failures too.

2. Escape hatch added. check-and-finalize --finalize-only scales up and releases the lock without reading status. It runs before the port-forward and needs Kubernetes only, so it works when Elasticsearch is unreachable, not just when the snapshot is gone. Mutually exclusive with --wait, and --operation-id moved to PreRunE validation so it is required unless --finalize-only is set — with an aged-out snapshot you may not have the name, and forcing a dummy value through would be a poor hatch. You were right that deleting attemptScaleUp took away a capability without replacing it.

3. reconnectingHealthClient narrowed and tested. The field was es.Interface but only GetIndicesHealth is ever called, so it is now indicesHealthGetter — tighter dependency, and testable with the existing fake. Three tests cover pass-through, dropping a broken client, and repeated disconnect; the double-close invariant is pinned by asserting pf stays nil for a seeded client, so it can never close a port-forward the caller owns.

4. One-shot path surfaces errors. maxErrors is 1 when --wait is not set. Tolerance is there for long polling; on a single check it turned a dead tunnel into "still in progress" with exit 0.

Also verified on the built binary: the mutual exclusion fires, a missing --operation-id is caught before config loading, and --finalize-only is accepted without it. Full suite and golangci-lint v2.11.3 clean.

Description rewritten to describe the final state rather than the sequence of revisions.

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.

1 participant