Prevent Tokio worker stack overflow during adversarial API load #519

Open
opened 2026-09-30 13:58:06 +00:00 by kayg · 11 comments
Owner

Evidence

A full local hostile-input round on job/motion-477 at b62297fa0d5e22dd70b1263027d3a6527c5dc476 produced a server crash. The captured server log contains:

2026-09-30T13:53:19Z thread 'tokio-rt-worker' has overflowed its stack
fatal runtime error: stack overflow, aborting

The server process then exited. Subsequent probes received 502 local adversarial server is unavailable; these are a cascade from the process death, not separate route findings. The round had slow requests while several other jobs were compiling and testing on the shared host. The log before the crash shows WebDAV upload work, Tantivy commits, and ONNX Runtime allocation, but the broad run did not identify the exact triggering request. No minimal reproduction is known yet.

The redacted captured log is attached. The runner was stopped after the crash cascade. Please isolate the trigger, fix the worker stack overflow, and add a focused regression probe.

## Evidence A full local hostile-input round on `job/motion-477` at `b62297fa0d5e22dd70b1263027d3a6527c5dc476` produced a server crash. The captured server log contains: ```text 2026-09-30T13:53:19Z thread 'tokio-rt-worker' has overflowed its stack fatal runtime error: stack overflow, aborting ``` The server process then exited. Subsequent probes received `502 local adversarial server is unavailable`; these are a cascade from the process death, not separate route findings. The round had slow requests while several other jobs were compiling and testing on the shared host. The log before the crash shows WebDAV upload work, Tantivy commits, and ONNX Runtime allocation, but the broad run did not identify the exact triggering request. No minimal reproduction is known yet. The redacted captured log is attached. The runner was stopped after the crash cascade. Please isolate the trigger, fix the worker stack overflow, and add a focused regression probe.
Author
Owner

This issue may duplicate #325. The 2026-09-30 evidence from the motion-477 adversarial run has been added to #325, where the existing Search watcher-overflow report is tracked. I created #519 before searching the issue list, so please treat the two together during triage.

This issue may duplicate #325. The 2026-09-30 evidence from the motion-477 adversarial run has been added to #325, where the existing Search watcher-overflow report is tracked. I created #519 before searching the issue list, so please treat the two together during triage.
Author
Owner

Starting files-open latency investigation on branch job/files-slow, base SHA cd3cea7575. The issue view currently describes a Tokio stack overflow, while this job prompt describes the Files loading regression; I am following the Files regression specified by the job.

Starting files-open latency investigation on branch job/files-slow, base SHA cd3cea757508d9f581d00fb7d5d7973fbc0a75fd. The issue view currently describes a Tokio stack overflow, while this job prompt describes the Files loading regression; I am following the Files regression specified by the job.
Author
Owner

Finding: the “Opening Files…” shell in apps/web/src/routes/+layout.svelte remains until selectMode's preloadMode promise resolves. That promise waits for SvelteKit preloadCode + preloadData and preloadModeData; the Files branch in modePreload.ts also waits for preloadRootPage(), which fetches GET /api/v1/files/entries?path=&limit=500&sort=name. This is the exact client gate I am timing in the good and bad production builds. The issue body mismatch noted in my start comment remains.

Finding: the “Opening Files…” shell in apps/web/src/routes/+layout.svelte remains until selectMode's preloadMode promise resolves. That promise waits for SvelteKit preloadCode + preloadData and preloadModeData; the Files branch in modePreload.ts also waits for preloadRootPage(), which fetches GET /api/v1/files/entries?path=&limit=500&sort=name. This is the exact client gate I am timing in the good and bad production builds. The issue body mismatch noted in my start comment remains.
Author
Owner

Finding from a local production-SPA run: direct navigation to /photos reached its ready selector, but after returning to /files, clicking the Photos Tab did not produce the ready Photos state within the probe's 30-second wait. The run aborted before writing its JSON. This shows a second cold-mode preloader wait and means the existing switch-to-Photos interaction sample is not currently usable; I am checking whether the same gate explains Files and will keep the route assertion intact.

