Force recovery when an old-generation backup worker fails (BackupNewAndOldRestore failure)

[saintstack]

When partitioned-log backup is enabled, each TLog generation gets a set of backup workers that pull mutations off the TLogs and upload them. When the transaction system recovers, the new generation gets fresh backup workers — but the previous generation usually still has a tail of mutations nobody has uploaded yet. So recovery also recruits workers for those leftover ranges: workers whose backupEpoch is an older generation than the recruitedEpoch they run under. They exist only to drain that tail, and they exit once they reach its end version.

Until that tail is drained, the old generation has to be kept around. oldestBackupEpoch stays pinned at it, the generation stays in oldTLogData, its TLog data cannot be popped, and the cluster does not reach FULLY_RECOVERED. All of that is by design and normally lasts a second or two.

The problem is what happened when one of those drain workers died. Every other participant in the log system is failure-monitored, but old-generation backup workers were deliberately excluded, with a comment explaining that losing one must not restart transaction-system recovery — a reasonable-sounding instinct, since they are stateless and their progress is persisted.

The catch is that recovery is the only code that ever recruits a replacement. recruitBackupWorkers runs as part of recovery, reads the backup progress records, and recruits a worker for every unfinished old range. Nothing else does. So when a drain worker died, its range simply waited for the next recovery — and if the cluster was otherwise healthy, no recovery came. The generation was then pinned forever: unbounded TLog retention, and FULLY_RECOVERED permanently out of reach. In simulation the test hangs until the trace overflows; in production you would see log data that never ages out.

How it showed up

main nightly at ddec61a629, slow/BackupNewAndOldRestore.toml seed 3263071716. Reading that trace:

• Epoch 46's tag -2:2 was re-recruited three times, at log epochs 48, 50 and 52 — each replacement recruited by the next recovery, and each one killed by an injected disk fault. The last died at t=529.24 with ErrorIsInjectedFault="1".
• Nothing recovered after that, so nothing re-recruited it. BackupWorkerPopDeferred then repeats to the end of the run with BackupEpoch="52" OldestEpoch="46" — the pin, frozen.
• fully_recovered appears four times, all before t=439, then never again through t=6134.
• With the cluster unable to quiesce, the 2.5 s backup-progress poll kept re-reading 99 stale records: 229,062 GotBackupProgress events, which eventually tripped TracedTooManyLines and aborted the run.

Relation to #13712

This reverses a tradeoff made deliberately two months ago. #13712 ("Avoid recovery on old backup worker failure", 8bc002346b38) removed exactly the monitoring this PR restores, and the comment deleted here is the one that PR left in its place. Its reason was the mirror image of mine: a drain worker's failure raises backup_worker_failed, and if recovery has not finished yet that starts another recovery generation which recruits the same unfinished work again, so repeated failures can stop the transaction system from ever completing recovery. That is an outage, it is worse than what I am fixing, and the removal was right as far as it went.

What it left behind is the pin, and its review thread said so at the time. Asked whether clusters would end up accepting_commits but never fully_recovered, the author agreed: "that is the state the clusters would end up in, and further manual intervention may be required to complete recovery, but at least an outage will be avoided if old backup workers are failing." The nightly failure above is that state arrived at by accident rather than by a failing host, and the pre-fix arm of the ensemble reached it 8 times in 1,161 runs with nobody intervening.

#13712 also named the fix it would have preferred — "detect and re-recruit the failed old-epoch worker without restarting recovery" — and described itself as "the smallest PR to fix the serious availability issue". That is the approach in the last section here, and it does not work for this failure: the monitor has to wait for FULLY_RECOVERED, which is the state a stranded generation prevents.

This is, in effect, a revert of #13712 plus a test. The loop that PR deleted sat inside if (!recoveryCompleteWrittenToCoreState.get()) and this one sits outside it, but that flag is set only when a coordinated state is written whose oldTLogData is empty, and oldTLogData stays populated whenever epoch != oldestBackupEpoch — a held backup pin is precisely what keeps the flag false. The gate is therefore open for exactly the period that matters, and the placement makes no behavioural difference. Iterating every log set in old.tLogs instead of old.tLogs[0] is likewise not a widening: old-epoch workers are only ever registered into old.tLogs[0], through getEpochLogSet, so that is defensiveness rather than extra coverage. What is genuinely new is the buggify() injection and the CODE_PROBE, without which this path is unreachable in simulation. All of that is a code reading rather than a measurement; the falsifiable form is that moving the loop back inside the gate should reproduce the ensemble result above, and if it hangs instead the reading is wrong.

