Files: HTTP 500 'files Index update failed' under heavy load (adversarial, load 50-72) #148

Closed
opened 2026-09-26 01:04:25 +00:00 by kayg · 25 comments
Owner

Seen by job/task-unicode's second adversarial run on 2026-09-26 (host load 50-72): one HTTP 500 with 'files Index update failed' from the Files plugin. A 5xx is never acceptable (owner rule: fix every 5xx). Likely SQLite busy/locked under write contention surfacing as 500 instead of being retried or mapped to 503+Retry-After, or an index write racing a rename. Find the call site that produces this message, reproduce under synthetic load (parallel uploads + renames + reconcile while CPU is saturated), make busy/locked errors retry with bounded backoff inside the transaction boundary, and map a genuinely transient failure to 503 with Retry-After, never 500. Verify the file operation stays atomic (no file installed without its index row or vice versa). Add the load case to tests/adversarial.

Seen by job/task-unicode's second adversarial run on 2026-09-26 (host load 50-72): one HTTP 500 with 'files Index update failed' from the Files plugin. A 5xx is never acceptable (owner rule: fix every 5xx). Likely SQLite busy/locked under write contention surfacing as 500 instead of being retried or mapped to 503+Retry-After, or an index write racing a rename. Find the call site that produces this message, reproduce under synthetic load (parallel uploads + renames + reconcile while CPU is saturated), make busy/locked errors retry with bounded backoff inside the transaction boundary, and map a genuinely transient failure to 503 with Retry-After, never 500. Verify the file operation stays atomic (no file installed without its index row or vice versa). Add the load case to tests/adversarial.
Author
Owner

Starting #148 on branch job/robustness, based on dev SHA 7c1d6c82ea98ac3772117a534fbb923825a60bab.

I will trace the failing Files write and SQLite contention paths, add a synthetic load regression to tests/adversarial, then validate transaction atomicity and transient HTTP handling.

Starting #148 on branch `job/robustness`, based on dev SHA `7c1d6c82ea98ac3772117a534fbb923825a60bab`. I will trace the failing Files write and SQLite contention paths, add a synthetic load regression to `tests/adversarial`, then validate transaction atomicity and transient HTTP handling.
Author
Owner

Finding: crates/plugins/files/src/uploads.rs::finish persists files_uploads.installing = 1 before replacing the destination, then writes the Files Index row. finalize calls discard on every error, which deletes the upload row and therefore the recovery intent even when the file has already been installed. A transient busy/locked error at the Index write can leave an installed file without an Index row or recovery marker. I am adding a contention regression and will retain the intent until the Index row and upload state can be completed atomically.

Finding: `crates/plugins/files/src/uploads.rs::finish` persists `files_uploads.installing = 1` before replacing the destination, then writes the Files Index row. `finalize` calls `discard` on every error, which deletes the upload row and therefore the recovery intent even when the file has already been installed. A transient busy/locked error at the Index write can leave an installed file without an Index row or recovery marker. I am adding a contention regression and will retain the intent until the Index row and upload state can be completed atomically.
Author
Owner

Additional busy-to-500 finding from the server audit: notification subscription and inbox handlers mapped every storage error to HTTP 500; Calendar cache handlers and AI turn enqueue also mapped SQLx errors directly to internal errors. A SQLite BUSY/LOCKED result in those paths would violate the retryable response contract. The handlers now detect BUSY/LOCKED and return 503, and the server adds Retry-After to any bare 503 response. Non-transient database errors still return 500. Targeted tests are pending.

Additional busy-to-500 finding from the server audit: notification subscription and inbox handlers mapped every storage error to HTTP 500; Calendar cache handlers and AI turn enqueue also mapped SQLx errors directly to internal errors. A SQLite BUSY/LOCKED result in those paths would violate the retryable response contract. The handlers now detect BUSY/LOCKED and return 503, and the server adds Retry-After to any bare 503 response. Non-transient database errors still return 500. Targeted tests are pending.
Author
Owner

The SQLite error mapping audit found three additional paths that flattened busy/locked failures into HTTP 500: Calendar mapped Notes' new retryable API error to internal, Photos search reduced both its metadata query and CLIP index query errors to a generic failure, and the Photos key photo route mapped metadata refresh errors to internal. These now preserve the transient state and return 503 with Retry-After: 1. Targeted crate checks are running; final verification will follow after merge.

The SQLite error mapping audit found three additional paths that flattened busy/locked failures into HTTP 500: Calendar mapped Notes' new retryable API error to `internal`, Photos search reduced both its metadata query and CLIP index query errors to a generic failure, and the Photos key photo route mapped metadata refresh errors to `internal`. These now preserve the transient state and return 503 with `Retry-After: 1`. Targeted crate checks are running; final verification will follow after merge.
Author
Owner

