Skip to content

fix(storage): raise LockTimeout.Default to 5 s so writers queued behind slow commits do not time out (#303) - #321

Closed
CaffeinatedCoder wants to merge 1 commit into
EntglDb:mainfrom
CaffeinatedCoder:fix/303-lock-timeout-default
Closed

CaffeinatedCoder wants to merge 1 commit into
EntglDb:mainfrom
CaffeinatedCoder:fix/303-lock-timeout-default

Conversation

@CaffeinatedCoder

Copy link
Copy Markdown
Collaborator

What was wrong

LockTimeout.Default gave every lock 500 ms (#303). A writer does not only wait for other writers' CPU work: an auto-committing InsertAsync holds the collection lock until its commit is in the WAL (in single-file mode the typed collections share one lock for the whole file, StorageEngine.CreateCollectionWriteLock), and a checkpoint holds the page-file write lock while it syncs the data file (PageFile.Flush). So the second, third, ... writer in the queue waits for one commit's I/O per writer ahead of it. When those add up to more than 500 ms the write fails with TimeoutException ("Timed out acquiring collection lock (Insert)", "commit lock (GroupCommit)", "PageFile write lock (AllocatePage)") and is rolled back. That is a healthy database being slow, and the application cannot tell it from a deadlock.

On main this already shows on shared CI disks (the flakes #302 works around in the tests). With #280 every commit batch syncs the WAL (4.5 ms mean / 7 ms p99 on Apple Silicon, tens of ms on a consumer SSD under load, hundreds when a cloud disk stalls), and the 500 ms budget becomes routine to exceed.

Mechanism

Eight writers on one collection, each commit taking 150 ms to reach the WAL: writer k waits about (k−1) × 150 ms for the collection lock. On main writers 5 to 8 wait more than 500 ms and throw:

System.TimeoutException : Timed out acquiring collection lock (Insert).
   at BLite.Core.DynamicCollection.InsertAsync(...) in DynamicCollection.cs:line 863

The async write paths wait with SemaphoreSlim.WaitAsync, which blocks no thread, so the doc comment's argument for a short timeout (not starving the thread pool) does not apply to them.

Fix

Option 1 of the issue:

  • LockTimeout.Default is now 5 s read / 5 s write (MaxConcurrentWriters stays 96). 5 s is what the WAL's own lock already uses (WriteAheadLog, MemoryWriteAheadLog, the WASM WALs all default to writeTimeoutMs = 5_000). The doc comment says why, and that a TimeoutException now means a stuck writer (a deadlock or a hung disk), not a slow one. Immediate is unchanged for callers who want SQLITE_BUSY behaviour, and LockTimeout.From(...) sets anything else.
  • The PageFileConfig.LockTimeout doc says which presets carry the default.
  • No new setting: PageFileConfig.LockTimeout already reaches every lock that waits with a lock timeout. The test below pins that, so a consumer can rely on raising or lowering it per engine.
  • One comment in StorageEngine.Dispose that quoted "WriteTimeoutMs (500 ms)" now says "(then 500 ms)".

I left the exception type (TimeoutException) and the messages as they are: catch sites keep working, and the messages already name the lock. If you would like the messages to also carry the waited time and point at PageFileConfig.LockTimeout, I can do that as a follow-up; it touches ~80 throw sites.

Option 2 of the issue (start the waiter's clock after the holder's sync) is more machinery for little gain over a budget no healthy disk reaches.

What still times out, and on what

Lock / wait Timeout after this PR From
collection locks (DocumentCollection, DynamicCollection), commit lock, metadata lock, page-file read/write/async locks, WAL lock, cross-process writer lock (.wal-shm) 5 s (read locks: ReadTimeoutMs, 5 s) PageFileConfig.LockTimeout
admission gate ("Too many concurrent writers") WriteTimeoutMs / 16 = 312 ms (was 31 ms) PageFileConfig.LockTimeout
checkpoint WAL truncation (gives up quietly, no exception) WriteTimeoutMs / 16, at least 10 ms PageFileConfig.LockTimeout
multi-process WAL catch-up in BeginTransaction (skips the replay, no exception) ReadTimeoutMs PageFileConfig.LockTimeout
in-memory and WASM engines (StorageEngine(IPageStorage, IWriteAheadLog)) 5 s, not configurable PageFileConfig.Default and the WAL's constructor default
WalSharedMemory open lock 60 s constant OpenLockTimeoutMs

Tests

New LockTimeoutDefaultTests:

  • Default_IsFiveSecondsForReadsAndWrites: LockTimeout.Default == From(5000, 5000, 96).
  • Presets_AndDetectedConfigs_UseTheDefault: Small, Default, Large, Server(path), DetectFromFile for a Small and a Large file, and the in-memory engine.
  • ConfiguredTimeout_ReachesEveryLock: a Server-layout engine opened with LockTimeout.From(1234, 2345, 7) hands it to the WAL, the main, index and per-collection page files, the admission gate, a DynamicCollection and a DocumentCollection.
  • CommitLock_WaitsForTheConfiguredWriteTimeout: with the commit lock held and a 150 ms timeout, an insert fails with "commit lock" after 100 ms to 3 s, not after the 5 s default.
  • WritersQueuedBehindSlowCommits_DoNotTimeOut: 8 writers on one collection of an in-memory engine whose WAL flush takes 150 ms (a wrapper around MemoryWriteAheadLog). The slowest writer must wait more than 500 ms (so the scenario exceeds the old default), and all 8 inserts succeed.

IndexPageReleaseTests.Dispose_WaitsForThePendingFreeCheckpoint_LongerThanTheLockTimeout asserted that the default write timeout is at most 1 s (it waits 3 × the timeout); it now opens with LockTimeout.From(500, 500) and tests the same thing.

On upstream/main (this PR's tests, LockTimeout.cs reverted): Default_IsFiveSecondsForReadsAndWrites and WritersQueuedBehindSlowCommits_DoNotTimeOut fail (the latter with the TimeoutException above, after 609 ms); the other three pass, as they should, because the setting already flows.

Mutations, each caught by the named test:

Mutation Fails
group commit waits LockTimeout.Default.WriteTimeoutMs on the commit lock CommitLock_WaitsForTheConfiguredWriteTimeout (waited 5 s)
DynamicCollection.WriteLockTimeoutMs returns the default ConfiguredTimeout_ReachesEveryLock
DocumentCollection.WriteLockTimeoutMs returns the default ConfiguredTimeout_ReachesEveryLock
WAL constructed with 5_000 instead of the config ConfiguredTimeout_ReachesEveryLock
AsStandaloneConfig (index and collection files) resets LockTimeout to the default ConfiguredTimeout_ReachesEveryLock
admission gate sized 96 instead of the config ConfiguredTimeout_ReachesEveryLock

Full suite, dotnet test tests/BLite.Tests (net10.0, macOS / Apple Silicon): 3097 passed, 0 failed, 4 skipped, 2 m 2 s. Two existing tests hold the metadata lock to provoke a timeout (VacuumTests.Vacuum_RebuildIndexes_DocumentCollection_FailedSwap_KeepsIndexAndFreesCopy, IndexBackfillTests.AddedIndex_WhoseMetadataCannotBeSaved_IsNotRegistered_AndItsPagesAreFreed); they now wait 5 s each instead of 0.5 s, included in that time.

With #280

#280 makes these waits longer (one WAL sync per commit batch), so this PR should land before it or with it. The two compose: fix/wal-fsync-on-commit merges into this branch without conflicts (git auto-merges PageFile.cs and StorageEngine.cs; the two PRs change different lines there). On that throwaway merge, the full suite gives 3103 passed, 0 failed, 4 skipped (this PR's tests plus #280's WalCommitSyncTests). That run took 12 m 3 s against 2 m 2 s here. The difference is #280's per-commit fsync on a disk other processes were loading at the time: the test host ran at 23% CPU, and stack samples showed threads in WriteAheadLog.FlushAsync → fsync, a different thread on each sample. Nothing timed out and nothing hung. WritersQueuedBehindSlowCommits_DoNotTimeOut simulates the sync with a delay, so it tests the slow-disk case on any machine, with or without #280.

Compatibility

  • No API change. The defaults of LockTimeout.Default and of every preset that uses it change from 500 ms to 5 s.
  • A caller that relied on a failure after 500 ms (its own retry loop, say) now waits up to 5 s. PageFileConfig.Default with { LockTimeout = LockTimeout.From(500, 500) } restores the old behaviour.
  • The synchronous waits (page-file ReaderWriterLockSlim, metadata lock, the multi-process catch-up in BeginTransaction) can now hold a thread up to 5 s instead of 0.5 s under contention. Under contention that long, the 500 ms default would have thrown.
  • The admission gate now waits up to 312 ms instead of 31 ms before "Too many concurrent writers".

Fixes #303

🤖 Generated with Claude Code

…nd slow commits do not time out (EntglDb#303)

A writer waits for the I/O of every writer queued ahead of it: an
auto-committing write holds the collection lock until its commit is in the
WAL, and a checkpoint holds the page-file write lock while it syncs the data
file. With 500 ms, a healthy but slow disk (and every commit once EntglDb#280 syncs
the WAL) turned those waits into TimeoutException and a rolled-back write.

LockTimeout.Default is now 5 s read / 5 s write, the same as the WAL's own
lock timeout, so a timeout means a stuck writer, not a slow one. Immediate
and From() are unchanged; PageFileConfig.LockTimeout already reaches every
lock, which the new tests pin.

Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
@mrdevrobot

Copy link
Copy Markdown
Contributor

Closing. LockTimeout.Default stays at 500 ms: per-commit fsync will be opt-in (see the review on #280), and with the default unchanged the 500 ms value holds. A longer timeout also delays the detection of a real deadlock tenfold. Applications that opt into full sync can raise the timeout through PageFileConfig.LockTimeout. #322 (an object-initializer config ending up with 0 ms) is a separate bug and stays open.

@mrdevrobot mrdevrobot closed this Oct 18, 2026

This branch was successfully deployed

1 active deployment
Production — 78dddd8f Deployed Oct 18, 2026 by CaffeinatedCoder via build_and_publish #772
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

bug Something isn't working package/core Affects BLite.Core

Projects

None yet

Development

Successfully merging this pull request may close these issues.

A commit that waits for another commit's disk sync fails with TimeoutException after 500 ms: LockTimeout.Default is tuned for an unsynced WAL

2 participants