The change

Monitor those workers like everything else. A failure now raises backup_worker_failed, which forces a recovery, and recovery's existing recruitBackupWorkers re-recruits the unfinished range. The repair is the mechanism FDB already has; this only makes it reachable.

Two details worth pointing out, since both look like mistakes if you skim:

It is not gated on !recoveryCompleteWrittenToCoreState, unlike the old-log-router monitoring immediately below it. That felt wrong to me at first too, and on a closer read the gate would not have excluded the wedge anyway — the pin is what holds that flag false, so the placement is not what makes this work. See "Relation to #13712" above. The earlier attempt that genuinely never ran was gated on recoveryState >= FULLY_RECOVERED, which a stranded generation never reaches.

Only unfinished work forces a recovery. A worker that drains its range sends BackupWorkerDone, and removeBackupWorker erases it from the log set — the same list this monitors. So the common case, a worker that finished and then went away, costs nothing. We only pay a recovery when there is genuinely a range left to redo.

Why you can believe it works

Nothing in simulation ever failed one of these workers on its own — zero occurrences across a 100,000-run ensemble — which is why the bug survived so long and why a fix could not be tested as-is. So the PR also adds a buggify()-gated io_error for a worker draining an older generation, plus a CODE_PROBE on detection so an ensemble can report whether the repair ran.

With that injection, one binary and one seed, monitoring switched at runtime (comparing seeds across two different binaries is meaningless — any code change reshuffles the simulation schedule):

monitoring	result	recovery attempts	last fully_recovered	ran to	PopDeferred
off	fails (SIGABRT)	6	t=150	18,873 simsec	1,843 — pinned at OldestEpoch=10 vs BackupEpoch=12
on	passes	9	—	435 simsec	3

The off leg is the nightly failure reproduced, signature and all. The on leg passes in a normal amount of time.

The cost is visible in that same table: three injected deaths produced three extra recovery attempts, one each. And in runs where no drain worker dies, the counts are identical with and without the change (5 attempts / 4 fully_recovered either way), so healthy clusters see no difference.

At scale. One binary, two tomls differing only by a knob that switches the monitoring, both arms in a single ensemble:

arm	runs	failures
monitoring off (pre-fix)	1,161	8
monitoring on (the fix)	1,178	0

All eight hung: every one reports SimElapsedTime="5401" against the 5400 s cap, failing with SetupAndRunError (timeout) plus ConsistencyCheckFailure and QuietDatabaseFailure — a cluster that cannot quiesce, which is what a pinned generation produces and what seed 80 showed at trace level. No asserts, no crashes: 8 for 8, the same failure mode. The fix arm's single failure is unrelated: it ran with backup_worker_enabled:=0, so this code cannot execute, and it died on an unrelated assert in flow/Trace.cpp:569 (removeRole). Fisher exact for 8/1,161 versus 0/1,178 is about 0.005.

That ensemble used a deterministic three kills per run rather than the shipped buggify() rate, so it exaggerates the fault load — deliberately, to make a rare coincidence observable at 2,300 runs instead of 100,000.

slow/BackupNewAndOldRestore.toml also ran 100,000 / 100,000 clean with the patch and the normal buggify rate.

Provenance, since this branch was rebased across 280 upstream commits mid-investigation: the ensemble above and the seed-34 spot check were run on the rebased code; the single-seed table and the 100,000-run clean sweep were measured at the previous base, ddec61a629. Those carry over because LogSystem::onError's failure-set logic is identical between the two bases — no upstream edit touches any waitFailureClient, backupFailed, routerFailed or recoveryCompleteWritten line.

Risk, stated honestly

