Collab: shared-note WebSocket upgrade intermittently refused in owner_editor_viewer_and_live_revoke #77

Closed
opened 2026-09-24 23:29:59 +00:00 by kayg · 13 comments
Owner

crates/calternal-collab/tests/shared_notes.rs::owner_editor_viewer_and_live_revoke fails about 1 run in 3 on the loaded build VM (seen on 8c21675 and c5c462c):

error: WebSocket connection to 'ws://127.0.0.1:<port>/collab/shared/<owner>/notes/<id>' failed: Expected 101 status code

The shared-note WebSocket upgrade is sometimes refused (not accepted wrongly, so this is not an authorization hole). Likely a race: shared_notes.mjs connects the editor/viewer before the share row or the note's Index identity is visible to SharedNoteAccess. It could also be a real product race, where a recipient opening a just-shared note gets refused for a moment.

Do: find which check refuses the upgrade (log the status and reason in the test), decide whether it's a test setup race (fix the test to wait on a real readiness signal) or a product race (make the share and identity visible before the share API returns, or retry the access lookup briefly on upgrade), and prove it with 50 consecutive passing runs under load.

`crates/calternal-collab/tests/shared_notes.rs::owner_editor_viewer_and_live_revoke` fails about 1 run in 3 on the loaded build VM (seen on `8c21675` and `c5c462c`): ``` error: WebSocket connection to 'ws://127.0.0.1:<port>/collab/shared/<owner>/notes/<id>' failed: Expected 101 status code ``` The shared-note WebSocket upgrade is sometimes refused (not accepted wrongly, so this is not an authorization hole). Likely a race: `shared_notes.mjs` connects the editor/viewer before the share row or the note's Index identity is visible to `SharedNoteAccess`. It could also be a real product race, where a recipient opening a just-shared note gets refused for a moment. Do: find which check refuses the upgrade (log the status and reason in the test), decide whether it's a test setup race (fix the test to wait on a real readiness signal) or a product race (make the share and identity visible before the share API returns, or retry the access lookup briefly on upgrade), and prove it with 50 consecutive passing runs under load.
Author
Owner

Investigation start: branch job/collab-flake, base/head c5c462c147. I am tracing the shared WebSocket handshake and will add the rejection status/reason to the real-client test before changing behavior.

Investigation start: branch job/collab-flake, base/head c5c462c147999c013e1db04bcf81f1dcee8e21b1. I am tracing the shared WebSocket handshake and will add the rejection status/reason to the real-client test before changing behavior.
Author
Owner

Finding: the shared Note test seeds note_items, files_index, and both Share rows before it starts the server. The viewer then connects after a fixed 900 ms sleep. The Hub flush is debounced at 750 ms, and Files refreshes its fingerprint only after the atomic Note write and Notes Index update. On a loaded machine, the viewer request can therefore overlap the save and see a stale Files identity. I added status and lookup-reason diagnostics; the runtime result will confirm or rule this out.

Finding: the shared Note test seeds note_items, files_index, and both Share rows before it starts the server. The viewer then connects after a fixed 900 ms sleep. The Hub flush is debounced at 750 ms, and Files refreshes its fingerprint only after the atomic Note write and Notes Index update. On a loaded machine, the viewer request can therefore overlap the save and see a stale Files identity. I added status and lookup-reason diagnostics; the runtime result will confirm or rule this out.
Author
Owner

Confirmed product race with a deterministic test: after the Notes atomic write, the test pauses the Files identity refresh and opens a viewer WebSocket. The fixture's Share row is still present, but Files rejects its stale item fingerprint. The endpoint returns 403 Forbidden and Bun reports Expected 101 status code. The same denied lookup also appeared in the earlier nondeterministic run after a 101 handshake, which then timed out waiting for the viewer to converge. I am adding a bounded recheck at shared-note connection admission; every retry reads the live Share and immutable Files identity again.

Confirmed product race with a deterministic test: after the Notes atomic write, the test pauses the Files identity refresh and opens a viewer WebSocket. The fixture's Share row is still present, but Files rejects its stale item fingerprint. The endpoint returns 403 Forbidden and Bun reports Expected 101 status code. The same denied lookup also appeared in the earlier nondeterministic run after a 101 handshake, which then timed out waiting for the viewer to converge. I am adding a bounded recheck at shared-note connection admission; every retry reads the live Share and immutable Files identity again.
Author
Owner

Gate finding: workspace Clippy stopped at calternal-server because the embedded SPA build directory is absent: does not exist. The resulting Frontend::get errors are downstream of the missing embedded assets. I will build the existing web app output and rerun the gate; this did not require a Rust source change.

Gate finding: workspace Clippy stopped at calternal-server because the embedded SPA build directory is absent: does not exist. The resulting Frontend::get errors are downstream of the missing embedded assets. I will build the existing web app output and rerun the gate; this did not require a Rust source change.
Author
Owner