Finding (config storage): Review of server error mapping found SQLite BUSY/LOCKED failures from admin config persistence and legacy signup config writes could become 400 or 500 responses. Evidence: put_config, save_config_toml, and session_context all call persist_config, but did not classify transient database errors. These paths now return 503 for SQLite BUSY/LOCKED and include Retry-After; provider discovery also preserves retryable auth database failures. Regression coverage: config_storage_busy_errors_are_retryable in the server wire tests.

Finding (config storage): Review of server error mapping found SQLite BUSY/LOCKED failures from admin config persistence and legacy signup config writes could become 400 or 500 responses. Evidence: `put_config`, `save_config_toml`, and `session_context` all call `persist_config`, but did not classify transient database errors. These paths now return 503 for SQLite BUSY/LOCKED and include `Retry-After`; provider discovery also preserves retryable auth database failures. Regression coverage: `config_storage_busy_errors_are_retryable` in the server wire tests.
Author
Owner

Finding (merged server build): cargo test -p calternal-server reached Rust compilation after the stable OpenSSL build and found two compile errors in the pending retryable error mapping: wire.rs referenced ApiFailure outside its module, and list_users returned StatusCode where its handler requires RetryableHttpError. I reused the server error envelope through a crate-visible constructor and wrapped the auth status so BUSY/LOCKED still becomes 503 with Retry-After. I am rebuilding the SPA asset required by RustEmbed, then I will rerun the server suite.

> Finding (merged server build): `cargo test -p calternal-server` reached Rust compilation after the stable OpenSSL build and found two compile errors in the pending retryable error mapping: `wire.rs` referenced `ApiFailure` outside its module, and `list_users` returned `StatusCode` where its handler requires `RetryableHttpError`. I reused the server error envelope through a crate-visible constructor and wrapped the auth status so BUSY/LOCKED still becomes 503 with `Retry-After`. I am rebuilding the SPA asset required by `RustEmbed`, then I will rerun the server suite.
Author
Owner

Merged current dev tip 6e1e5656 before final validation. Resolved the Files Index conflict by retaining the no-op upsert check while retrying BUSY/LOCKED writes and mapping DB failures to the retryable service response. Kept the text-file thumbnail skip and preserved typed DB errors; deduplicated thumbnail enqueue now retries safely. Validation after this merge: cargo test -p calternal-db passed 7 unit + 9 integration tests; cargo test -p calternal-plugin-files passed 91 tests. Merge commit: b2da8d1e31.

Merged current dev tip 6e1e5656 before final validation. Resolved the Files Index conflict by retaining the no-op upsert check while retrying BUSY/LOCKED writes and mapping DB failures to the retryable service response. Kept the text-file thumbnail skip and preserved typed DB errors; deduplicated thumbnail enqueue now retries safely. Validation after this merge: `cargo test -p calternal-db` passed 7 unit + 9 integration tests; `cargo test -p calternal-plugin-files` passed 91 tests. Merge commit: b2da8d1e31eac9cf6e54aa0bb323617de5cb1449.
Author
Owner

Adversarial finding during the one-time real-server round: the 48-way saved-search rename storm produced 7 client-side NO RESPONSE (timed out) results at the probe's 30 s timeout. The server process remained alive. The other 41 requests had not yet been tallied when this comment was posted; I will include the final count and probe exit in the completion report. This is outside the Files SQLite contention path and occurred while multiple other real-server jobs were active on the shared host. I am recording it for follow-up rather than changing unrelated saved-search behavior in #148.

Adversarial finding during the one-time real-server round: the 48-way saved-search rename storm produced 7 client-side `NO RESPONSE (timed out)` results at the probe's 30 s timeout. The server process remained alive. The other 41 requests had not yet been tallied when this comment was posted; I will include the final count and probe exit in the completion report. This is outside the Files SQLite contention path and occurred while multiple other real-server jobs were active on the shared host. I am recording it for follow-up rather than changing unrelated saved-search behavior in #148.
Author
Owner

Additional non-SLOW adversarial finding: the 16-request bookmark capture storm (10 s request timeout) returned four client timeouts (status=-1) and twelve expected 429 responses. The server remained alive. The contention cap rejected work, but four requests did not complete within the probe timeout on this shared host. I will include the full run exit and status in the completion report; this is separate from the Files SQLite retry path and is recorded here for follow-up.

Additional non-SLOW adversarial finding: the 16-request bookmark capture storm (10 s request timeout) returned four client timeouts (`status=-1`) and twelve expected 429 responses. The server remained alive. The contention cap rejected work, but four requests did not complete within the probe timeout on this shared host. I will include the full run exit and status in the completion report; this is separate from the Files SQLite retry path and is recorded here for follow-up.
Author
Owner

Blocking adversarial finding from attack2.py: while the sync daemon ran, the probe deleted its local Sync root, waited 6 s, recreated an empty root, then checked the remote tree 8 s later. keep/k0.txt had disappeared from the remote tree. The same run's daemon logs showed repeated sync reconcile deferred: local destination cannot be replaced safely, followed by local filesystem failed ... Sync: No such file or directory; the probe confirmed one remote file was trashed. This is data loss under a local-root disappearance race. I am tracing it before completion; the full adversarial round is still running.

