bug: managed-workspace E2E tests intermittently fail with SQLite lock contention #3679

Activity

1. purp

   added

   help wantedExtra attention is neededExtra attention is needed

   area:buildRelated to CI/CD and buildsRelated to CI/CD and builds

   topic:testing

   on Sep 24, 2026
2. purp

   added the

   Bug

   issue type on Sep 24, 2026
3. kvnloo commented on Sep 27, 2026

   

   kvnloo

   on Sep 27, 2026

   More actions

   I can investigate this.

   I would avoid adding retries first, because that could hide whether this is a gateway persistence bug or test-level database sharing.

   My first pass would be:

   1. reproduce the two named managed-workspace tests under the same nextest concurrency;
   2. record connection acquisition, transaction start/end, and SQLite busy/lock timing around workspace creation;
   3. A/B the same workload with only the persistence operation serialized;
   4. A/B again with test-isolated databases while preserving the original concurrency.

   That should distinguish:

   • legitimate concurrent gateway writes contending on the production database;
   • an unnecessarily long transaction;
   • shared test-state contention;
   • a runner/isolation problem.

   Stop condition for the investigation: identify the lock holder/path well enough that we can reproduce it deterministically.

   I would not treat a blanket retry or a longer sleep as the fix.
4. fitzyracing1 commented on Oct 4, 2026

   

   fitzyracing1

   on Oct 4, 2026

   More actions

   @kvnloo, are you still working on this? If not, I'd like to pick it up. The ~5.1s failures match sqlx's default 5s busy_timeout (the SQLite connect options in persistence/sqlite.rs don't set one), so the MustCreate insert in the workspace create handler looks like it's waiting on another connection that holds the write lock for more than 5 seconds. My first step would be a persistence-level stress test that runs concurrent workspace creates alongside the BEGIN IMMEDIATE paths and the relaxed pool, and records which one holds the lock, before touching any timeouts.

   👀React with 👀1Reacted by Kevin Rajan
5. kvnloo commented on Oct 4, 2026

   

   kvnloo

   on Oct 4, 2026

   More actions

   Thanks for checking, and for digging into this! Please go ahead! don't wait on me. I outlined an investigation here, but I don't have a patch or reproducer to hand over.

   Your persistence-level stress test sounds like a useful next step, particularly identifying which path holds the write lock before changing timeouts. Thanks for picking this up, and sorry I didn't follow up sooner.
6. fitzyracing1 commented on Oct 7, 2026

   

   fitzyracing1

   on Oct 7, 2026

   More actions

   Thanks @kvnloo, I'll take it from here. I'll start with the persistence-level stress test to see which path holds the write lock, and I'll post what I find here before changing any timeouts.
7. fitzyracing1 commented on Oct 7, 2026

   

   fitzyracing1

   on Oct 7, 2026

   More actions

   Update from the persistence-level stress test. Short version: I don't think any single path holds the write lock for more than 5s. The failing waiter gets starved by a steady stream of short writes, and the failing build was still on the rollback journal.

   What the code shows

   • busy_timeout is never set in persistence/sqlite.rs, so it's sqlx's implicit 5s (sqlx-sqlite 0.9.0, options/mod.rs:203). That lines up with the ~5.1s failures.
   • No write transaction spans non-DB work. The only explicit write transactions are create_if_workspace_count_below and put_policy_revision_atomic (both BEGIN IMMEDIATE, DB statements only). Everything else, including the workspace MustCreate insert, is a single autocommit statement.
   • Run 36063204811 checked out exactly c8e53de, which doesn't contain perf(server): enable WAL for the SQLite store; relax sync only for SSH session issuance #3543. That gateway used the rollback journal (sqlx doesn't set journal_mode), synchronous=FULL, and the 5-connection pool, with no relaxed pool. All tests in the binary share one SQLite file on the gateway PVC.

   CI history (Branch E2E, runs created Sep 24–Oct 7, every attempt of the workspace-managed job): 494 job instances, 4 failed with database is locked. All 4 were SHAs without #3543 (2194310, e60098d, c8e53de, f155eeb), so 4 of the 21 pre-WAL instances. Of the 473 instances with WAL, none failed with database is locked.

   Stress test. 8 concurrent simulated tests (workspace create, then template BEGIN IMMEDIATE, sandbox create, put_policy_revision_atomic, status CAS updates, relaxed SSH-session create), plus readers and a batched cleanup delete. Each write is instrumented with a busy handler that copies SQLite's default backoff, so it records who waited and for how long. A slower CI disk is modeled by adding latency to each fsync through an LD_PRELOAD shim. That latency is injected, not measured from CI.

   Real Store, failed workspace creates (max workspace-create latency in parentheses):

   config	+0 ms/fsync	+20 ms	+50 ms	+100 ms
   c8e53de options (rollback journal)	0/160 (140 ms)	6/40 (5.06 s)	–	–
   main (WAL + relaxed pool)	0/160 (62 ms)	0/40 (1.86 s)	0/40 (4.14 s)	9/24 (5.02 s)

   The errors are the CI message exactly: database error: error returned from database: (code: 5) database is locked.

   Lock attribution for one failed create (rollback journal, +20 ms/fsync): it waited 5005.7 ms over 60 busy-handler retries. In that window 61 other writes committed: 31 status CAS updates, 6 policy-atomic transactions, 6 template creates, 6 workspace creates, 6 sandbox creates, 5 SSH-session creates, 1 cleanup delete. Their holds sum to about 5.0 s, and the longest single hold was 83.9 ms. Each rollback-journal commit holds the lock for about 4 fsyncs (about 82 ms at +20 ms/fsync), and a run does about 11x as many fsyncs as on WAL. SQLite's busy handler is a polling sleep that doesn't preserve arrival order, so the waiter keeps losing.

   A/B (standalone harness, same SQL, rollback journal, +20 ms/fsync, 5 runs × 8 tests):

   • baseline: 10/40 and 10/40 workspace creates failed
   • workspace-create persistence op serialized only: 0/40, but 13 reads and 2 cleanup deletes now fail with database is locked (the contention just moves)
   • isolated DB per test: 0/40, max 193 ms
   • busy_timeout 30s: 0/40, but max wait 6.9 s
   • in-process FIFO write queue: 0/40 creates, max 746 ms (reads still fail under the rollback journal)

   On WAL, the same harness fails at +100 ms/fsync (8/24) and passes with the in-process write queue (0/24, max 1.2 s).

   Takeaways

   1. perf(server): enable WAL for the SQLite store; relax sync only for SSH session issuance #3543 (WAL) most likely explains why this hasn't recurred since Sep 25. It raises the threshold a lot but doesn't remove the failure mode.
   2. Raising busy_timeout only hides the starvation. Isolating DBs per test would also hide a real gateway behavior.
   3. The change I'd propose: keep the 5s busy_timeout but set it explicitly, and queue writers in-process behind a FIFO tokio::sync::Mutex in SqliteStore. Then in-process writers wait in order instead of polling, and the busy timeout only covers contention from outside the process. With that on main: 0/24 at +100 ms/fsync (max 1.4 s), 0/40 at +50 ms (max 0.72 s), and the openshell-server lib tests pass. I'd also add the stress test as an #[ignore]d reproducer.

   I haven't run the kind-based E2E suite locally, so I don't have the repeated-run numbers the acceptance criteria ask for yet. I'd like a maintainer's view on the write-queue approach before opening a PR.
8. EmilienM commented on Oct 13, 2026

   

   EmilienM

   on Oct 13, 2026

   Contributor

   More actions

   Another data point: the new sqlite_concurrent_writes_return_their_own_resource_version test from #4408 fails with the same (code: 5) database is locked on both Windows MSVC lanes (x64 and arm64) in #4147's runs, about 8 s in. #4147 doesn't change that SQLite path, and these look like the first test:windows runs since #4408 merged. Windows runners have slow fsync, so this looks like the starvation you measured at high fsync latency, and that test could double as a reproducer for the write-queue change.