Gate finding: workspace Clippy stopped at calternal-server because the embedded SPA build directory is absent: crates/calternal-server/../../apps/web/build/ does not exist. The Frontend::get errors are downstream of the missing embedded assets. I will build the existing web app output and rerun the gate; no Rust source change is needed.

Gate finding: workspace Clippy stopped at calternal-server because the embedded SPA build directory is absent: crates/calternal-server/../../apps/web/build/ does not exist. The Frontend::get errors are downstream of the missing embedded assets. I will build the existing web app output and rerun the gate; no Rust source change is needed.
Author
Owner

Additional finding from the full workspace run: while the test held the post-rename Files fingerprint stale, the already-open editor hit serve's periodic SharedNoteAccess check and was closed before the viewer handshake. The test failed at editor Share lost after Note save. Therefore the same bounded fresh lookup is needed at active-session access checks as well as initial upgrade admission.

Additional finding from the full workspace run: while the test held the post-rename Files fingerprint stale, the already-open editor hit serve's periodic SharedNoteAccess check and was closed before the viewer handshake. The test failed at editor Share lost after Note save. Therefore the same bounded fresh lookup is needed at active-session access checks as well as initial upgrade admission.
Author
Owner

The first loaded 50-run attempt reached 14 passes and failed on run 15. Files still reported the pre-seeded Share row with a stale item fingerprint after the collab layer's 30 ms retry window; the already-open editor closed. I am moving the bounded wait to Files' Note Share lookup and will retry only while the Share row still names the currently indexed item. A missing or changed item identity will continue to deny without a grace period.

The first loaded 50-run attempt reached 14 passes and failed on run 15. Files still reported the pre-seeded Share row with a stale item fingerprint after the collab layer's 30 ms retry window; the already-open editor closed. I am moving the bounded wait to Files' Note Share lookup and will retry only while the Share row still names the currently indexed item. A missing or changed item identity will continue to deny without a grace period.
Author
Owner

Workspace cargo test --workspace has not completed after more than 30 minutes. The runner is still inside calternal_server::wire::tests::full_app_setup_session_config_and_backup --exact --ignored --test-threads=1, launched by wire::tests::live_apps_run_in_separate_processes; there has been no test output during the stall. I am stopping this run to free the machine for the required 50-pass shared_notes run and will report the workspace gate as stalled unless it completes on a later retry.

Workspace `cargo test --workspace` has not completed after more than 30 minutes. The runner is still inside `calternal_server::wire::tests::full_app_setup_session_config_and_backup --exact --ignored --test-threads=1`, launched by `wire::tests::live_apps_run_in_separate_processes`; there has been no test output during the stall. I am stopping this run to free the machine for the required 50-pass `shared_notes` run and will report the workspace gate as stalled unless it completes on a later retry.
Author
Owner

The selective Files retry did not cover the intermittent case: the latest 50-run attempt passed 14 runs, then the editor WebSocket closed during run 15. The test logged four access denials while the Share row still existed, and the Notes session reported editor Share lost after Note save. I am instrumenting the regression to record the Share-bound and current Files item IDs at the atomic-save boundary; this will distinguish a delayed fingerprint refresh from an Index identity change.

The selective Files retry did not cover the intermittent case: the latest 50-run attempt passed 14 runs, then the editor WebSocket closed during run 15. The test logged four access denials while the Share row still existed, and the Notes session reported `editor Share lost after Note save`. I am instrumenting the regression to record the Share-bound and current Files item IDs at the atomic-save boundary; this will distinguish a delayed fingerprint refresh from an Index identity change.
Author
Owner

The timing-labeled failure is the live-revoke wait (editor close after Share revoke), after the Note save had refreshed Files access successfully. The shared session checks idle connections on a 1-second timer, then may spend 30 ms in the access retry; this leaves little room under the test's 1.1-second close bound. I am shortening the idle recheck to 500 ms, which keeps access checks current and gives revoke a scheduling margin without changing grant decisions.

The timing-labeled failure is the live-revoke wait (`editor close after Share revoke`), after the Note save had refreshed Files access successfully. The shared session checks idle connections on a 1-second timer, then may spend 30 ms in the access retry; this leaves little room under the test's 1.1-second close bound. I am shortening the idle recheck to 500 ms, which keeps access checks current and gives revoke a scheduling margin without changing grant decisions.
Author
Owner

The workspace test run passed the collab, Files, Notes, and other reached package suites, then stalled in wire::tests::live_apps_run_in_separate_processes while its child runs wire::tests::full_app_setup_session_config_and_backup. The child removed its temporary member Home but did not return the user-delete response. The route holds Root::lock_mutation() while calling FilesState::reconcile_all(), which takes the same lock, matching the stall. calternal-server is outside this job's owned files, so I am stopping this run and will report the workspace gate as blocked by that existing server test.