Blocking adversarial finding from `attack2.py`: while the sync daemon ran, the probe deleted its local Sync root, waited 6 s, recreated an empty root, then checked the remote tree 8 s later. `keep/k0.txt` had disappeared from the remote tree. The same run's daemon logs showed repeated `sync reconcile deferred: local destination cannot be replaced safely`, followed by `local filesystem failed ... Sync: No such file or directory`; the probe confirmed one remote file was trashed. This is data loss under a local-root disappearance race. I am tracing it before completion; the full adversarial round is still running.
Author
Owner

Further attack2 results: (1) GET /api/v1/photos/timeline returned HTTP 200 with an empty days list for 12 seconds after User B opted into User A's active Photos share; the probe recorded “active shared photo never appeared”. (2) With 64 SSE streams open for one user, 20 Files mkdirs took 13.3 seconds. (3) The feed storm's one HTTP 500 caused its reader to stop, after which it reported 112 expected paths absent from the consumed feed. The 112 count is downstream of the reader exit, not independent proof of lost writes. The server remained alive. The separate sync data-loss observation is in my previous comment.

Further attack2 results: (1) `GET /api/v1/photos/timeline` returned HTTP 200 with an empty `days` list for 12 seconds after User B opted into User A's active Photos share; the probe recorded “active shared photo never appeared”. (2) With 64 SSE streams open for one user, 20 Files mkdirs took 13.3 seconds. (3) The feed storm's one HTTP 500 caused its reader to stop, after which it reported 112 expected paths absent from the consumed feed. The 112 count is downstream of the reader exit, not independent proof of lost writes. The server remained alive. The separate sync data-loss observation is in my previous comment.
Author
Owner

Root cause for the sync data-loss finding: scan_local_tree_cached hashed files but did not snapshot or recheck traversed directories. A deterministic regression test deleted and recreated the sync root after WalkDir yielded its first entry; the current scanner returned Ok(LocalScan) instead of rejecting that partial inventory. I am adding directory-change detection so a pass cannot plan remote deletions from a tree that changed during traversal.

> Root cause for the sync data-loss finding: `scan_local_tree_cached` hashed files but did not snapshot or recheck traversed directories. A deterministic regression test deleted and recreated the sync root after `WalkDir` yielded its first entry; the current scanner returned `Ok(LocalScan)` instead of rejecting that partial inventory. I am adding directory-change detection so a pass cannot plan remote deletions from a tree that changed during traversal.
Author
Owner

Root replacement fix: committed as 4bd6c16e. scan_local_tree_cached now snapshots the root and traversed directories, holds the root handle during validation, and returns ConcurrentChange before publishing an inventory if the tree changed. The deterministic regression reproduced the race before the fix and passes after it; cargo test -p calternal-sync passed 40 tests. Also committed fc2f6536 to map SQLite pool saturation to retryable service errors and set bounded acquisition timeouts; the targeted db/auth/server suites passed. Merged the latest dev tip 116cd780 as 75d5a035. Final workspace and web gates are running.

> Root replacement fix: committed as `4bd6c16e`. `scan_local_tree_cached` now snapshots the root and traversed directories, holds the root handle during validation, and returns `ConcurrentChange` before publishing an inventory if the tree changed. The deterministic regression reproduced the race before the fix and passes after it; `cargo test -p calternal-sync` passed 40 tests. Also committed `fc2f6536` to map SQLite pool saturation to retryable service errors and set bounded acquisition timeouts; the targeted db/auth/server suites passed. Merged the latest `dev` tip `116cd780` as `75d5a035`. Final workspace and web gates are running.
Author
Owner

Resuming #148 after the VM restart. Branch: job/robustness; current head: b2a61021ab06adfeee327e5546a6393655de15f0; current local dev tip: 65265f87ffcc9c44c05e577b4e2ea9c27de130b2. The worktree is clean. The timer snapshot ef2ab509 contains an incomplete calendar/view.rs hunk with merge conflict markers; the active branch has the resolved merge, so I am not applying the broken snapshot. I will merge the newer dev tip, review the resulting state, then complete final gates and the report.

Resuming #148 after the VM restart. Branch: `job/robustness`; current head: `b2a61021ab06adfeee327e5546a6393655de15f0`; current local `dev` tip: `65265f87ffcc9c44c05e577b4e2ea9c27de130b2`. The worktree is clean. The timer snapshot `ef2ab509` contains an incomplete `calendar/view.rs` hunk with merge conflict markers; the active branch has the resolved merge, so I am not applying the broken snapshot. I will merge the newer `dev` tip, review the resulting state, then complete final gates and the report.
Author
Owner

