kayg/calternal-v0

Archived

Watch

Fork 0

Tasks: 1,000 ticks take 22 minutes to become visible #1447

Closed

opened 2026-10-08 05:20:31 +00:00 by kayg · 6 comments

kayg commented

2026-10-08 05:20:31 +00:00

Owner

Problem

API audit #1374 on the perf VM: 1,000 POST /api/v1/notes/tasks/tick requests (concurrency 8) all returned 200, but the completed state took 1,347 s (22 minutes) to become visible through the API — about 1.3 s per tick. Target for a bulk operation: visible within 500 ms of the last response. Startup indexing of the same Home took 510 s.

Expected

Each tick is a small edit: it must not rewrite and re-index unrelated content or serialize all ticks behind one slow path. Profile where the time goes (file rewrite per Note, Search/Task index update, projection rebuild, lock waits), fix the top costs, and make concurrent ticks on Tasks in the same Note coalesce safely (no lost tick, no overwrite of a concurrent edit). Measure before/after on the perf VM with the bench/api-audit-1374.mjs bulk section (job/apiaudit-1374).

## Problem API audit #1374 on the perf VM: 1,000 `POST /api/v1/notes/tasks/tick` requests (concurrency 8) all returned 200, but the completed state took 1,347 s (22 minutes) to become visible through the API — about 1.3 s per tick. Target for a bulk operation: visible within 500 ms of the last response. Startup indexing of the same Home took 510 s. ## Expected Each tick is a small edit: it must not rewrite and re-index unrelated content or serialize all ticks behind one slow path. Profile where the time goes (file rewrite per Note, Search/Task index update, projection rebuild, lock waits), fix the top costs, and make concurrent ticks on Tasks in the same Note coalesce safely (no lost tick, no overwrite of a concurrent edit). Measure before/after on the perf VM with the bench/api-audit-1374.mjs bulk section (job/apiaudit-1374).

kayg referenced this issue

2026-10-08 13:01:19 +00:00

Tasks: tick returns HTTP 500 for most items in a bulk Undo #1446

kayg commented

2026-10-08 13:01:20 +00:00

Author

Owner

Started #1446 and #1447 on branch job/tick-1446, base d395b6e25da20d8c67b8b9fc1a593b813939c8a7. Read the API audit report and runner from job/apiaudit-1374. First reproduce the 1,000-Task completion and Undo at concurrency 8 with per-response error bodies and Notes debug logging. Then profile the tick write and projection path, measure on the perf VM, and check SIGKILL recovery.

Started #1446 and #1447 on branch `job/tick-1446`, base `d395b6e25da20d8c67b8b9fc1a593b813939c8a7`. Read the API audit report and runner from `job/apiaudit-1374`. First reproduce the 1,000-Task completion and Undo at concurrency 8 with per-response error bodies and Notes debug logging. Then profile the tick write and projection path, measure on the perf VM, and check SIGKILL recovery.

kayg commented

2026-10-08 13:18:43 +00:00

Author

Owner

Source findings:

tasks_api::tick resolves the response Task after the durable replacement and returns ApiError::internal() when no projected Task matches the old Index identity. A stale Index row with the checkbox removed from Markdown reproduces this path. The change resolves the response before writing and returns HTTP 409 with code conflict. A focused Rust regression keeps the source unchanged.
On the local real-server 1,000-Task run, initial ticks return HTTP 200 with approximately 2–5 seconds of guarded work, plus the per-User lock wait. The original bulk Undo is still running; the stale-row case is not yet proven to explain the audit's 834 errors.
index_source_once issues individual statements for every Task and reminder, plus cursor allocation and pruning per reminder. The pending change uses bounded SQL batches and one sync range allocation/prune per source, with identical projection and durability boundaries. Reminder source hash state is reused without changing ETag bytes.
A first perf fixture attempt retained the old source path after offline seeding and returned HTTP 404 for all requests. This is invalid measurement evidence. The harness now waits for all 1,000 Tasks at the expected source before sending ticks; the corrected baseline is running under perf-run.

