fix(kbfs): back off in waitForCompleteFlush instead of spinning

[chrisnojima]

The bug

waitForCompleteFlush (go/kbfs/libkbfs/tlf_journal.go) loops until the journal drains. It returns lastFlushErr only when it is a ServerErrorLockConflict and discards every other error:

j.signalWork()
err = j.wg.Wait(ctx)
if err != nil { return err }
_, noLock := j.lastFlushErr.(kbfsmd.ServerErrorLockConflict)
if noLock { return j.lastFlushErr }

So a flush that keeps failing — an unreachable MD or block server returning EOF — never drains the journal, returns as fast as it can fail, and gets re-signalled immediately.

That signalWork() is the second half of it: it cancels the background flusher's retry timer (tlf_journal.go:629-632), so the exponential backoff is computed and logged on every pass and never once waited on. The Retrying in 59s lines describe a wait that does not happen.

Impact

Seen in the wild: 160,586 flush attempts in 31 seconds (5,180/s) on one git TLF, which filled the 128MB kbfs log by itself — 39% of the file was these two lines:

160,586  tlf_journal.go:664  Background work error for 53ab05b7…: EOF
160,586  tlf_journal.go:670  Retrying in <n>s

The log reads like a conflict-resolution loop, but CR ran exactly once in that window, and the backoff values grow and cap correctly (251ms → … → 59.9s). The backoff object is fine; nothing waits on it. git is what hits this because waitForCompleteFlush is the single-op path (libgit/rpc.go:81).

The fix

Keep looping on a nil error — a conflict or squash pauses the journal and flushes nothing, which is the reason the loop exists — and give the loop its own exponential backoff for anything else. Retry-forever semantics are preserved, so a transient failure still recovers; it just no longer spins.

Also reads lastFlushErr under journalLock. flush's defer writes it under that lock, so the old read was a data race.

Testing

New testTLFJournalSingleOpPersistentFlushErr makes every MD put fail and counts attempts over a 2s window:

	result
without the fix	FAIL — 14,093 attempts in 2s (7,046/s)
	FAIL — 13,644 attempts in 2s (second MD version)
with the fix	ok

TestTLFJournal passes under -race with no data races. TestJournal* in libkbfs and all of kbfs/libgit pass.

One trap worth knowing for future tests in this file: testBWDelegate.OnNewState sends to an unbuffered channel, so the background loop stalls the moment a test stops calling requireNextState. An earlier version of this test reported 0 attempts both with and without the fix because of it — a false green in the dangerous direction. The test now drains delegate.stateCh in a goroutine.

🤖 Generated with Claude Code

[Copilot]

Pull request overview

This PR fixes a KBFS single-op flush hot-loop where waitForCompleteFlush could repeatedly re-signal background work and effectively cancel the flusher’s retry timer, causing extremely high flush-attempt rates under persistent failures (e.g., EOF/unreachable servers). It also eliminates a data race by reading lastFlushErr under journalLock.

Changes:

• Add a local exponential backoff inside waitForCompleteFlush for persistent flush errors, while preserving retry-forever behavior.
• Read lastFlushErr via a new getLastFlushErr() helper guarded by journalLock to avoid a race with the flusher.
• Add a regression test that forces persistent MD Put failures and asserts attempts stay bounded over a time window (including draining delegate.stateCh to avoid stalling the background loop).

Reviewed changes

Copilot reviewed 2 out of 2 changed files in this pull request and generated no comments.

File	Description
go/kbfs/libkbfs/tlf_journal.go	Adds locked access to lastFlushErr and introduces a dedicated backoff in waitForCompleteFlush to prevent spinning on persistent flush failures.
go/kbfs/libkbfs/tlf_journal_test.go	Extends shimMDServer to simulate persistent Put errors and adds a regression test to ensure finishSingleOp doesn’t trigger a hot retry loop.