Validation finding: the first default-parallel cargo test -p calternal-plugin-files had one failure: media::tests::timeout_kills_the_whole_media_process_group observed a process in state R after its 10 s poll window (103 passed, 1 failed). The exact test passed alone, and the full crate passed 104/104 with --test-threads=4. A post-run process check found no media-timeout-test or sleep 60 process; host load was 28. I have not found evidence of a persistent descendant leak. I will keep test concurrency bounded for final gates.

Validation finding: the first default-parallel `cargo test -p calternal-plugin-files` had one failure: `media::tests::timeout_kills_the_whole_media_process_group` observed a process in state `R` after its 10 s poll window (103 passed, 1 failed). The exact test passed alone, and the full crate passed 104/104 with `--test-threads=4`. A post-run process check found no `media-timeout-test` or `sleep 60` process; host load was 28. I have not found evidence of a persistent descendant leak. I will keep test concurrency bounded for final gates.
Author
Owner

Post-merge real-server adversarial round completed its first API pass after merge 61cdb607:

  • attack.py reported 27 findings, all tagged SLOW (including 5.1–8.1 s saved-search creates, 13.3 s Calendar Event creation, 5.6 s DAV sync, and 5.8 s Reminders sync). These were under concurrent adversarial runs on the shared host.
  • Hostile-byte probe reported 0 findings. Feed storm emitted no anomaly before the second-round probe stopped.
  • The non-SLOW Photos shared-timeline finding repeated: HTTP 200 with an empty days list throughout the 12-second opt-in window. This is already tracked in #215 (also duplicated in #187/#188/#173).
  • attack2.py then aborted in its collab section because its note() helper returned None after a non-201 response and the caller dereferenced it. The helper discarded the response, so the server-side cause is unknown; I recorded the harness failure on #221. The separate restart probe reported 0 findings.

The full round2 summary was not emitted after that probe exception; this is a known coverage gap for the remaining round2 sections.

Post-merge real-server adversarial round completed its first API pass after merge `61cdb607`: - `attack.py` reported 27 findings, all tagged `SLOW` (including 5.1–8.1 s saved-search creates, 13.3 s Calendar Event creation, 5.6 s DAV sync, and 5.8 s Reminders sync). These were under concurrent adversarial runs on the shared host. - Hostile-byte probe reported 0 findings. Feed storm emitted no anomaly before the second-round probe stopped. - The non-SLOW Photos shared-timeline finding repeated: HTTP 200 with an empty `days` list throughout the 12-second opt-in window. This is already tracked in #215 (also duplicated in #187/#188/#173). - `attack2.py` then aborted in its collab section because its `note()` helper returned `None` after a non-201 response and the caller dereferenced it. The helper discarded the response, so the server-side cause is unknown; I recorded the harness failure on #221. The separate restart probe reported 0 findings. The full round2 summary was not emitted after that probe exception; this is a known coverage gap for the remaining round2 sections.
Author
Owner

Merged current dev (dfa8e85f) into the job branch at 4b7f188a. The merge conflict in the media process-group test keeps both the longer startup window and process start-time/group identity check. cargo test -p calternal-plugin-files -- --test-threads=1 passed: 104 passed, 0 failed; the new property replay seed passes in the serial run. Starting the one post-merge real-server adversarial round now.

Merged current dev (dfa8e85f) into the job branch at 4b7f188a. The merge conflict in the media process-group test keeps both the longer startup window and process start-time/group identity check. `cargo test -p calternal-plugin-files -- --test-threads=1` passed: 104 passed, 0 failed; the new property replay seed passes in the serial run. Starting the one post-merge real-server adversarial round now.
Author
Owner

Post-merge real-server adversarial evidence from this continuation:

  • The Files TUS PATCH probe got HTTP 503 twice with Index is busy; retry shortly where it expected 204. The Journal race later completed 8 sync uploads; its file and index checks found 46 entries, with no lost or duplicate lines. The server stayed alive, and the restart probe had 0 findings.
  • Round 1 reported 111 findings and round 2 reported 66. Most were SLOW latency results while multiple other build and adversarial jobs were active on the shared host.
  • The round-1 task, saved-search, calendar, and analytics write storms also received retryable Authentication database busy 503 responses. Their evidence is summarized on #166.
  • Related non-SLOW cases already have open follow-up issues: #214 (one Calendar 500), #223 (public Edit frame-limit socket), and #228 (slowloris probe uses the Node proxy).

The busy Index response is retryable and did not produce a consistency failure in this run.

Post-merge real-server adversarial evidence from this continuation: - The Files TUS PATCH probe got HTTP 503 twice with `Index is busy; retry shortly` where it expected 204. The Journal race later completed 8 sync uploads; its file and index checks found 46 entries, with no lost or duplicate lines. The server stayed alive, and the restart probe had 0 findings. - Round 1 reported 111 findings and round 2 reported 66. Most were SLOW latency results while multiple other build and adversarial jobs were active on the shared host. - The round-1 task, saved-search, calendar, and analytics write storms also received retryable Authentication database busy 503 responses. Their evidence is summarized on #166. - Related non-SLOW cases already have open follow-up issues: #214 (one Calendar 500), #223 (public Edit frame-limit socket), and #228 (slowloris probe uses the Node proxy). The busy Index response is retryable and did not produce a consistency failure in this run.
Author
Owner