Finding from a local production-SPA run: direct navigation to /photos reached its ready selector, but after returning to /files, clicking the Photos Tab did not produce the ready Photos state within the probe's 30-second wait. The run aborted before writing its JSON. This shows a second cold-mode preloader wait and means the existing switch-to-Photos interaction sample is not currently usable; I am checking whether the same gate explains Files and will keep the route assertion intact.
Author
Owner

Measured finding (#519): Files stays on Opening Files because the tray changes layout between pointerdown and pointerup. In the production SPA probe, the gesture began on Files (tab-files), pendingMode immediately selected Files and expanded its active label, then pointerup landed on Photos (tab-photos); the browser emitted no click event, so selectMode never calls goto. Both preloads completed (preloadRoute=true, preloadModeData done), and /api/v1/files/entries?path=&limit=500&sort=name returned 200 in 53–103 ms. The mode therefore remains pending indefinitely after an ordinary pointer click misses. I am bisecting the supplied deploy sequence to identify which deployed change made this tray movement an input regression.

Measured finding (#519): Files stays on Opening Files because the tray changes layout between pointerdown and pointerup. In the production SPA probe, the gesture began on Files (tab-files), pendingMode immediately selected Files and expanded its active label, then pointerup landed on Photos (tab-photos); the browser emitted no click event, so selectMode never calls goto. Both preloads completed (preloadRoute=true, preloadModeData done), and /api/v1/files/entries?path=&limit=500&sort=name returned 200 in 53–103 ms. The mode therefore remains pending indefinitely after an ordinary pointer click misses. I am bisecting the supplied deploy sequence to identify which deployed change made this tray movement an input regression.
Author
Owner

Measured root cause and fix for #519:

  • Culprit source commit: 9a4275387dddd93595a85b611594acdfc988915f (2026-09-27, “Switch mode views with pointerdown preloading”). It is an ancestor of both deployed 99288dcfe and 5d6d22e60. Its preloadModeOnPointerDown sets pendingMode immediately. That expands the selected tab label between pointerdown and pointerup. In both deployed builds the pointer starts on Files and ends on Photos; no click fires, so selectMode never navigates and the UI stays on “Opening Files…”.
  • The Files entries API is not the waiter: it returned 200 in 59 ms at 99288dcfe and 143 ms at 5d6d22e60. Both probes had zero rows after 8.8 s / 10.3 s. The report that this began between 992 and 5d is not supported by the local reproduction; the same defect is present in the earlier “fast” commit.
  • The fix leaves the active tab unchanged until click, while keeping pointerdown route/data preloading. The route profile now uses a real 2,000-file Home and measures the first painted row. Local post-fix phone/tablet/desktop results were 886 / 434 / 1,085 ms (p95 across these three samples: 1,085 ms) at host load averages 40.22–41.44. The 500 ms budget is recorded as missed in this overloaded local run. On phone, /api/v1/files/entries?path=&limit=500&sort=name returned 200 and completed 309 ms after input; three main-thread long tasks lasted 171, 116, and 81 ms.
  • Other direct route profiles cover Calendar, Files, Photos, Mail, Money, Analytics, Notes, and Appearance at 390/820/1440 px. Calendar, Photos, Mail, and Analytics tab activations are measured too. Money is not enabled in this local mode catalog, so only its direct route is measured.

Good-path Playwright trace: apps/web/target/perf/files-good-trace.zip. The bad-path Playwright/Chrome profiles and request logs are target/perf/mode-switch-trace-992.json, target/perf/mode-switch-trace-5d.json, target/perf/mode-switch-992.json, and target/perf/mode-switch.json. None of these artifacts are committed.

Measured root cause and fix for #519: - Culprit source commit: `9a4275387dddd93595a85b611594acdfc988915f` (2026-09-27, “Switch mode views with pointerdown preloading”). It is an ancestor of both deployed `99288dcfe` and `5d6d22e60`. Its `preloadModeOnPointerDown` sets `pendingMode` immediately. That expands the selected tab label between pointerdown and pointerup. In both deployed builds the pointer starts on Files and ends on Photos; no `click` fires, so `selectMode` never navigates and the UI stays on “Opening Files…”. - The Files entries API is not the waiter: it returned 200 in 59 ms at `99288dcfe` and 143 ms at `5d6d22e60`. Both probes had zero rows after 8.8 s / 10.3 s. The report that this began between 992 and 5d is not supported by the local reproduction; the same defect is present in the earlier “fast” commit. - The fix leaves the active tab unchanged until click, while keeping pointerdown route/data preloading. The route profile now uses a real 2,000-file Home and measures the first painted row. Local post-fix phone/tablet/desktop results were 886 / 434 / 1,085 ms (p95 across these three samples: 1,085 ms) at host load averages 40.22–41.44. The 500 ms budget is recorded as missed in this overloaded local run. On phone, `/api/v1/files/entries?path=&limit=500&sort=name` returned 200 and completed 309 ms after input; three main-thread long tasks lasted 171, 116, and 81 ms. - Other direct route profiles cover Calendar, Files, Photos, Mail, Money, Analytics, Notes, and Appearance at 390/820/1440 px. Calendar, Photos, Mail, and Analytics tab activations are measured too. Money is not enabled in this local mode catalog, so only its direct route is measured. Good-path Playwright trace: `apps/web/target/perf/files-good-trace.zip`. The bad-path Playwright/Chrome profiles and request logs are `target/perf/mode-switch-trace-992.json`, `target/perf/mode-switch-trace-5d.json`, `target/perf/mode-switch-992.json`, and `target/perf/mode-switch.json`. None of these artifacts are committed.
Author
Owner

Result

The regression is in 9a4275387dddd93595a85b611594acdfc988915f (2026-09-27, “Switch mode views with pointerdown preloading”). preloadModeOnPointerDown set pendingMode before the click. That changed the selected tab label and width during the press, moving the hit target before pointerup. The production probe saw pointerdown on Files and pointerup on Photos, with no click; navigation never started and “Opening Files…” remained visible. The fix removes this premature selection state while keeping deferred preloading.

The supplied deploy list does not isolate a new regression after 99288dcfe: both 99288dcfe and 5d6d22e60 reproduce it. On those builds, Files showed zero rows after 8.8s and 10.3s. The entries endpoint returned 200 in 59ms and 143ms, respectively, so the wait was in the client interaction, not that endpoint.

After fix

A production web build on the merged branch used a 2,000-file Home fixture and measured first-row paint once at each requested width. Under substantial shared-host load (load average rose from 24.49/29.57/28.61 to 32.71/31.91/29.89), Files painted its first row in 841ms at 390px, 999ms at 820px, and 1,058ms at 1440px (three-sample p95: 1,058ms). The /api/v1/files/entries?path=&limit=500&sort=name request returned 200 in 34ms; it ended 272ms after pointerdown. Files JS/CSS resources ended in 161–178ms. Tracing recorded 60ms and 104ms main-thread long tasks.

The example 500ms budget is included and was missed in this loaded local run. This is a performance finding, not a correctness failure. The same one-run-per-tab profile measured switch p95s: Calendar 1,425ms, Photos 680ms, Mail 744ms, Money 560ms, Analytics 2,856ms. The request storm made 4,242 requests (p50 38ms, p95 198ms; all 200); observed server peak RSS was about 298.6MB. Direct files.entries route timing was p50/p95 69.7ms (one sample).

Gates

bun install --frozen-lockfile:

Checked 631 installs across 749 packages (no changes) [1.84s]

bun run build:

✓ built in 33.15s
Run npm run preview to preview your production build locally.
> Using @sveltejs/adapter-static
  Wrote site to "build"
  ✔ done

bun run check:

$ node scripts/check-type-tokens.mjs && node scripts/check-motion-tokens.mjs && svelte-kit sync && svelte-check --tsconfig ./tsconfig.json
Text sizes and UI shape values use shared role tokens.
UI transitions and animation options use shared motion tokens or documented exceptions.

bun run test:

 Test Files  140 passed (140)
      Tests  914 passed (914)
   Start at  19:58:15
   Duration  170.14s (transform 56%, environment 18%, import 12%, tests 10%, setup 4%)

  Transform  |component| transforming modules took 465.11s · 53% 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

No server or Rust code changed, so Rust gates and an API adversarial round were not applicable. The optional local server rebuild was stopped under host contention; the route profile used the existing real local server. Build outputs were cleaned after verification.

Files and review evidence

Changed: apps/web/src/routes/+layout.svelte, apps/web/e2e/route-perf.mjs, apps/web/e2e/harness.mjs, apps/web/e2e/photos-perf.mjs, and new shared fixture helper apps/web/e2e/file-home.mjs.

Final trace and request/performance output are in target/perf/files-merged-trace.zip, target/perf/routes-merged-final.json, and target/perf/routes-merged-final.log. Production screenshots for light/dark at 390px, 820px, and 1440px are in target/perf/files-519-review/ and are uncommitted review artifacts.

Decisions where DESIGN.md was silent: use the prompt’s example 500ms target as a report-only budget; seed a realistic but bounded 2,000-file Home fixture; start interaction timing at the real input event and report endpoint completion separately so delayed input is visible; run one sample per viewport/tab under the four-hour job limit and report those as low-confidence measurements.

Head: 15e17aeaf (includes the required merge from origin/dev). No push, deploy, or merge was performed.

## Result The regression is in `9a4275387dddd93595a85b611594acdfc988915f` (2026-09-27, “Switch mode views with pointerdown preloading”). `preloadModeOnPointerDown` set `pendingMode` before the click. That changed the selected tab label and width during the press, moving the hit target before pointerup. The production probe saw pointerdown on Files and pointerup on Photos, with no click; navigation never started and “Opening Files…” remained visible. The fix removes this premature selection state while keeping deferred preloading. The supplied deploy list does not isolate a new regression after `99288dcfe`: both 99288dcfe and 5d6d22e60 reproduce it. On those builds, Files showed zero rows after 8.8s and 10.3s. The entries endpoint returned 200 in 59ms and 143ms, respectively, so the wait was in the client interaction, not that endpoint. ## After fix A production web build on the merged branch used a 2,000-file Home fixture and measured first-row paint once at each requested width. Under substantial shared-host load (load average rose from 24.49/29.57/28.61 to 32.71/31.91/29.89), Files painted its first row in 841ms at 390px, 999ms at 820px, and 1,058ms at 1440px (three-sample p95: 1,058ms). The `/api/v1/files/entries?path=&limit=500&sort=name` request returned 200 in 34ms; it ended 272ms after pointerdown. Files JS/CSS resources ended in 161–178ms. Tracing recorded 60ms and 104ms main-thread long tasks. The example 500ms budget is included and was missed in this loaded local run. This is a performance finding, not a correctness failure. The same one-run-per-tab profile measured switch p95s: Calendar 1,425ms, Photos 680ms, Mail 744ms, Money 560ms, Analytics 2,856ms. The request storm made 4,242 requests (p50 38ms, p95 198ms; all 200); observed server peak RSS was about 298.6MB. Direct files.entries route timing was p50/p95 69.7ms (one sample). ## Gates `bun install --frozen-lockfile`: ``` Checked 631 installs across 749 packages (no changes) [1.84s] ``` `bun run build`: ``` ✓ built in 33.15s Run npm run preview to preview your production build locally. > Using @sveltejs/adapter-static Wrote site to "build" ✔ done ``` `bun run check`: ``` $ node scripts/check-type-tokens.mjs && node scripts/check-motion-tokens.mjs && svelte-kit sync && svelte-check --tsconfig ./tsconfig.json Text sizes and UI shape values use shared role tokens. UI transitions and animation options use shared motion tokens or documented exceptions. ``` `bun run test`: ``` Test Files 140 passed (140) Tests 914 passed (914) Start at 19:58:15 Duration 170.14s (transform 56%, environment 18%, import 12%, tests 10%, setup 4%) Transform |component| transforming modules took 465.11s · 53% 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 ``` No server or Rust code changed, so Rust gates and an API adversarial round were not applicable. The optional local server rebuild was stopped under host contention; the route profile used the existing real local server. Build outputs were cleaned after verification. ## Files and review evidence Changed: `apps/web/src/routes/+layout.svelte`, `apps/web/e2e/route-perf.mjs`, `apps/web/e2e/harness.mjs`, `apps/web/e2e/photos-perf.mjs`, and new shared fixture helper `apps/web/e2e/file-home.mjs`. Final trace and request/performance output are in `target/perf/files-merged-trace.zip`, `target/perf/routes-merged-final.json`, and `target/perf/routes-merged-final.log`. Production screenshots for light/dark at 390px, 820px, and 1440px are in `target/perf/files-519-review/` and are uncommitted review artifacts. Decisions where DESIGN.md was silent: use the prompt’s example 500ms target as a report-only budget; seed a realistic but bounded 2,000-file Home fixture; start interaction timing at the real input event and report endpoint completion separately so delayed input is visible; run one sample per viewport/tab under the four-hour job limit and report those as low-confidence measurements. Head: `15e17aeaf` (includes the required merge from `origin/dev`). No push, deploy, or merge was performed.
Author
Owner

Fixed and deployed in 15e17aeaf (calternal.cloud healthy): pressing a tab no longer changes its width before the click, so Files opens. Remaining first-row time (0.8–1.1 s under build-host load) is tracked by #549 (tab switch on HDD).

Fixed and deployed in 15e17aeaf (calternal.cloud healthy): pressing a tab no longer changes its width before the click, so Files opens. Remaining first-row time (0.8–1.1 s under build-host load) is tracked by #549 (tab switch on HDD).
kayg closed this issue 2026-09-30 18:22:20 +00:00
Author
Owner

Correction: closed by mistake. The files-slow job posted its report here by error; this issue (Tokio worker stack overflow under adversarial API load) is still open. The Files fix belongs to #522.

Correction: closed by mistake. The files-slow job posted its report here by error; this issue (Tokio worker stack overflow under adversarial API load) is still open. The Files fix belongs to #522.
kayg reopened this issue 2026-09-30 18:22:45 +00:00
Author
Owner

A 2026-09-30 full local real-server API adversarial round on merged origin/dev (e96a8bf2a) kept the server process alive but reported eight no-response outcomes in a 16-request Appearance family write storm. Requests had a 10-second timeout; the final Appearance read was 200 but ten requested assignments were missing. The run also produced many explicitly SLOW file and DAV observations under concurrent build-host load.

This did not reproduce a stack overflow. I am attaching it as additional contention evidence for the adversarial-load work; the precise cause is not isolated.

A 2026-09-30 full local real-server API adversarial round on merged `origin/dev` (`e96a8bf2a`) kept the server process alive but reported eight no-response outcomes in a 16-request Appearance family write storm. Requests had a 10-second timeout; the final Appearance read was 200 but ten requested assignments were missing. The run also produced many explicitly `SLOW` file and DAV observations under concurrent build-host load. This did not reproduce a stack overflow. I am attaching it as additional contention evidence for the adversarial-load work; the precise cause is not isolated.
Author
Owner

Linked: crash-525 (job/crash-525) found this abort. A Tokio worker stack overflow during a checked filesystem write in the cross-source Tag rename. Its fix raises the worker stack to 4 MiB and adds a 100-rename storm regression, which passes. job/parity-484 also carries a "Tag rename stack overflow" fix. Both merge in round 4.
Still open here (root cause): a bigger stack is a mitigation. Find the deep frame (recursive rename plan, or a large async state machine held on the stack) with the preserved core (calternal-wt/crash-525-evidence/core.1636042, test data only). Fix it by boxing/iterating, and make the regression storm pass at Tokio's default 2 MiB stack. Then keep 4 MiB only as headroom, with a comment that explains why.

Linked: crash-525 (job/crash-525) found this abort. A Tokio worker stack overflow during a checked filesystem write in the cross-source Tag rename. Its fix raises the worker stack to 4 MiB and adds a 100-rename storm regression, which passes. job/parity-484 also carries a "Tag rename stack overflow" fix. Both merge in round 4. **Still open here (root cause):** a bigger stack is a mitigation. Find the deep frame (recursive rename plan, or a large async state machine held on the stack) with the preserved core (`calternal-wt/crash-525-evidence/core.1636042`, test data only). Fix it by boxing/iterating, and make the regression storm pass at Tokio's default 2 MiB stack. Then keep 4 MiB only as headroom, with a comment that explains why.
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#519
No description provided.