Recovery creates the very population this monitors, so a host that reliably kills backup workers could produce recovery, drain workers, another death, recovery again. The loop rate is bounded by BACKUP_TIMEOUT detection plus recovery duration, and the identical exposure already exists for current-generation backup workers, whose failures have always forced recovery. But it is the thing to push back on if you are going to push back on something.

The loop cannot spin without making progress, though. recruitBackupWorkers recruits only ranges that still have work left — getUnfinishedPartitionedBackup — and resumes each one at savedVersion + 1, so any cycle in which the worker persisted progress before dying strictly shrinks the remaining range, and the loop ends when the range drains. That bounds the number of recoveries, not just their rate. The case that makes no progress is a worker that dies before its first progress save on every attempt, which needs a host failing deterministically — and recruitBackupWorkers already converts a worker that will not come up into backup_worker_failed, so recovery aborting on an unhealthy backup worker is existing behaviour rather than something this adds.

What is not measured is how often the trigger occurs in the field. The failure needs a coincidence — the last of several deaths landing after the final natural recovery — which is why the nightly hit it roughly once in 100,000 runs.

An approach that did not work, in case someone suggests it

My first attempt avoided recoveries altogether: a cluster-controller actor that re-recruited the dead worker directly (~210 lines — monitorAndRecruitBackupWorkers, a worker-id→tag map on ClusterRecoveryData, LogSystem::addBackupWorker, and a knob). Modelled on monitorAndRecruitLogRouters, it waited for recoveryState >= FULLY_RECOVERED before monitoring anything.

That is exactly the state a stranded generation prevents, so the monitor slept precisely when it was needed. Measured, with a kill injected: monitoring ended at t=121.85, the workers died at t=126.41–126.67, the monitor never started again, and the run failed with PopDeferred×1886. Reusing recovery is both smaller and correct, because recovery already owns re-recruitment.

[foundationdb-ci]

Result of foundationdb-pr-clang-ide on Linux RHEL 9

• Commit ID: 6193ffe
• Duration 0:20:30
• Result: ✅ SUCCEEDED
• Error: N/A
• Build Log terminal output (available for 30 days)
• Build Workspace zip file of the working directory (available for 30 days)

[foundationdb-ci]

Result of foundationdb-pr-macos-m1 on macOS 14.x

• Commit ID: 6193ffe
• Duration 0:31:38
• Result: ✅ SUCCEEDED
• Error: N/A
• Build Log terminal output (available for 30 days)
• Build Workspace zip file of the working directory (available for 30 days)

[foundationdb-ci]

Result of foundationdb-pr-macos on macOS 14.x

• Commit ID: 6193ffe
• Duration 0:47:26
• Result: ✅ SUCCEEDED
• Error: N/A
• Build Log terminal output (available for 30 days)
• Build Workspace zip file of the working directory (available for 30 days)

[foundationdb-ci]

Result of foundationdb-pr-clang-arm on Linux RHEL 9

• Commit ID: 6193ffe
• Duration 0:50:11
• Result: ✅ SUCCEEDED
• Error: N/A
• Build Log terminal output (available for 30 days)
• Build Workspace zip file of the working directory (available for 30 days)

[foundationdb-ci]

Result of foundationdb-pr-clang on Linux RHEL 9

• Commit ID: 6193ffe
• Duration 0:55:32
• Result: ✅ SUCCEEDED
• Error: N/A
• Build Log terminal output (available for 30 days)
• Build Workspace zip file of the working directory (available for 30 days)

[foundationdb-ci]

Result of foundationdb-pr on Linux RHEL 9

• Commit ID: 6193ffe
• Duration 1:01:41
• Result: ✅ SUCCEEDED
• Error: N/A
• Build Log terminal output (available for 30 days)
• Build Workspace zip file of the working directory (available for 30 days)

[foundationdb-ci]

Result of foundationdb-pr-cluster-tests on Linux RHEL 9

• Commit ID: 6193ffe
• Duration 1:44:43
• Result: ✅ SUCCEEDED
• Error: N/A
• Build Log terminal output (available for 30 days)
• Build Workspace zip file of the working directory (available for 30 days)
• Cluster Test Logs zip file of the test logs (available for 30 days)

[saintstack]

Closing in favor of #14240. This issue 'fixed' restoration of old-generation backup workers on failure by undoing #13712.