Finished report — robustness

Branch: job/robustness
Head: 7655d18ad79b4635ba5c754859b69b9c68a3598c

Built

  • Added bounded retry handling for transient SQLite contention in Files Index writes. A persistent busy Index returns 503 service_unavailable with Retry-After: 1; a lock released during retry lets the operation complete. File-change races during hashing are retried, and an unchanged Index row is treated as success.
  • Added regression coverage for a held/released SQLite writer lock and the busy-host state-machine replay. Extended the adversarial probes and hardened media child-process timeout handling.
  • Merged dev at 2d84737bd44ed9134ade42ea3fc13ddcf875a2ae before the final gates. The subsequent Sync merge retained both branches' stable-read and local-root checks.

Main files: crates/calternal-db/src/sqlite.rs, crates/plugins/files/src/index.rs, crates/plugins/files/src/lib.rs, crates/plugins/files/src/uploads.rs, crates/calternal-auth/src/error.rs, crates/calternal-sync/src/local.rs, crates/plugins/calendar/src/routes.rs, crates/plugins/notes/src/lib.rs, crates/plugins/photos/src/index.rs, crates/calternal-server/src/main.rs, crates/calternal-server/src/wire.rs, crates/plugins/files/src/media.rs, tests/adversarial/attack.py, and crates/plugins/files/proptest-regressions/lib.txt. The full branch diff from the merge base also touches the related Files routes, auth, DAV, tags, Calendar, Notes, Notifications, Photos and API-facing DB helpers.

Adversarial round

After merging dev, the real-server round completed: round 1 reported 111 findings and round 2 reported 66, mostly SLOW latency findings on the shared host. Hostile-byte and restart probes reported 0 findings; the server stayed alive. The original Files Index 500 did not recur. Under the Files TUS write storm, two requests received retryable 503 responses (Index is busy; retry shortly); the response implementation and regression test include Retry-After: 1.

