Fix silent pre-listen hang and silent wrong-recovery on --recover (#2076) by badrishc · Pull Request #2093 · microsoft/garnet

Badrish Chandramouli (badrishc) · 2026-08-30T05:20:59Z

Fixes #2076

Symptom

GarnetServer --recover hangs before binding its listen socket. Threads spin at 100% CPU, the underlying exception is swallowed, and nothing is logged at the default Warning level. Orchestrators see a live process that never becomes available, and there is no diagnostic to act on.

Root cause

Two independent defects compose into the reported failure. The first turns a lost or failed I/O into an infinite spin; the second guarantees that spin is silent.

1. `ScanIteratorBase.BufferAndLoad` is not failure-atomic (primary)

BufferAndLoad claims a frame with a CAS on nextLoadedPages[nextFrame], replaces loadCompletionEvents[nextFrame] with a fresh unset CountdownEvent(1), and then defers the actual read through epoch.BumpCurrentEpoch(() => DoReadPage(frameIndex)).

If DoReadPage threw synchronously (device open failure, missing segment, sharded-device dispatch error), the old code decremented pendingDrainCallbacks and rethrew. That left three pieces of broken state:

nextLoadedPages[nextFrame] stayed claimed while loadedPages[nextFrame] stayed -1, so NeedBufferAndLoad's while (true) loop spun forever at 100% CPU.
The fresh unset CountdownEvent was never signalled, so every WaitForFrameLoad waiter parked permanently.
The rethrow escaped into LightEpoch.Drain, aborting an arbitrary unrelated thread's drain pass.

This sits directly on the --recover critical path. Garnet always sets FastCommitMode = true, and TsavoriteLog.RestoreLatestAsync runs its fast-commit scan with HeadAddress = long.MaxValue, which forces a disk read on every recovery.

Fix: DoReadPage's catch no longer rethrows. It calls the new FailFrameLoad, which installs a fresh unset CountdownEvent(1) and cancels the frame's CTS — exactly mirroring the pre-existing async error path — then decrements pendingDrainCallbacks. The failure is surfaced to the caller instead of deadlocking the scan.

Because LightEpoch.BumpCurrentEpoch(Action) can throw either before or after it registers the action (and the caller cannot tell which), an unconditional catch-and-repair would double-decrement pendingDrainCallbacks. A per-claim frameRepairLatch (Interlocked.Exchange) ensures exactly one of the catch block or DoReadPage performs the repair.

2. Recovery-path waits were untimed and unlogged (amplifier)

Bare catch { } blocks in TsavoriteLog.RestoreLatestAsync/RestoreSpecificCommitAsync, Recovery.cs, and the database managers discarded the reason for failure. Combined with defect 1, the operator gets a silent hang instead of an error.

Fix: those catches now log (naming the offending token/commit), the database managers log recovery errors at Error rather than Information, and ScanIteratorBase.Dispose's spin emits a rate-limited warning naming the stuck frame.

3. Silent wrong-recovery in `RestoreSpecificCommitAsync`

RestoreSpecificCommitAsync wrapped both the metadata load and the fast-commit scan in bare catch { }, and verified the recovered commit number only with a Debug.Assert. In Release, recovering to a non-existent commit number succeeded silently and returned a different commit's data.

The existing "non-existent commit throws" test in LogTests.cs runs with FastCommitMode unset, so it only ever reaches the early if (!fastCommitMode) throw guard. Garnet always enables fast commit, so that configuration had zero coverage. Verified empirically in Release: RecoverAsync(4) returned commit 1's data without error.

Fix: the Debug.Assert is now a runtime check that throws, and the scan catch logs and rethrows.

4. Metadata read errors were ignored

DeviceLogCommitCheckpointManager.ReadInto never inspected the I/O error code (only WriteInto did). A failed metadata read was logged but the caller then parsed the uninitialized pooled buffer as checkpoint metadata. Now checked and thrown; also adds a MaxMetadataSize bound and using var device.

ReadInto rounds its length up to a sector boundary, so it deliberately over-reads: Windows reports that as ERROR_HANDLE_EOF (38) while Linux just returns a short read. End-of-file is therefore excluded from the fatal check, and the pooled buffer is cleared before the read so untransferred bytes read back as deterministic zeros instead of another caller's stale metadata. That removes the stale-buffer hazard on both platforms rather than only reporting it on one.

CI caught this: an earlier revision treated any non-zero error code as fatal, which broke the checkpoint-family cluster suites on windows-latest (the failed read left servers without a clean shutdown, so files stayed locked and TearDown reported Timed out DeleteDirectory (primary failure — test itself passed)). MetadataReadToleratesEndOfFile covers it and fails with the previous check in place.

5. Sharded-device dispatch could strand callbacks

ShardedStorageDevice.ReadAsync/WriteAsync dispatched to each shard without a guard. A throw from a later shard skipped the remaining callbacks, leaving the caller's countdown permanently short. Per-shard dispatch is now wrapped so every shard's completion is accounted for.

Native (C++) changes

Three concerns belong below the managed layer and are fixed there, in libs/storage/Tsavorite/cc/src/device/:

file_linux.cc — QueueIoHandler::QueueRunFor and UringIoHandler::QueueRunFor now set_last_error on an out-of-range context index or a null context, and report genuine io_getevents failures with strerror. Previously these returned an opaque negative value with no diagnosis.
file_linux.cc — libaio's drain path now normalizes -EINTR to 0. Without this a benign signal is indistinguishable from a broken ring. The submit paths already did this; only the drain path was missing it.
native_device.h — wires up handler_.initialized(), which was previously dead code, as a second constructor gate. This enforces the "no device with zero I/O contexts" invariant natively.

Prebuilt binaries for all 6 RIDs were regenerated by the native-build.yml workflow (run 33289058905) and are included in commit 1b57a6d84. I verified the published binaries contain the new diagnostic string literals, and that the libaio-only variant correctly lacks the io_uring symbols.

The managed actualIoContexts < 1 clamp in NativeStorageDevice is reduced to a thin ABI-skew guard now that the invariant is enforced natively.

Publication race in `NativeStorageDevice` (found while testing)

The completion-drainer threads were .Start()ed before Volatile.Write(ref nativeDevice, ...) published the handle, so early drain passes could observe a null handle. On an unmodified --recover boot on my machine this produced 17 previously-silent undrainable-ring events. Passing the handle by value to CompletionWorker takes it to 0.

NativeStorageDevice also now detects a persistently undrainable ring, backs off, and reports it (rate-limited, relaying the native error message) rather than spinning silently.

Testing

New tests (libs/storage/Tsavorite/cs/test/):

Test	Covers
`ScanTerminatesWhenPageReadThrowsSynchronously`	Defect 1 — the infinite spin
`ScanDoesNotReturnStaleDataWhenReadAheadPageFails`	8 failure ordinals, unique per-entry payloads, strict ordering + no-duplicate assertions
`ShardedReadCompletesWhenLaterShardThrows` / `ShardedWriteCompletesWhenLaterShardThrows`	Defect 5, both directions
`FastCommitRecoverToMissingCommitNumThrows`	Defect 3 — the silent wrong-recovery
`MetadataReadFailureIsReportedRatherThanReturningGarbage`	Defect 4
`MetadataReadToleratesEndOfFile`	Defect 4 — benign sector-rounded over-read must not be fatal

Supporting fault-injection devices added to SimulatedFlakyDevice.cs: SyncThrowOnReadDevice, SyncThrowOnWriteDevice, ErrorCodeOnReadDevice.

Each new test was verified to fail when the corresponding fix is neutralized.

Suite results against the CI-published binaries: Tsavorite.test 290 passed, Tsavorite.test.recovery 204 passed, Garnet.test 1046 passed. Live end-to-end checkpoint → --recover verified on both libaio and io_uring backends.

Reviews

Audited by Gemini 3.1 Pro and GPT-5.6 in addition to my own pass. Gemini verified the analysis with no significant findings; GPT raised 5 issues, of which 4 are fixed here and 1 is deliberately deferred (below). Verifying GPT's findings is what surfaced defect 4.

Notes / follow-ups

A follow-up issue is warranted for a terminal faulted device state that proactively cancels outstanding I/O. GPT recommended it; I deliberately scoped it out because it requires per-device I/O tracking that does not exist today plus a rework of Dispose ordering — too risky for a bug fix.
The native C++ changes have no unit coverage; there is no C++ test harness in cc/ (no gtest, no add_test).
The reporter's observation that the hang is libaio-specific is still only partially explained. The one concrete code-level asymmetry is that io_uring's QueueRunFor always returns non-negative, while libaio's return ret ? ret : n; could hand back a raw negative errno. Both backends now go through the same normalization and diagnosis.
CommitRecordBoundedGrowthTest(LocalMemory,-1) and NetworkTests.NetworkExceptions are pre-existing load-sensitive flakes, not regressions. Both were A/B-confirmed against a pristine c9607605b worktree at comparable failure rates (NetworkTests: 1/4 pristine vs 1/3 this branch). Neither touches code changed here — CommitRecordBoundedGrowthTest fails inside RecoveryStatus.WaitReadAsync, a different mechanism from ScanIteratorBase.
Many Garnet.test fixtures are Parallelizable yet bind the same fixed TestUtils.EndPoint (127.0.0.1:33278). One full-suite run on this branch hit a collision cascade (9 failures, 5 of them inside a single fixture, with signatures like reading another fixture's data, SocketClosed, and GarnetClientDisposedException). Two other full runs on this branch were clean at 1046/1046, and the implicated AofShardedTxnRecoveryTests passes 10/10 in isolation. Worth a separate issue to give fixtures unique endpoints.
numBytes is not populated uniformly across IDevice implementations. NativeStorageDevice reports 0 on a successful read (confirmed by instrumentation: a 4-byte request rounded to 512 came back transferred=0, errorCode=0). Short-read detection must not be built on it, so truncation is detected from the metadata length prefix instead. The hazard is now documented on the DeviceIOCompletionCallback contract; fixing the inconsistency at its source is worth a separate issue.
The Garnet.test.vectorset / Garnet.test.cluster.vectorsets jobs are pre-existing flakes, failing on 9 of the 12 most recent main runs with a different test each time (HSCANAsync, MigrateVectorSetWhileModifyingAsync, ConcurrentVaddToSpilledSetMakesProgress). The Garnet.test.cluster.replication.tls failure fails inside PopulatePrimaryWithObjects with a MOVED/unassigned-slot topology race, before any checkpoint work; that suite passes 103/103 locally in CI's Release configuration.
Correction to commit 75c712f8's message, which claimed a ScanIteratorBase.Dispose deadlock fix. There is no such deadlock: BufferAndLoad's CAS loop does not return until the deferred read action has run, and pendingDrainCallbacks is incremented only there, so a non-zero count in Dispose is always I/O in flight, never a queued drain action. The epoch drain added there could not release anything and was removed in be8fc8d1; the periodic stall report is what surfaces a device that never delivers a completion.

Copilot

Pull request overview

Fixes silent recovery hangs and incorrect fast-commit recovery by making storage failures observable and failure-safe.

Changes:

Repairs scan-frame state after synchronous I/O failures.
Validates recovery metadata and requested commits.
Improves native-device diagnostics and adds fault-injection tests.

Reviewed changes

Copilot reviewed 14 out of 26 changed files in this pull request and generated 4 comments.

Show a summary per file

File	Description
`LogFastCommitTests.cs`	Tests missing fast commits.
`FlakyDeviceTests.cs`	Tests scan and metadata failures.
`BasicStorageTests.cs`	Tests sharded synchronous failures.
`SimulatedFlakyDevice.cs`	Adds fault-injection devices.
`TsavoriteLog.cs`	Hardens fast-commit recovery.
`Recovery.cs`	Logs unreadable checkpoints.
`DeviceLogCommitCheckpointManager.cs`	Validates metadata reads and sizes.
`ShardedStorageDevice.cs`	Accounts for failed shard dispatches.
`NativeStorageDevice.cs`	Improves drainer publication and diagnostics.
`ScanIteratorBase.cs`	Makes page-load failure handling atomic.
`native_device.h`	Enforces initialized I/O handlers.
`file_linux.cc`	Diagnoses drain failures and handles `EINTR`.
`SingleDatabaseManager.cs`	Elevates recovery error logging.
`MultiDatabaseManager.cs`	Elevates checkpoint and AOF errors.

💡 Add a code-review agent skill or configure MCP servers for context-aware, tailored reviews. Learn more in the docs.

) A GarnetServer started with --recover could hang before binding its listen socket, spinning at 100% CPU with nothing logged at the default Warning level. Orchestrators saw a healthy-looking process that was permanently unavailable. Two composing defects, plus several adjacent silent-failure paths found while tracing them. ScanIteratorBase was not failure-atomic. BufferAndLoad claims a frame via nextLoadedPages, then defers the read through BumpCurrentEpoch. When the read threw synchronously, the old code decremented pendingDrainCallbacks and rethrew, leaving the frame claimed while loadedPages stayed -1: the CAS loop spun forever, waiters parked on a completion event nothing would signal, and the exception escaped into an unrelated thread's drain pass. Failures now repair the frame via FailFrameLoad, which installs the same unset-event plus cancelled-token state an asynchronous failure already produces, so the existing WaitForFrameLoad guard is unchanged and valid frames are never skipped. BumpCurrentEpoch can throw both before our action is registered and after, and the caller cannot tell which. An interlocked latch makes the repair idempotent so the frame is repaired exactly once on either ordering. Garnet always sets FastCommitMode = true, and RestoreLatestAsync runs its fast-commit scan with HeadAddress = long.MaxValue, so every --recover forces a disk read and puts this code on the pre-listen critical path. RestoreSpecificCommitAsync swallowed metadata and scan failures, leaving only a Debug.Assert to verify the recovered commit number. In release builds, which is where recovery actually runs, a failed scan silently recovered an OLDER commit. The check is now enforced at runtime. DeviceLogCommitCheckpointManager.ReadInto never inspected the IO callback's error code, so a failed metadata read returned whatever the pooled buffer held and the caller parsed it as checkpoint metadata. Native side: the libaio and io_uring drain paths now record why a drain was refused, normalize -EINTR to zero so a benign signal is not reported as a broken ring, and NativeDeviceImpl gates construction on handler_.initialized(). The managed drainer reports any undrainable ring rather than only a fully undrainable range, and takes the device handle by value to close a publication race that left drainers polling a not-yet-published handle. Remaining recovery paths that swallowed exceptions now log, and recovery errors are logged at Error rather than Information so they are visible by default. Tests: regression coverage for synchronous read and write failures in scan and sharded devices, stale-frame detection using unique payloads with strict ordering assertions, fast-commit recovery to a missing commit number, and metadata read failure reporting. Each new test was verified to fail with its corresponding fix neutralized. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> Copilot-Session: 74768ba7-7f07-408b-8385-19be319e7820

Regenerated by the Build Native Device workflow (run 33289058905) from the native sources on 'badrishc/fix-recovery-hang-2076'.

ReadInto rounds its length up to a sector boundary, so it routinely asks for more bytes than the metadata file holds. Windows reports that over-read as ERROR_HANDLE_EOF (38) while Linux simply returns a short read, so the new "any non-zero error code is fatal" check turned every Windows read of a sub-sector metadata file into a thrown exception. That broke the checkpoint-family cluster tests on windows-latest: the failed metadata read left servers without a clean shutdown, so the files stayed locked and TearDown reported "Timed out DeleteDirectory (primary failure -- test itself passed)". Exclude end-of-file from the fatal check, and clear the pooled buffer before the read so the bytes that were not transferred read back as deterministic zeros instead of another caller's stale metadata. That keeps the original intent -- a genuine device error must not be parsed as checkpoint metadata -- while removing the stale-buffer hazard on both platforms rather than only reporting it on one. Add MetadataReadToleratesEndOfFile, which fails with the previous check in place. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> Copilot-Session: 74768ba7-7f07-408b-8385-19be319e7820

FastCommitRecoverToMissingCommitNumThrows asserted TsavoriteException, but which exception reports the missing commit is platform dependent. Where the forward scan runs off the end of the written region the read fails and WaitForFrameLoad rethrows the resulting OperationCanceledException -- pre-existing behavior, kept because callers look for an OCE -- while otherwise the scan completes without finding the commit and the commit-number check rejects it. Windows takes the first path and failed the assertion. Assert on the guarantee instead: recovery must not succeed, must not fall back to an earlier commit's data, and must report one of those two failures. Neutralizing the scan catch's rethrow still fails this test (RecoverAsync returns null having silently recovered commit 1), so it continues to guard the fix it was written for. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> Copilot-Session: 74768ba7-7f07-408b-8385-19be319e7820

Drain the epoch while waiting in ScanIteratorBase.Dispose. A page read deferred onto the drain list only runs when some thread drains the epoch; if the disposing thread holds the epoch and is the only participant, the existing spin on pendingDrainCallbacks never terminates. This is the same class of silent unbounded wait this PR removes elsewhere. Also from PR review: - TsavoriteLog.RestoreSpecificCommitAsync resets the recovery-state sentinels before both failure exits, matching the restore-failure path. - DeviceLogCommitCheckpointManager.ReadInto rejects a successful read that transferred fewer bytes than the caller asked for, so a truncated metadata file is reported rather than parsed from a zeroed buffer. - NativeStorageDevice rate-limits broken-drain reporting on elapsed time rather than poll count, so the interval does not depend on poll rate. - New ScanIteratorEpochFailureTests covers the frame-claim accounting when the epoch bump throws before and after the page-read action is registered, and when issuing the read throws. - FlakyDeviceTests writes metadata before the healthy-read assertion, which previously read a file that was never written. Comments across the change are condensed to state current behavior. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> Copilot-Session: 74768ba7-7f07-408b-8385-19be319e7820

The previous commit rejected a metadata read whose reported transfer count was smaller than the requested size. That count is not part of the IDevice contract in practice: NativeStorageDevice reports 0 bytes transferred on a successful read, so every checkpoint metadata read through it was rejected. This broke recovery in the cluster replication and multilog suites, where the resulting device churn then exhausted the process's aio contexts and surfaced as io_setup EAGAIN. Detect the same condition from data the reader already has. ReadInto clears its buffer before reading, so a file that is empty or shorter than its length prefix yields a length of zero; ThrowIfInvalidMetadataSize now rejects zero alongside negative and oversized lengths, naming the file. TruncatedCommitMetadataIsRejected covers this through GetCommitMetadata with a device that reports a successful but empty read. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> Copilot-Session: 74768ba7-7f07-408b-8385-19be319e7820

The test wrapped the checkpoint device to simulate an empty read. The wrapper reimplemented segment routing and misrouted reads on Windows, so even the healthy round-trip failed there. Write a genuine zero-length commit instead, which produces the same zero length prefix through the real write path on every platform. Give the manager its own directory: TestUtils.MethodTestDir is keyed on the method name alone, so a parallel fixture with a same-named method shares it. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> Copilot-Session: 74768ba7-7f07-408b-8385-19be319e7820

ZeroLengthCommitMetadataIsRejected built its manager with deleteOnClose, so Commit's device deleted the commit file on dispose and the healthy round-trip read back an empty file. Use the default the production configuration and the other commit-metadata tests use. Also document that numBytes is not populated by every IDevice implementation. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> Copilot-Session: 74768ba7-7f07-408b-8385-19be319e7820

BufferAndLoad's CAS loop does not return until the deferred read action has run, and pendingDrainCallbacks is incremented only there, so a non-zero count in Dispose is always I/O in flight rather than a queued drain action. Draining the epoch could not release it. The periodic stall report is what surfaces a device that never delivers a completion. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> Copilot-Session: 74768ba7-7f07-408b-8385-19be319e7820

…ery on --recover (microsoft#2076/microsoft#2093), bump 2.1.6

Copilot AI balanced review requested due to automatic review settings August 30, 2026 05:20

Copilot started reviewing on behalf of Badrish Chandramouli (badrishc) August 30, 2026 05:21 View session

Copilot AI reviewed Aug 30, 2026

View reviewed changes

Badrish Chandramouli (badrishc) marked this pull request as draft August 30, 2026 17:27

Badrish Chandramouli (badrishc) marked this pull request as ready for review September 8, 2026 15:12

Badrish Chandramouli (badrishc) and others added 9 commits September 8, 2026 08:13

[Tsavorite] Update prebuilt native device binaries

9b2343b

Regenerated by the Build Native Device workflow (run 33289058905) from the native sources on 'badrishc/fix-recovery-hang-2076'.

Badrish Chandramouli (badrishc) force-pushed the badrishc/fix-recovery-hang-2076 branch from be8fc8d to 821db70 Compare September 8, 2026 15:21

Ted Hart (TedHartMS) approved these changes Sep 8, 2026

View reviewed changes

Badrish Chandramouli (badrishc) merged commit d20d639 into main Sep 8, 2026
461 of 463 checks passed

Badrish Chandramouli (badrishc) deleted the badrishc/fix-recovery-hang-2076 branch September 8, 2026 21:28

x@01 (x-at-01) added a commit to webc-fork/garnet that referenced this pull request Sep 9, 2026

merge: upstream 2026-09-08 — fix silent pre-listen hang & wrong-recov…

b946e14

…ery on --recover (microsoft#2076/microsoft#2093), bump 2.1.6

Khoren Mansuryan (khoren-mansuryan) mentioned this pull request Oct 9, 2026

2.2.1: --recover still blocks pre-listen forever when every libaio completion ring is undrainable (seccomp EPERM on io_pgetevents) — the drainer now reports it but nothing fails the pending I/O #2228

Open

Navigation Menu

Repository navigation

Fix silent pre-listen hang and silent wrong-recovery on --recover (#2076) - #2093

Fix silent pre-listen hang and silent wrong-recovery on --recover (#2076)#2093
Badrish Chandramouli (badrishc) merged 9 commits into
mainfrom
badrishc/fix-recovery-hang-2076

Badrish Chandramouli (badrishc) commented Aug 30, 2026 •

edited

Loading

Uh oh!

Copilot AI left a comment

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants

Conversation

Badrish Chandramouli (badrishc) commented Aug 30, 2026 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Symptom

Root cause

1. ScanIteratorBase.BufferAndLoad is not failure-atomic (primary)

2. Recovery-path waits were untimed and unlogged (amplifier)

3. Silent wrong-recovery in RestoreSpecificCommitAsync

4. Metadata read errors were ignored

5. Sharded-device dispatch could strand callbacks

Native (C++) changes

Publication race in NativeStorageDevice (found while testing)

Testing

Reviews

Notes / follow-ups

Uh oh!

Copilot AI left a comment

Choose a reason for hiding this comment

Pull request overview

Reviewed changes

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants

Badrish Chandramouli (badrishc) commented Aug 30, 2026 •

edited

Loading

1. `ScanIteratorBase.BufferAndLoad` is not failure-atomic (primary)

3. Silent wrong-recovery in `RestoreSpecificCommitAsync`

Publication race in `NativeStorageDevice` (found while testing)