Source findings: - `tasks_api::tick` resolves the response Task after the durable replacement and returns `ApiError::internal()` when no projected Task matches the old Index identity. A stale Index row with the checkbox removed from Markdown reproduces this path. The change resolves the response before writing and returns HTTP 409 with code `conflict`. A focused Rust regression keeps the source unchanged. - On the local real-server 1,000-Task run, initial ticks return HTTP 200 with approximately 2–5 seconds of guarded work, plus the per-User lock wait. The original bulk Undo is still running; the stale-row case is not yet proven to explain the audit's 834 errors. - `index_source_once` issues individual statements for every Task and reminder, plus cursor allocation and pruning per reminder. The pending change uses bounded SQL batches and one sync range allocation/prune per source, with identical projection and durability boundaries. Reminder source hash state is reused without changing ETag bytes. - A first perf fixture attempt retained the old source path after offline seeding and returned HTTP 404 for all requests. This is invalid measurement evidence. The harness now waits for all 1,000 Tasks at the expected source before sending ticks; the corrected baseline is running under `perf-run`.

kayg commented

2026-10-08 14:18:42 +00:00

Author

Owner

The filesystem change queue retains a pinned parent directory descriptor for each durable source write. A slow subscriber plus repeated writes to one Note can retain thousands of descriptors under the process limit of 1,024. The fix shares a live parent descriptor by kernel identity, preserves each event's full pre-write identity token, and bounds distinct optional parent proofs to 64. Excess optional proofs use the existing conservative adoption path. Filesystem pressure errors also receive a stable retryable 503 instead of 500. A subprocess regression uses RLIMIT_NOFILE=96 with 1,000 same-Note writes and 500 different parents.

The Notes fix also coalesces unguarded User ticks on the same Note into a checked durable commit, then projects Tasks before acknowledgement. Guarded and Agent requests keep their existing attribution and revision semantics. Performance and crash recovery measurements are in progress.

#1446 release reproduction at concurrency 8: complete 1,000 Tasks returned 1,000 HTTP 200 in 1,532.609 s; Undo returned 168 HTTP 200 and 832 HTTP 500 in 393.684 s. All 500 bodies were `{"code":"internal","message":"Notes operation failed"}`. The first corresponding server errors were EMFILE (`Too many open files`), including Search segment writes and filesystem reads, before shutdown. The filesystem change queue retains a pinned parent directory descriptor for each durable source write. A slow subscriber plus repeated writes to one Note can retain thousands of descriptors under the process limit of 1,024. The fix shares a live parent descriptor by kernel identity, preserves each event's full pre-write identity token, and bounds distinct optional parent proofs to 64. Excess optional proofs use the existing conservative adoption path. Filesystem pressure errors also receive a stable retryable 503 instead of 500. A subprocess regression uses RLIMIT_NOFILE=96 with 1,000 same-Note writes and 500 different parents. The Notes fix also coalesces unguarded User ticks on the same Note into a checked durable commit, then projects Tasks before acknowledgement. Guarded and Agent requests keep their existing attribution and revision semantics. Performance and crash recovery measurements are in progress.

kayg commented

2026-10-08 14:36:02 +00:00

Author

Owner

Committed the descriptor cause fix as 2b08889dc, then retryable filesystem pressure and projection-repair regression as 16ac6bd3f.

The low-descriptor subprocess passed 1,000 same-Note writes and 500 distinct parents with a hard descriptor limit of 96. The full filesystem suite passed (98 unit tests, 53 storage tests, and four other integration tests). The expanded Notes suite passed:

test result: ok. 324 passed; 0 failed; 4 ignored; 0 measured; 0 filtered out; finished in 374.92s
test result: ok. 2 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 2.72s

Both crate clippy gates passed. The web performance guard has zero violations and 48 fewer exception sites. Release after/crash measurements and the server gates are in progress; the VM is held by another calternal benchmark, so the measurement will queue through perf-run.

Committed the descriptor cause fix as `2b08889dc`, then retryable filesystem pressure and projection-repair regression as `16ac6bd3f`. The low-descriptor subprocess passed 1,000 same-Note writes and 500 distinct parents with a hard descriptor limit of 96. The full filesystem suite passed (98 unit tests, 53 storage tests, and four other integration tests). The expanded Notes suite passed: ``` test result: ok. 324 passed; 0 failed; 4 ignored; 0 measured; 0 filtered out; finished in 374.92s test result: ok. 2 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 2.72s ``` Both crate clippy gates passed. The web performance guard has zero violations and 48 fewer exception sites. Release after/crash measurements and the server gates are in progress; the VM is held by another calternal benchmark, so the measurement will queue through perf-run.