Other non-SLOW evidence was reported on existing issues: Calendar returned one unexpected 500 in its duplicate-account storm (#214); Public Edit stayed open after 301 empty WebSocket frames (#223); the slowloris probe targeted the Node editor proxy and some 502s were proxy-generated after upstream resets (#228); cross-plugin write storms produced transient auth DB busy 503s (#166); and three Collab hostile-client assertions failed intermittently under shared-host load (#81). No unrelated behavior was changed in this job.

Gates

cargo fmt --check exited 0 with no output.

cargo clippy --all-targets -- -D warnings exited 0. Final output:

    Finished `dev` profile [unoptimized + debuginfo] target(s) in 11m 25s

cargo test --workspace --no-fail-fast -- --test-threads=1 exited nonzero. The retry completed all test targets and ended with:

error: 6 targets failed:
    `-p calternal-collab --test hostile_clients`
    `-p calternal-collab --test shared_notes`
    `-p calternal-collab --test two_clients`
    `-p calternal-collab --test untouched_bytes`
    `-p calternal-db --test queue`
    `-p calternal-plugin-notes --lib`

Several failures were Sqlx(PoolTimedOut) during fixture setup. The three Collab hostile-client assertions are described above and on #81. Focused serial suites passed: Files 104; Sync 47 library tests plus 2 CLI tests; Photos 39 passed and 2 ignored; Server 43 passed and 2 ignored. The focused silent/partial/idle connection timeout test passed 1/1.

bun run check exited 0:

svelte-check found 0 errors and 0 warnings

bun run test exited 0:

 Test Files  78 passed (78)
      Tests  579 passed (579)
   Start at  14:34:41
   Duration  51.88s (transform 62%, import 16%, environment 12%, tests 7%, setup 2%)

Known gaps and decisions

  • The workspace test gate is not green on this shared host; its exact failures are listed above and tracked on #81/#166. I did not change Collab, DB queue or Notes tests because focused serial runs and prior workspace runs showed load-correlated fixture failures rather than a reproducible defect in this issue's Files path.
  • Remaining non-SLOW adversarial findings are tracked on #214, #223, #228, #166 and #81. The proxy-target slowloris and proxy-generated 502s need a correctly targeted follow-up probe.
  • docs/DESIGN.md did not specify transient SQLite contention behavior. I chose bounded retries at the Index write boundary, followed by 503 plus Retry-After: 1 when contention persists. No product/UI design decisions were needed.
## Finished report — robustness Branch: `job/robustness` Head: `7655d18ad79b4635ba5c754859b69b9c68a3598c` ### Built - Added bounded retry handling for transient SQLite contention in Files Index writes. A persistent busy Index returns `503 service_unavailable` with `Retry-After: 1`; a lock released during retry lets the operation complete. File-change races during hashing are retried, and an unchanged Index row is treated as success. - Added regression coverage for a held/released SQLite writer lock and the busy-host state-machine replay. Extended the adversarial probes and hardened media child-process timeout handling. - Merged `dev` at `2d84737bd44ed9134ade42ea3fc13ddcf875a2ae` before the final gates. The subsequent Sync merge retained both branches' stable-read and local-root checks. Main files: `crates/calternal-db/src/sqlite.rs`, `crates/plugins/files/src/index.rs`, `crates/plugins/files/src/lib.rs`, `crates/plugins/files/src/uploads.rs`, `crates/calternal-auth/src/error.rs`, `crates/calternal-sync/src/local.rs`, `crates/plugins/calendar/src/routes.rs`, `crates/plugins/notes/src/lib.rs`, `crates/plugins/photos/src/index.rs`, `crates/calternal-server/src/main.rs`, `crates/calternal-server/src/wire.rs`, `crates/plugins/files/src/media.rs`, `tests/adversarial/attack.py`, and `crates/plugins/files/proptest-regressions/lib.txt`. The full branch diff from the merge base also touches the related Files routes, auth, DAV, tags, Calendar, Notes, Notifications, Photos and API-facing DB helpers. ### Adversarial round After merging `dev`, the real-server round completed: round 1 reported 111 findings and round 2 reported 66, mostly `SLOW` latency findings on the shared host. Hostile-byte and restart probes reported 0 findings; the server stayed alive. The original Files Index 500 did not recur. Under the Files TUS write storm, two requests received retryable `503` responses (`Index is busy; retry shortly`); the response implementation and regression test include `Retry-After: 1`. Other non-SLOW evidence was reported on existing issues: Calendar returned one unexpected 500 in its duplicate-account storm (#214); Public Edit stayed open after 301 empty WebSocket frames (#223); the slowloris probe targeted the Node editor proxy and some 502s were proxy-generated after upstream resets (#228); cross-plugin write storms produced transient auth DB busy 503s (#166); and three Collab hostile-client assertions failed intermittently under shared-host load (#81). No unrelated behavior was changed in this job. ### Gates `cargo fmt --check` exited 0 with no output. `cargo clippy --all-targets -- -D warnings` exited 0. Final output: ```text Finished `dev` profile [unoptimized + debuginfo] target(s) in 11m 25s ``` `cargo test --workspace --no-fail-fast -- --test-threads=1` exited nonzero. The retry completed all test targets and ended with: ```text error: 6 targets failed: `-p calternal-collab --test hostile_clients` `-p calternal-collab --test shared_notes` `-p calternal-collab --test two_clients` `-p calternal-collab --test untouched_bytes` `-p calternal-db --test queue` `-p calternal-plugin-notes --lib` ``` Several failures were `Sqlx(PoolTimedOut)` during fixture setup. The three Collab hostile-client assertions are described above and on #81. Focused serial suites passed: Files 104; Sync 47 library tests plus 2 CLI tests; Photos 39 passed and 2 ignored; Server 43 passed and 2 ignored. The focused silent/partial/idle connection timeout test passed 1/1. `bun run check` exited 0: ```text svelte-check found 0 errors and 0 warnings ``` `bun run test` exited 0: ```text Test Files 78 passed (78) Tests 579 passed (579) Start at 14:34:41 Duration 51.88s (transform 62%, import 16%, environment 12%, tests 7%, setup 2%) ``` ### Known gaps and decisions - The workspace test gate is not green on this shared host; its exact failures are listed above and tracked on #81/#166. I did not change Collab, DB queue or Notes tests because focused serial runs and prior workspace runs showed load-correlated fixture failures rather than a reproducible defect in this issue's Files path. - Remaining non-SLOW adversarial findings are tracked on #214, #223, #228, #166 and #81. The proxy-target slowloris and proxy-generated 502s need a correctly targeted follow-up probe. - `docs/DESIGN.md` did not specify transient SQLite contention behavior. I chose bounded retries at the Index write boundary, followed by `503` plus `Retry-After: 1` when contention persists. No product/UI design decisions were needed.
Author
Owner

Started #148 on branch job/robustness at 7655d18a; dev base SHA: f1c0766907. Investigating the request-scoped database checkout deadline and contention regressions.

Started #148 on branch job/robustness at 7655d18a; dev base SHA: f1c0766907d5d1a0a3a7ea0ae807e43dd2caf9f0. Investigating the request-scoped database checkout deadline and contention regressions.
Author
Owner

Finding: calternal-db set both the single writer and reader pools to a 2-second acquire timeout. The writer pool is shared by JobQueue and plugin writes, so pool saturation was being turned into PoolTimedOut before those background calls could wait their turn. I restored a 30-second timeout and added a queue regression that holds the writer connection for 5.5 seconds; cargo test -p calternal-db passed (9 unit tests, 9 integration tests, 1 ignored). Commit: 85443657.

Finding: `calternal-db` set both the single writer and reader pools to a 2-second acquire timeout. The writer pool is shared by `JobQueue` and plugin writes, so pool saturation was being turned into `PoolTimedOut` before those background calls could wait their turn. I restored a 30-second timeout and added a queue regression that holds the writer connection for 5.5 seconds; `cargo test -p calternal-db` passed (9 unit tests, 9 integration tests, 1 ignored). Commit: 85443657.
Author
Owner

HTTP-boundary regression: Files item-ID assignment handlers now cap only writer-pool checkout at five seconds. When /stat holds the Files Index writer connection, it returns 503 with Retry-After: 1 within the deadline; after release, the same Index write succeeds. The existing external SQLite BUSY regression still succeeds when its lock is released after 5.5 seconds, because the request deadline does not cancel SQLite's lock wait or bounded retries. cargo test -p calternal-plugin-files passed: 105 passed, 0 failed.

While validating that crate, its media timeout test reported a surviving process although the process had exited between /proc reads. The test kept the prior R state on NotFound; it now clears that stale state. The isolated media test and full Files crate run pass.

HTTP-boundary regression: Files item-ID assignment handlers now cap only writer-pool checkout at five seconds. When `/stat` holds the Files Index writer connection, it returns 503 with `Retry-After: 1` within the deadline; after release, the same Index write succeeds. The existing external SQLite BUSY regression still succeeds when its lock is released after 5.5 seconds, because the request deadline does not cancel SQLite's lock wait or bounded retries. `cargo test -p calternal-plugin-files` passed: 105 passed, 0 failed. While validating that crate, its media timeout test reported a surviving process although the process had exited between `/proc` reads. The test kept the prior `R` state on `NotFound`; it now clears that stale state. The isolated media test and full Files crate run pass.
Author
Owner

Completed

Branch: job/robustness
Head: 516d7e58056b79397669a4f4f121394b72951d5d
The branch is pushed. git push origin job/robustness returned Everything up-to-date.

Restored the SQLite pool acquire timeout to 30 seconds so background queues, imports, indexing, migrations, and collaboration writes can wait for the single writer. Added a five-second writer checkout deadline only at HTTP Files Index call sites. HTTP contention returns 503 with Retry-After; regular pool users keep the longer wait, and bounded SQLite BUSY/LOCKED retries remain unchanged.

Added regressions proving that a background queue write waits behind a writer held for more than five seconds, and that an HTTP Files write returns 503 with Retry-After within its deadline. The Files test also checks that Index assignment succeeds after the lock clears. Fixed stale process-state handling in the media timeout test when a killed child exits before /proc is read.

Files changed for this issue:

  • crates/calternal-db/src/db.rs
  • crates/calternal-db/src/jobs.rs
  • crates/plugins/files/src/index.rs
  • crates/plugins/files/src/lib.rs
  • crates/plugins/files/src/media.rs
  • crates/plugins/files/src/public.rs
  • crates/plugins/files/src/shares.rs
  • crates/plugins/files/src/uploads.rs

Commits

  • 85443657 Restore long SQLite pool checkout for background work
  • 66399421 Bound HTTP Files Index writer checkout
  • 79d49d39 Clear exited state in media timeout test
  • Merged dev before gates. Its tip advanced during the first full test run, so the new tip 74d60726 was merged before the final gates. Final merge commit: 516d7e58.

Gates

cargo fmt --all --check exited 0 with empty output.

cargo clippy --all-targets -- -D warnings exited 0. Final output:

    Finished `dev` profile [unoptimized + debuginfo] target(s) in 1m 39s

cargo test exited 0 on the final merged head. Final build output:

    Finished `test` profile [unoptimized + debuginfo] target(s) in 5m 58s

Relevant test output:

test result: ok. 9 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 5.85s

test result: ok. 105 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 54.31s

cargo clean completed:

     Removed 16307 files, 13.4GiB total

Removed apps/web/build and apps/web/.svelte-kit after the Rust gates. The worktree is clean. Web bun run check and bun run test were not run because this issue changes Rust code only.

Gaps and decisions

No known issue-specific gaps. Model-dependent and performance benchmark tests marked ignored by the workspace remain unrun. The five-second HTTP checkout deadline and 30-second pool timeout follow the issue request and SQLx default, respectively. The deadline wraps writer checkout only, so background callers and SQL operations retain their own wait and retry behavior.

## Completed Branch: `job/robustness` Head: `516d7e58056b79397669a4f4f121394b72951d5d` The branch is pushed. `git push origin job/robustness` returned `Everything up-to-date`. Restored the SQLite pool acquire timeout to 30 seconds so background queues, imports, indexing, migrations, and collaboration writes can wait for the single writer. Added a five-second writer checkout deadline only at HTTP Files Index call sites. HTTP contention returns 503 with `Retry-After`; regular pool users keep the longer wait, and bounded SQLite BUSY/LOCKED retries remain unchanged. Added regressions proving that a background queue write waits behind a writer held for more than five seconds, and that an HTTP Files write returns 503 with `Retry-After` within its deadline. The Files test also checks that Index assignment succeeds after the lock clears. Fixed stale process-state handling in the media timeout test when a killed child exits before `/proc` is read. Files changed for this issue: - `crates/calternal-db/src/db.rs` - `crates/calternal-db/src/jobs.rs` - `crates/plugins/files/src/index.rs` - `crates/plugins/files/src/lib.rs` - `crates/plugins/files/src/media.rs` - `crates/plugins/files/src/public.rs` - `crates/plugins/files/src/shares.rs` - `crates/plugins/files/src/uploads.rs` ## Commits - `85443657` Restore long SQLite pool checkout for background work - `66399421` Bound HTTP Files Index writer checkout - `79d49d39` Clear exited state in media timeout test - Merged `dev` before gates. Its tip advanced during the first full test run, so the new tip `74d60726` was merged before the final gates. Final merge commit: `516d7e58`. ## Gates `cargo fmt --all --check` exited 0 with empty output. `cargo clippy --all-targets -- -D warnings` exited 0. Final output: ```text Finished `dev` profile [unoptimized + debuginfo] target(s) in 1m 39s ``` `cargo test` exited 0 on the final merged head. Final build output: ```text Finished `test` profile [unoptimized + debuginfo] target(s) in 5m 58s ``` Relevant test output: ```text test result: ok. 9 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 5.85s test result: ok. 105 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 54.31s ``` `cargo clean` completed: ```text Removed 16307 files, 13.4GiB total ``` Removed `apps/web/build` and `apps/web/.svelte-kit` after the Rust gates. The worktree is clean. Web `bun run check` and `bun run test` were not run because this issue changes Rust code only. ## Gaps and decisions No known issue-specific gaps. Model-dependent and performance benchmark tests marked ignored by the workspace remain unrun. The five-second HTTP checkout deadline and 30-second pool timeout follow the issue request and SQLx default, respectively. The deadline wraps writer checkout only, so background callers and SQL operations retain their own wait and retry behavior.
Author
Owner

Correction/update to the final report: I also ran the web gates on the final merged head 516d7e58056b79397669a4f4f121394b72951d5d. This supersedes the earlier sentence that said they were not run.

bun run check exited 0. Output:

Loading svelte-check in workspace: /home/kayg/Developer/calternal-wt/robustness/apps/web
Getting Svelte diagnostics...

svelte-check found 0 errors and 0 warnings

bun run test exited 0. Summary output:

 Test Files  80 passed (80)
      Tests  585 passed (585)
   Start at  16:40:41
   Duration  96.92s (transform 67%, environment 13%, import 11%, tests 7%, setup 2%)

  Transform  |component| transforming modules took 176.28s · 62% of tracked time, re-done on every run
             persist transforms across runs with fsModuleCache: true
             learn more: https://vitest.dev/guide/improving-performance#caching-between-reruns

Vitest also printed Could not parse CSS stylesheet and repeated Not implemented: Window's scrollTo() method diagnostics; the suite still exited 0. The generated .svelte-kit cache was removed. The worktree remains clean, and the branch head matches origin/job/robustness.

Correction/update to the final report: I also ran the web gates on the final merged head `516d7e58056b79397669a4f4f121394b72951d5d`. This supersedes the earlier sentence that said they were not run. `bun run check` exited 0. Output: ```text Loading svelte-check in workspace: /home/kayg/Developer/calternal-wt/robustness/apps/web Getting Svelte diagnostics... svelte-check found 0 errors and 0 warnings ``` `bun run test` exited 0. Summary output: ```text Test Files 80 passed (80) Tests 585 passed (585) Start at 16:40:41 Duration 96.92s (transform 67%, environment 13%, import 11%, tests 7%, setup 2%) Transform |component| transforming modules took 176.28s · 62% of tracked time, re-done on every run persist transforms across runs with fsModuleCache: true learn more: https://vitest.dev/guide/improving-performance#caching-between-reruns ``` Vitest also printed `Could not parse CSS stylesheet` and repeated `Not implemented: Window's scrollTo() method` diagnostics; the suite still exited 0. The generated `.svelte-kit` cache was removed. The worktree remains clean, and the branch head matches `origin/job/robustness`.
Author
Owner

Merged in 57d1752c: 30 s pool timeout for all callers, 5 s writer-checkout deadline at HTTP boundary → 503 + Retry-After, bounded BUSY/LOCKED retries.

Merged in 57d1752c: 30 s pool timeout for all callers, 5 s writer-checkout deadline at HTTP boundary → 503 + Retry-After, bounded BUSY/LOCKED retries.
kayg closed this issue 2026-09-27 14:45:57 +00:00
Sign in to join this conversation.
No labels
No milestone
No project
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set

Reference
kayg/calternal#148
No description provided.