The workspace test run passed the collab, Files, Notes, and other reached package suites, then stalled in `wire::tests::live_apps_run_in_separate_processes` while its child runs `wire::tests::full_app_setup_session_config_and_backup`. The child removed its temporary member Home but did not return the user-delete response. The route holds `Root::lock_mutation()` while calling `FilesState::reconcile_all()`, which takes the same lock, matching the stall. `calternal-server` is outside this job's owned files, so I am stopping this run and will report the workspace gate as blocked by that existing server test.
Author
Owner

Finished. HEAD: 0fcec8faa170e62ad556bec40f32e1bf9dd22c26. Working tree is clean.

Built:

  • Files shared-Note access now retries for at most 160 ms only when the live Share still names the current indexed item and its filesystem fingerprint is stale. Revoked, missing, and replaced identities still deny immediately.
  • Shared Note sessions recheck idle connections every 500 ms, leaving margin for live Share revocation.
  • The shared-notes WebSocket regression records handshake status/reason and item identities, holds a real post-rename stale-fingerprint interval, and labels the convergence stage on failure.

Gate output:

  • cargo fmt --check: no output; exit 0.
  • cargo clippy --workspace --all-targets -- -D warnings: Finished dev profile [unoptimized + debuginfo] target(s) in 41.96s
  • 50-run stress loop:
    pass 50/50
    shared_notes consecutive passes: 50/50
    50
    
  • cargo test --workspace --exclude calternal-server: exit 0. Relevant exact output: test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 3.76s (shared_notes) and test result: ok. 51 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 31.63s (Files).
  • cargo test --workspace: interrupted (exit 130) in the nested live-app test after output test wire::tests::live_apps_run_in_separate_processes has been running for over 60 seconds.
  • cargo clean: Removed 15077 files, 10.9GiB total

Known gap: the full workspace test stalls in calternal-server::wire::tests::full_app_setup_session_config_and_backup, after its user-delete route removes the temporary member Home. Inspection points to delete_user retaining Root::lock_mutation() while it calls FilesState::reconcile_all(), which takes the same lock. calternal-server is outside this job's owned files, so it remains unresolved here.

Decisions not set by DESIGN.md: the stale-fingerprint retry window is 8 retries at 20 ms (160 ms total); the idle shared-session recheck interval is 500 ms to fit the test's sub-second revoke expectation.

Finished. HEAD: `0fcec8faa170e62ad556bec40f32e1bf9dd22c26`. Working tree is clean. Built: - Files shared-Note access now retries for at most 160 ms only when the live Share still names the current indexed item and its filesystem fingerprint is stale. Revoked, missing, and replaced identities still deny immediately. - Shared Note sessions recheck idle connections every 500 ms, leaving margin for live Share revocation. - The shared-notes WebSocket regression records handshake status/reason and item identities, holds a real post-rename stale-fingerprint interval, and labels the convergence stage on failure. Gate output: - `cargo fmt --check`: no output; exit 0. - `cargo clippy --workspace --all-targets -- -D warnings`: `Finished `dev` profile [unoptimized + debuginfo] target(s) in 41.96s` - 50-run stress loop: ``` pass 50/50 shared_notes consecutive passes: 50/50 50 ``` - `cargo test --workspace --exclude calternal-server`: exit 0. Relevant exact output: `test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 3.76s` (shared_notes) and `test result: ok. 51 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 31.63s` (Files). - `cargo test --workspace`: interrupted (exit 130) in the nested live-app test after output `test wire::tests::live_apps_run_in_separate_processes has been running for over 60 seconds`. - `cargo clean`: `Removed 15077 files, 10.9GiB total` Known gap: the full workspace test stalls in `calternal-server::wire::tests::full_app_setup_session_config_and_backup`, after its user-delete route removes the temporary member Home. Inspection points to `delete_user` retaining `Root::lock_mutation()` while it calls `FilesState::reconcile_all()`, which takes the same lock. `calternal-server` is outside this job's owned files, so it remains unresolved here. Decisions not set by DESIGN.md: the stale-fingerprint retry window is 8 retries at 20 ms (160 ms total); the idle shared-session recheck interval is 500 ms to fit the test's sub-second revoke expectation.
Author
Owner

Completed on dev in 2de7f022a3 (Merge job/collab-flake: Collab: retry shared-note access across atomic saves; faster idle revoke checks (#77)).

Completed on dev in 2de7f022a3d18eddaf8592fbfcbdb379065476e3 (Merge job/collab-flake: Collab: retry shared-note access across atomic saves; faster idle revoke checks (#77)).
kayg closed this issue 2026-10-01 05:09:01 +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#77
No description provided.