kayg referenced this issue

2026-10-08 15:46:38 +00:00

Tasks: tick returns HTTP 500 for most items in a bulk Undo #1446

kayg commented

2026-10-08 15:46:40 +00:00

Author

Owner

Completed #1446 and #1447 on job/tick-1446. Head: 35afee54f7d361856e4e8ac7aaef3599ceaebd44. The worktree is clean. No issue is closed.

The cause was retained filesystem directory descriptors. The release after run returned 1,000 HTTP 200 completions and 1,000 HTTP 200 Undo responses. Visibility fell from 1,532.662 s to 265.587 s. All 103 acknowledged VM crash ticks and all 104 local crash ticks survived; disk and Index agree for all 1,000 Tasks.

The broad server test run has one SLOW-only Calendar startup timing failure; its focused recheck and both server integrations pass. All changed-crate, clippy, formatting and web checks pass. Detailed verbatim results, files, remaining performance costs and decisions follow.

Task ticks: durable bulk completion and Undo (#1446, #1447)

Built

Share filesystem directory proof handles by live kernel identity. Keep at most 64 distinct optional pins per Root. Keep the full pre-write token for each event. This prevents a slow change subscriber from using one descriptor per tick.
Return 503 service_unavailable with Retry-After: 1 for descriptor pressure and temporary filesystem contention. Stale Task source or Note identity returns 409 conflict before a write.
Coalesce unguarded User ticks on distinct Tasks in one Note. Sync the checked Note replacement, commit the complete Task projection, then acknowledge each request. Opposite edits of the same Task have separate durable commits. Guarded and Agent ticks retain their request scope.
Insert Task and reminder projections in groups of 200 rows. Reserve one reminder cursor range and prune once per source transaction. Clone the source hash state for reminder ETags. The ETag bytes and stale DAV write protection stay the same.
Repair a stale projection when an idempotent retry finds its intended state already on disk. The retry creates no extra Version.
Add concurrent Rust tests, a low-descriptor subprocess test, a real-server burst profile, and a SIGKILL recovery probe.

Evidence

The locked release baseline reproduced 1,000 completions in 1,532.609 s (all 200), then Undo in 393.684 s (168 HTTP 200, 832 HTTP 500). Every 500 body was {"code":"internal","message":"Notes operation failed"}. The first server errors were Too many open files (os error 24). Directory proofs held by the change queue caused the descriptor shortage. Shutdown PoolClosed messages occurred later and are not the cause.

The filesystem regression performs 1,000 writes to one Note and 500 writes across distinct parent directories under RLIMIT_NOFILE=96. It passed. Concurrent Task tests cover Tasks in one Daily note and in different Notes, opposite ticks, repeated Undo, stale identity, and repair after an unacknowledged projection.

Expected cost

For a burst, writes and projection transactions scale with Note batches, rather than with individual ticks. At concurrency 8, a full group normally contains eight distinct Tasks. SQL inserts cost ceil(rows / 200) statements. Source ETag hashing costs Note bytes plus projected row bytes, rather than rows times Note bytes. Applying a group still scans the Note for each Task in memory. No request scans the full Home.

Decisions

Use the existing User writer guard. Do not add a second writer authority.
Use a 2 ms collection window, 64 operations per group, a queue of 256, and a 30 s guard timeout. A full queue or timeout returns the existing stable retry response.
Batch only unguarded User ticks. Keep Agent attribution and If-Match semantics in the direct request path.
Share at most 64 live directory pins per Root. Above this budget, omit the optional proof and use the existing conservative adoption path. This does not change write authority or durability.
Refresh exact performance guard identities and add exact in-memory call proofs. Move existing read-path projection debt to its live batched statements. Reduce the exception count by 48; do not weaken any rule or raise a ratchet.

UX gaps closed

Bulk Undo no longer fails from retained descriptors. A stale Task no longer receives a misleading 500. An idempotent retry repairs its Index before returning success. No UI controls changed.

Release measurements

Use perf-run on perf-test-69-63. Build here and copy the binaries. Before uses shared release af202e151; its Notes sources match the #1374 audit source. After uses the branch code through 16ac6bd3f. Use four Tokio workers, concurrency 8 and RLIMIT_NOFILE=1,024. The fixture has one Daily note with 1,000 Tasks, 2,000 unrelated Notes and 5,000 Files. It omits the 24 Photos and two linked Notes from #1374. These are Task measurements, not a new full-Home audit.

Phase	Returned, before	Visible, before	Returned, after	Visible, after	HTTP results, before → after
Complete 1,000	1,532.609 s	1,532.662 s	265.529 s	265.587 s	1,000 × 200 → 1,000 × 200
Undo 1,000	393.684 s	393.754 s	256.140 s	256.188 s	168 × 200 + 832 × 500 → 1,000 × 200

Completion is 5.77 times faster. Both after lists have all 1,000 intended states. The before Undo list has only 168 intended states. Its shorter duration includes failed work; do not compare it as a successful 1,000-Task Undo.

Per request	Before p50 / p95	After p50 / p95
Complete	12,083.019 / 14,245.052 ms	1,871.750 / 3,461.383 ms
Undo, all responses	2,658.503 / 8,766.526 ms	1,917.826 / 3,466.301 ms
Warm single tick, 10 samples	2,710.857 / 12,373.122 ms	1,447.167 / 3,379.189 ms

The after single-tick trace separates synced replacement from projection. Median durable time is 470.200 ms; median projection time is 168.727 ms. Means are 657.151 ms and 252.102 ms. HTTP total also includes preparation, the collection window, writer wait and response work. Durability remains a material cost. A burst amortizes it across eight Tasks rather than weakening it.

After completion uses 551.16 server CPU seconds (207.57% mean CPU) and 981,400 KiB peak RSS. Undo uses 539.63 CPU seconds (210.68%) and 1,028,692 KiB peak RSS. These are whole-process numbers and include background workers. The before resource sampler started partway through Undo, so there is no valid whole-burst CPU/RSS comparison. The new profile records these metrics for later comparisons. docs/perf/baseline.json has no earlier Task tick profile; this report adds the explicit before/after entry.

The before load average was 0.10 0.36 0.56 at the start. The after locked session started at 1.22 1.54 1.85. The copied fixture had an old Task source path in its Index. Run the existing Notes reconcile action once before the after samples. Fixture preparation and path settlement are outside all reported tick timings. An earlier 404 run is invalid and is excluded.

Real local reproduction and crash recovery

With the Notes debug flag used by the real-server harness and a 1,024 descriptor limit, the shared release reproduced all 1,000 completions in 1,370.244 s, then 174 successful Undo requests and 826 HTTP 500 responses. The first Undo failure was near Task 61. Its body was {"code":"internal","message":"Notes operation failed"}. The retained server log has EMFILE errors. This is the controlled local reproduction. An earlier busy-host run had transport timeouts and changed its limit late; it is retained as load evidence only.

The fixed local release returned 1,000 × 200 for completion and 1,000 × 200 for Undo. The lists had all intended states. Completion returned in 231.555 s; Undo returned in 262.265 s. These are local, busy-host measurements.

On the local release, SIGKILL followed 104 success receipts during a 1,000-tick burst. Restart retained all 104 and Markdown agreed with all 1,000 Task rows.

On the perf VM, SIGKILL followed 103 success receipts. The server restarted on the same data roots. The first recovery probe had no fixture User ID file; its disk check failed on that configuration error. Its Index check had already found every acknowledged tick. A read-only check of the restarted, stopped fixture with the verified User ID confirmed all 103 receipts and all 1,000 disk/Index states. This check starts no server or measurement workload. The redundant queued recovery run was cancelled. No completed operation or burst was repeated.

Files

crates/calternal-fs/src/root.rs, src/write.rs, tests/storage.rs: shared proof pins and the low-descriptor regression.
crates/plugins/notes/src/tasks_api.rs, src/tasks_tick.rs, src/tasks_store.rs, src/lib.rs, README.md: tick admission, durable grouping, projection batching, retry errors, tests and invariants.
bench/task-tick-1446.mjs, tests/adversarial/tasks-tick-1446.mjs: real-server requests, timing, resource samples, acceptance and recovery checks.
contracts/perf/registry.json, exceptions.json, ratchet.json, adoption-1058.json: exact live guard proofs and smaller debt.
docs/perf/baseline.json, this report: explicit measurements and limits.

Gates

Run all Cargo commands with CARGO_PROFILE_DEV_DEBUG=line-tables-only, CARGO_INCREMENTAL=0, CARGO_BUILD_JOBS=4 and worktree target/tmp as TMPDIR. cargo fmt --check exits 0 with no output. Result lines below are verbatim. Full logs remain in ignored artifacts/tick-1446/.

cargo clippy -p calternal-fs --all-targets -- -D warnings

    Finished `dev` profile [unoptimized + debuginfo] target(s) in 20.77s

cargo test -p calternal-fs -- --test-threads=4

    Finished `test` profile [unoptimized + debuginfo] target(s) in 2.26s
test result: ok. 98 passed; 0 failed; 1 ignored; 0 measured; 0 filtered out; finished in 45.55s
test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.15s
test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 1.27s
test result: ok. 53 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 275.79s
test result: ok. 2 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.08s
test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s

cargo clippy -p calternal-plugin-notes --all-targets -- -D warnings

    Finished `dev` profile [unoptimized + debuginfo] target(s) in 38.67s

cargo test -p calternal-plugin-notes -- --test-threads=4

    Finished `test` profile [unoptimized + debuginfo] target(s) in 2m 20s
test result: ok. 324 passed; 0 failed; 4 ignored; 0 measured; 0 filtered out; finished in 374.92s
test result: ok. 2 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 2.72s
test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s

cargo clippy -p calternal-server --all-targets -- -D warnings

    Finished `dev` profile [unoptimized + debuginfo] target(s) in 8m 47s

cargo test -p calternal-server -- --test-threads=4

search_reconcile_calendar_write_profile files=20000 writes=32 p50_ms=10295 p95_ms=10615 p95_budget_ms=10000
Calendar write p95 10.61581893s exceeded 10s
test result: FAILED. 271 passed; 1 failed; 12 ignored; 0 measured; 0 filtered out; finished in 193.87s

The only broad server failure is a timing budget in the 20,000-File Calendar startup profile. Keep its expectation unchanged. The focused recheck passes. An initial direct invocation of the ignored live-app test used the default debug test stack and aborted. The existing live-app launcher supplies a larger stack. The corrected focused command used RUST_MIN_STACK=8388608:

cargo test -p calternal-server wire::tests::startup_search_reconciliation_keeps_calendar_writes_responsive_on_large_home -- --ignored --exact --test-threads=1

    Finished `test` profile [unoptimized + debuginfo] target(s) in 2m 01s
test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 283 filtered out; finished in 77.90s

Run the server integration tests that the broad failure had not reached:

cargo test -p calternal-server --test perf_guards --test private_index_permissions -- --test-threads=4

    Finished `test` profile [unoptimized + debuginfo] target(s) in 9m 58s
test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 69.64s
test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.38s

cd apps/web && bun run check

perf-lint: PASS; 0 violations; 22496 scoped exceptions
svelte-check found 0 errors and 4 warnings in 2 files

cd apps/web && bun run test -- --maxWorkers=2

 Test Files  297 passed (297)
      Tests  2120 passed (2120)
   Duration  662.45s (environment 28%, transform 25%, import 23%, tests 17%, setup 6%)

Known gaps and UX gaps left

The broad server gate has the SLOW-only Calendar timing failure above. Its focused recheck passes. There is no changed assertion or raised timing budget.
Tick throughput is much better, but 1,000 durable ticks still take about four minutes on this fixture. Source application still scans the Note for each Task in a group. The new trace and profile retain these costs for follow-up work.
The baseline has no complete CPU/RSS series. Do not claim a resource regression or improvement from its partial sample.
API list visibility is measured. No web code changed; this job does not measure browser render latency or add UI controls.
All requested Task burst, error and crash checks pass after the fix. No functional gap remains in those scenarios.

For the merge round

Run cargo test -p calternal-server -- --test-threads=4 in the combined branch. It must run the normal live-app launcher and prove the Calendar startup timing gate and server integrations together. This job already ran the requested Task completion, Undo and crash scenarios; they are not deferred.

Completed #1446 and #1447 on `job/tick-1446`. Head: `35afee54f7d361856e4e8ac7aaef3599ceaebd44`. The worktree is clean. No issue is closed. The cause was retained filesystem directory descriptors. The release after run returned 1,000 HTTP 200 completions and 1,000 HTTP 200 Undo responses. Visibility fell from 1,532.662 s to 265.587 s. All 103 acknowledged VM crash ticks and all 104 local crash ticks survived; disk and Index agree for all 1,000 Tasks. The broad server test run has one SLOW-only Calendar startup timing failure; its focused recheck and both server integrations pass. All changed-crate, clippy, formatting and web checks pass. Detailed verbatim results, files, remaining performance costs and decisions follow. # Task ticks: durable bulk completion and Undo (#1446, #1447) ## Built - Share filesystem directory proof handles by live kernel identity. Keep at most 64 distinct optional pins per Root. Keep the full pre-write token for each event. This prevents a slow change subscriber from using one descriptor per tick. - Return `503 service_unavailable` with `Retry-After: 1` for descriptor pressure and temporary filesystem contention. Stale Task source or Note identity returns `409 conflict` before a write. - Coalesce unguarded User ticks on distinct Tasks in one Note. Sync the checked Note replacement, commit the complete Task projection, then acknowledge each request. Opposite edits of the same Task have separate durable commits. Guarded and Agent ticks retain their request scope. - Insert Task and reminder projections in groups of 200 rows. Reserve one reminder cursor range and prune once per source transaction. Clone the source hash state for reminder ETags. The ETag bytes and stale DAV write protection stay the same. - Repair a stale projection when an idempotent retry finds its intended state already on disk. The retry creates no extra Version. - Add concurrent Rust tests, a low-descriptor subprocess test, a real-server burst profile, and a SIGKILL recovery probe. ## Evidence The locked release baseline reproduced 1,000 completions in 1,532.609 s (all 200), then Undo in 393.684 s (168 HTTP 200, 832 HTTP 500). Every 500 body was `{"code":"internal","message":"Notes operation failed"}`. The first server errors were `Too many open files (os error 24)`. Directory proofs held by the change queue caused the descriptor shortage. Shutdown `PoolClosed` messages occurred later and are not the cause. The filesystem regression performs 1,000 writes to one Note and 500 writes across distinct parent directories under RLIMIT_NOFILE=96. It passed. Concurrent Task tests cover Tasks in one Daily note and in different Notes, opposite ticks, repeated Undo, stale identity, and repair after an unacknowledged projection. ## Expected cost For a burst, writes and projection transactions scale with Note batches, rather than with individual ticks. At concurrency 8, a full group normally contains eight distinct Tasks. SQL inserts cost ceil(rows / 200) statements. Source ETag hashing costs Note bytes plus projected row bytes, rather than rows times Note bytes. Applying a group still scans the Note for each Task in memory. No request scans the full Home. ## Decisions - Use the existing User writer guard. Do not add a second writer authority. - Use a 2 ms collection window, 64 operations per group, a queue of 256, and a 30 s guard timeout. A full queue or timeout returns the existing stable retry response. - Batch only unguarded User ticks. Keep Agent attribution and If-Match semantics in the direct request path. - Share at most 64 live directory pins per Root. Above this budget, omit the optional proof and use the existing conservative adoption path. This does not change write authority or durability. - Refresh exact performance guard identities and add exact in-memory call proofs. Move existing read-path projection debt to its live batched statements. Reduce the exception count by 48; do not weaken any rule or raise a ratchet. ## UX gaps closed Bulk Undo no longer fails from retained descriptors. A stale Task no longer receives a misleading 500. An idempotent retry repairs its Index before returning success. No UI controls changed. ## Release measurements Use `perf-run` on `perf-test-69-63`. Build here and copy the binaries. Before uses shared release `af202e151`; its Notes sources match the #1374 audit source. After uses the branch code through `16ac6bd3f`. Use four Tokio workers, concurrency 8 and RLIMIT_NOFILE=1,024. The fixture has one Daily note with 1,000 Tasks, 2,000 unrelated Notes and 5,000 Files. It omits the 24 Photos and two linked Notes from #1374. These are Task measurements, not a new full-Home audit. | Phase | Returned, before | Visible, before | Returned, after | Visible, after | HTTP results, before → after | | --- | ---: | ---: | ---: | ---: | --- | | Complete 1,000 | 1,532.609 s | 1,532.662 s | 265.529 s | 265.587 s | 1,000 × 200 → 1,000 × 200 | | Undo 1,000 | 393.684 s | 393.754 s | 256.140 s | 256.188 s | 168 × 200 + 832 × 500 → 1,000 × 200 | Completion is 5.77 times faster. Both after lists have all 1,000 intended states. The before Undo list has only 168 intended states. Its shorter duration includes failed work; do not compare it as a successful 1,000-Task Undo. | Per request | Before p50 / p95 | After p50 / p95 | | --- | ---: | ---: | | Complete | 12,083.019 / 14,245.052 ms | 1,871.750 / 3,461.383 ms | | Undo, all responses | 2,658.503 / 8,766.526 ms | 1,917.826 / 3,466.301 ms | | Warm single tick, 10 samples | 2,710.857 / 12,373.122 ms | 1,447.167 / 3,379.189 ms | The after single-tick trace separates synced replacement from projection. Median durable time is 470.200 ms; median projection time is 168.727 ms. Means are 657.151 ms and 252.102 ms. HTTP total also includes preparation, the collection window, writer wait and response work. Durability remains a material cost. A burst amortizes it across eight Tasks rather than weakening it. After completion uses 551.16 server CPU seconds (207.57% mean CPU) and 981,400 KiB peak RSS. Undo uses 539.63 CPU seconds (210.68%) and 1,028,692 KiB peak RSS. These are whole-process numbers and include background workers. The before resource sampler started partway through Undo, so there is no valid whole-burst CPU/RSS comparison. The new profile records these metrics for later comparisons. `docs/perf/baseline.json` has no earlier Task tick profile; this report adds the explicit before/after entry. The before load average was `0.10 0.36 0.56` at the start. The after locked session started at `1.22 1.54 1.85`. The copied fixture had an old Task source path in its Index. Run the existing Notes reconcile action once before the after samples. Fixture preparation and path settlement are outside all reported tick timings. An earlier 404 run is invalid and is excluded. ## Real local reproduction and crash recovery With the Notes debug flag used by the real-server harness and a 1,024 descriptor limit, the shared release reproduced all 1,000 completions in 1,370.244 s, then 174 successful Undo requests and 826 HTTP 500 responses. The first Undo failure was near Task 61. Its body was `{"code":"internal","message":"Notes operation failed"}`. The retained server log has EMFILE errors. This is the controlled local reproduction. An earlier busy-host run had transport timeouts and changed its limit late; it is retained as load evidence only. The fixed local release returned 1,000 × 200 for completion and 1,000 × 200 for Undo. The lists had all intended states. Completion returned in 231.555 s; Undo returned in 262.265 s. These are local, busy-host measurements. On the local release, SIGKILL followed 104 success receipts during a 1,000-tick burst. Restart retained all 104 and Markdown agreed with all 1,000 Task rows. On the perf VM, SIGKILL followed 103 success receipts. The server restarted on the same data roots. The first recovery probe had no fixture User ID file; its disk check failed on that configuration error. Its Index check had already found every acknowledged tick. A read-only check of the restarted, stopped fixture with the verified User ID confirmed all 103 receipts and all 1,000 disk/Index states. This check starts no server or measurement workload. The redundant queued recovery run was cancelled. No completed operation or burst was repeated. ## Files - `crates/calternal-fs/src/root.rs`, `src/write.rs`, `tests/storage.rs`: shared proof pins and the low-descriptor regression. - `crates/plugins/notes/src/tasks_api.rs`, `src/tasks_tick.rs`, `src/tasks_store.rs`, `src/lib.rs`, `README.md`: tick admission, durable grouping, projection batching, retry errors, tests and invariants. - `bench/task-tick-1446.mjs`, `tests/adversarial/tasks-tick-1446.mjs`: real-server requests, timing, resource samples, acceptance and recovery checks. - `contracts/perf/registry.json`, `exceptions.json`, `ratchet.json`, `adoption-1058.json`: exact live guard proofs and smaller debt. - `docs/perf/baseline.json`, this report: explicit measurements and limits. ## Gates Run all Cargo commands with `CARGO_PROFILE_DEV_DEBUG=line-tables-only`, `CARGO_INCREMENTAL=0`, `CARGO_BUILD_JOBS=4` and worktree `target/tmp` as `TMPDIR`. `cargo fmt --check` exits 0 with no output. Result lines below are verbatim. Full logs remain in ignored `artifacts/tick-1446/`. `cargo clippy -p calternal-fs --all-targets -- -D warnings` ``` Finished `dev` profile [unoptimized + debuginfo] target(s) in 20.77s ``` `cargo test -p calternal-fs -- --test-threads=4` ``` Finished `test` profile [unoptimized + debuginfo] target(s) in 2.26s test result: ok. 98 passed; 0 failed; 1 ignored; 0 measured; 0 filtered out; finished in 45.55s test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.15s test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 1.27s test result: ok. 53 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 275.79s test result: ok. 2 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.08s test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s ``` `cargo clippy -p calternal-plugin-notes --all-targets -- -D warnings` ``` Finished `dev` profile [unoptimized + debuginfo] target(s) in 38.67s ``` `cargo test -p calternal-plugin-notes -- --test-threads=4` ``` Finished `test` profile [unoptimized + debuginfo] target(s) in 2m 20s test result: ok. 324 passed; 0 failed; 4 ignored; 0 measured; 0 filtered out; finished in 374.92s test result: ok. 2 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 2.72s test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s ``` `cargo clippy -p calternal-server --all-targets -- -D warnings` ``` Finished `dev` profile [unoptimized + debuginfo] target(s) in 8m 47s ``` `cargo test -p calternal-server -- --test-threads=4` ``` search_reconcile_calendar_write_profile files=20000 writes=32 p50_ms=10295 p95_ms=10615 p95_budget_ms=10000 Calendar write p95 10.61581893s exceeded 10s test result: FAILED. 271 passed; 1 failed; 12 ignored; 0 measured; 0 filtered out; finished in 193.87s ``` The only broad server failure is a timing budget in the 20,000-File Calendar startup profile. Keep its expectation unchanged. The focused recheck passes. An initial direct invocation of the ignored live-app test used the default debug test stack and aborted. The existing live-app launcher supplies a larger stack. The corrected focused command used `RUST_MIN_STACK=8388608`: `cargo test -p calternal-server wire::tests::startup_search_reconciliation_keeps_calendar_writes_responsive_on_large_home -- --ignored --exact --test-threads=1` ``` Finished `test` profile [unoptimized + debuginfo] target(s) in 2m 01s test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 283 filtered out; finished in 77.90s ``` Run the server integration tests that the broad failure had not reached: `cargo test -p calternal-server --test perf_guards --test private_index_permissions -- --test-threads=4` ``` Finished `test` profile [unoptimized + debuginfo] target(s) in 9m 58s test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 69.64s test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.38s ``` `cd apps/web && bun run check` ``` perf-lint: PASS; 0 violations; 22496 scoped exceptions svelte-check found 0 errors and 4 warnings in 2 files ``` `cd apps/web && bun run test -- --maxWorkers=2` ``` Test Files 297 passed (297) Tests 2120 passed (2120) Duration 662.45s (environment 28%, transform 25%, import 23%, tests 17%, setup 6%) ``` ## Known gaps and UX gaps left - The broad server gate has the SLOW-only Calendar timing failure above. Its focused recheck passes. There is no changed assertion or raised timing budget. - Tick throughput is much better, but 1,000 durable ticks still take about four minutes on this fixture. Source application still scans the Note for each Task in a group. The new trace and profile retain these costs for follow-up work. - The baseline has no complete CPU/RSS series. Do not claim a resource regression or improvement from its partial sample. - API list visibility is measured. No web code changed; this job does not measure browser render latency or add UI controls. - All requested Task burst, error and crash checks pass after the fix. No functional gap remains in those scenarios. ## For the merge round Run `cargo test -p calternal-server -- --test-threads=4` in the combined branch. It must run the normal live-app launcher and prove the Calendar startup timing gate and server integrations together. This job already ran the requested Task completion, Undo and crash scenarios; they are not deferred.

kayg referenced this issue

2026-10-08 18:42:36 +00:00

Merge round 35b #1479

kayg referenced this issue from a commit

2026-10-08 19:43:32 +00:00

Merge job/tick-1446 (#1446 #1447)

kayg commented

2026-10-09 05:36:38 +00:00

Author

Owner

Deployed to calternal.cloud in merge round 35b (build 9dc65437e, live 2026-10-09 ~11:07 IST). Closing.

Deployed to calternal.cloud in merge round 35b (build 9dc65437e, live 2026-10-09 ~11:07 IST). Closing.