Server aborts during adversarial tag rename API probe #525

Closed
opened 2026-09-30 14:39:55 +00:00 by kayg · 9 comments
Owner

Evidence

The one-time API-only adversarial run for MCP performance job #492 reached the real local server. Earlier API probes passed, including the tag rename preview. The next probe, POST /api/v1/tags/rename with old_tag=travel and new_tag=journey, received no response; subsequent requests received connection refused. The runner reported the server process as Aborted and exited with status 1.

The relevant probe is tag rename across sources in tests/adversarial/attack.py around line 2608. The probe expects the rename operation to return 200 and update Markdown, XMP, and folder JSON sources.

Host load was unusually high during the run (load average reached approximately 42). This is context, not an explanation for an abort. The adversarial runner removed its temporary logs during cleanup; no core file or coredumpctl was available, so the abort stack is unknown. The observed timing points to the rename probe, but does not prove that request caused the abort.

Follow-up

Reproduce this on a quiet host, preserve the server log/core, identify and fix the abort, and add a regression test. Do not change the existing adversarial expectations unless the rename contract changes.

## Evidence The one-time API-only adversarial run for MCP performance job #492 reached the real local server. Earlier API probes passed, including the tag rename preview. The next probe, `POST /api/v1/tags/rename` with `old_tag=travel` and `new_tag=journey`, received no response; subsequent requests received connection refused. The runner reported the server process as `Aborted` and exited with status 1. The relevant probe is `tag rename across sources` in `tests/adversarial/attack.py` around line 2608. The probe expects the rename operation to return 200 and update Markdown, XMP, and folder JSON sources. Host load was unusually high during the run (load average reached approximately 42). This is context, not an explanation for an abort. The adversarial runner removed its temporary logs during cleanup; no core file or `coredumpctl` was available, so the abort stack is unknown. The observed timing points to the rename probe, but does not prove that request caused the abort. ## Follow-up Reproduce this on a quiet host, preserve the server log/core, identify and fix the abort, and add a regression test. Do not change the existing adversarial expectations unless the rename contract changes.
Author
Owner

Starting on job/crash-525 from base f2d03f37af (origin/dev). I am tracing the real-server tag rename abort and will preserve the reproduction output.

Starting on job/crash-525 from base f2d03f37af584f4259c0fc9119fd524b91332a50 (origin/dev). I am tracing the real-server tag rename abort and will preserve the reproduction output.
Author
Owner

Reproduced the failure on 2026-09-30 against a real local server with RUST_BACKTRACE=1, core dumps enabled, and the API-only adversarial run. The exact POST /api/v1/tags/rename probe returned no response; the server log then showed:

thread 'tokio-rt-worker' (1636054) has overflowed its stack
fatal runtime error: stack overflow, aborting

The runner reported calternal-server as Aborted (core dumped). The retained core is target/tmp/adversarial.ML6hkM/core.1636042 (705 MiB). The host load average at the time was 37.60, 37.48, 40.48. I am examining the core to identify the stack frame that exhausts the Tokio worker stack.

Reproduced the failure on 2026-09-30 against a real local server with `RUST_BACKTRACE=1`, core dumps enabled, and the API-only adversarial run. The exact `POST /api/v1/tags/rename` probe returned no response; the server log then showed: ``` thread 'tokio-rt-worker' (1636054) has overflowed its stack fatal runtime error: stack overflow, aborting ``` The runner reported `calternal-server` as `Aborted (core dumped)`. The retained core is `target/tmp/adversarial.ML6hkM/core.1636042` (705 MiB). The host load average at the time was 37.60, 37.48, 40.48. I am examining the core to identify the stack frame that exhausts the Tokio worker stack.
Author
Owner

The retained core confirms a stack overflow, not an OOM or deadlock. GDB's crash-thread backtrace reaches blake3::Hasher::new in calternal-fs/src/write.rs:195 while the request is in write_folder_metadata → rewrite_tag_in_folder_metadata → rename::apply → rename::rename → rename_tag. The backtrace then shows the Axum/Tower request middleware chain. #[tokio::main] did not set a worker stack size, while the existing cross-source Tags test gives its current-thread runtime a 4 MiB stack. I will set the server worker stack to 4 MiB and rerun the 100-rename real-server probe.

The retained core confirms a stack overflow, not an OOM or deadlock. GDB's crash-thread backtrace reaches `blake3::Hasher::new` in `calternal-fs/src/write.rs:195` while the request is in `write_folder_metadata` → `rewrite_tag_in_folder_metadata` → `rename::apply` → `rename::rename` → `rename_tag`. The backtrace then shows the Axum/Tower request middleware chain. `#[tokio::main]` did not set a worker stack size, while the existing cross-source Tags test gives its current-thread runtime a 4 MiB stack. I will set the server worker stack to 4 MiB and rerun the 100-rename real-server probe.
Author
Owner

During the 2026-09-30 API-only adversarial run, the #525 Tag rename regression completed 100/100 rewrites and the server stayed alive. Later, outside the Tags probe, POST /api/v1/notes/tasks requests 20–23 returned client timeouts (the Task storm uses a 60-second request timeout). A later DAV Reminder create also timed out, and a 1,000-entry DAV listing returned 207 in 39.9 seconds. Server logs show SQLx pool acquisition waits of about 7–8 seconds; host load during the Tag profile was about 38–42. This is evidence of severe shared-host/database contention in unrelated Task and DAV routes, not an observed Tag rename failure. Recording it for separate triage as required by the adversarial rules.

During the 2026-09-30 API-only adversarial run, the #525 Tag rename regression completed 100/100 rewrites and the server stayed alive. Later, outside the Tags probe, `POST /api/v1/notes/tasks` requests 20–23 returned client timeouts (the Task storm uses a 60-second request timeout). A later DAV Reminder create also timed out, and a 1,000-entry DAV listing returned 207 in 39.9 seconds. Server logs show SQLx pool acquisition waits of about 7–8 seconds; host load during the Tag profile was about 38–42. This is evidence of severe shared-host/database contention in unrelated Task and DAV routes, not an observed Tag rename failure. Recording it for separate triage as required by the adversarial rules.
Author
Owner

Additional evidence from the same API campaign: the first /api/v1/tags/journey read after the successful cross-source rename listed file and photo, but omitted the tagged Note. The Markdown source contained #journey/europe. After the 100-rename loop, a direct read of that same Tag page returned file, note and photo, and the Index had the Note row. This transient Tag index/API inconsistency was not reproduced after the loop and remains unexplained. The campaign also reported the existing DAV Journal accepts a well-formed alarm expectation as expected 201, got 204; I left the expectation unchanged per the owner rule.

I stopped the broader API-only campaign at its 30-minute timebox after the #525 loop completed. Connection-refused results emitted during teardown are cancellation artifacts and are not findings.

Additional evidence from the same API campaign: the first `/api/v1/tags/journey` read after the successful cross-source rename listed `file` and `photo`, but omitted the tagged Note. The Markdown source contained `#journey/europe`. After the 100-rename loop, a direct read of that same Tag page returned `file`, `note` and `photo`, and the Index had the Note row. This transient Tag index/API inconsistency was not reproduced after the loop and remains unexplained. The campaign also reported the existing `DAV Journal accepts a well-formed alarm` expectation as `expected 201, got 204`; I left the expectation unchanged per the owner rule. I stopped the broader API-only campaign at its 30-minute timebox after the #525 loop completed. Connection-refused results emitted during teardown are cancellation artifacts and are not findings.
Author
Owner

The post-merge API-only run also found two unrelated Appearance upload failures. The 25 MiB .calternal/backgrounds Tus create returned 201 (probe expects 413), and the non-image background Tus install returned 204 (probe expects 400). I left both existing assertions unchanged and filed the evidence in #553: Appearance uploads accept oversized and non-image Tus payloads.

The post-merge API-only run also found two unrelated Appearance upload failures. The 25 MiB `.calternal/backgrounds` Tus create returned 201 (probe expects 413), and the non-image background Tus install returned 204 (probe expects 400). I left both existing assertions unchanged and filed the evidence in #553: Appearance uploads accept oversized and non-image Tus payloads.
Author
Owner

Result

Reproduced the server abort on a real local server with RUST_BACKTRACE=1 and a retained core. This was a Tokio worker stack overflow, not OOM or a deadlock. GDB traced the request through rename_tag → rename::rename → rename::apply → rewrite_tag_in_folder_metadata → write_folder_metadata to blake3::Hasher::new in calternal-fs/src/write.rs:195.

Configured the server's Tokio worker stack to 4 MiB. Added the #525 real-server regression storm: 100 alternating Markdown/XMP/folder-JSON Tag renames, each beside 16 concurrent Tag Index reads. Against the merged server, all 100 renames completed; all requests returned 200, each rename updated at least three objects, and there were no Tag failures or stack-abort markers. The broader API-only campaign was deliberately stopped after this target completed (shell exit 143 from SIGTERM); later probes were not run.

The original core, reproduction/server logs, and gate logs are retained outside the worktree at /home/kayg/Developer/calternal-wt/crash-525-evidence/.

Changes

  • crates/calternal-server/src/main.rs: set a 4 MiB Tokio worker stack for the server runtime.
  • tests/adversarial/attack.py, tests/adversarial/run.sh: add and profile the cross-source rename storm; expose the server PID to the resource sampler.
  • bench/tag-rename-525.sh, docs/perf/README.md, docs/perf/baseline.json, docs/perf/runs/2026-09-30T170130Z-ed2c0d91-tag-rename.json: record and compare the hot-path profile.

Commits: ed2c0d913b87417b13b038f51ac2b1826ec1d6db, c9a7f90d6c1728500613e40f8c07a7db1202afea, and merge of origin/dev at f36ee68520622f8a3c4b34284f583335b988e546.

Gates

cargo fmt --check: exit 0; stdout and stderr were empty.

cargo clippy -p calternal-tags --all-targets -- -D warnings:

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

cargo test -p calternal-tags:

    Finished `test` profile [unoptimized + debuginfo] target(s) in 9m 47s
     Running unittests src/lib.rs (/mnt/hdd/targets/jobs/crash-525/debug/deps/calternal_tags-ea0194c857e496e9)
running 11 tests
test result: ok. 11 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 3.56s
   Doc-tests calternal_tags
running 0 tests
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 39m 22s

cargo test -p calternal-server:

    Finished `test` profile [unoptimized + debuginfo] target(s) in 9m 30s
     Running unittests src/main.rs (/mnt/hdd/targets/jobs/crash-525/debug/deps/calternal_server-fcbe95c5650c499e)
running 96 tests
test result: ok. 93 passed; 0 failed; 3 ignored; 0 measured; 0 filtered out; finished in 29.93s

python3 -m py_compile tests/adversarial/attack.py and bash -n tests/adversarial/run.sh bench/tag-rename-525.sh passed. Benchmark comparison output:

Compared /home/kayg/Developer/calternal-wt/crash-525/docs/perf/baseline.json with docs/perf/runs/2026-09-30T170130Z-ed2c0d91-tag-rename.json
No regressions over the published budgets.

cargo clean output:

     Removed 15263 files, 8.4GiB total

Performance

The local profile completed 100 renames with 16 concurrent Tag reads each. It used a 477-file, 54-directory Home with 12 Markdown Notes. Results: p50 2529.87 ms, p95 6741.14 ms, mean CPU 12.37%, average RSS 667,215,650 bytes, peak RSS 667,656,192 bytes, and 328.12 s elapsed. Host load average was 42.23/40.61/37.79 before and 39.84/38.80/37.89 after. This was a busy local host profile; the largest Home was not measured.

Known findings

  • The earlier API campaign saw one immediate Tag page missing the Note kind after rename; the complete kind set appeared after the rename storm. The post-merge run did not reproduce this. The existing expectation remains unchanged; evidence is in the comments on this issue.
  • The adversarial run also reported the existing DAV expectation mismatch (expected 201, received 204). The expectation was not changed.
  • Merged origin/dev Appearance probes accepted a 25 MiB background Tus create (201; expected 413) and a non-image background Tus install (204; expected 400). I left both assertions unchanged and filed these findings as #553.
  • The measured Home is smaller than the large Home workload, and the profile ran locally under high host load.

Decision

The design docs do not set a Tokio worker stack size. I chose 4 MiB because it clears the measured failing call chain and matches the stack size already used by the cross-source Tags test.

Head SHA: f36ee68520622f8a3c4b34284f583335b988e546.

## Result Reproduced the server abort on a real local server with `RUST_BACKTRACE=1` and a retained core. This was a Tokio worker stack overflow, not OOM or a deadlock. GDB traced the request through `rename_tag` → `rename::rename` → `rename::apply` → `rewrite_tag_in_folder_metadata` → `write_folder_metadata` to `blake3::Hasher::new` in `calternal-fs/src/write.rs:195`. Configured the server's Tokio worker stack to 4 MiB. Added the #525 real-server regression storm: 100 alternating Markdown/XMP/folder-JSON Tag renames, each beside 16 concurrent Tag Index reads. Against the merged server, all 100 renames completed; all requests returned 200, each rename updated at least three objects, and there were no Tag failures or stack-abort markers. The broader API-only campaign was deliberately stopped after this target completed (shell exit 143 from SIGTERM); later probes were not run. The original core, reproduction/server logs, and gate logs are retained outside the worktree at `/home/kayg/Developer/calternal-wt/crash-525-evidence/`. ## Changes - `crates/calternal-server/src/main.rs`: set a 4 MiB Tokio worker stack for the server runtime. - `tests/adversarial/attack.py`, `tests/adversarial/run.sh`: add and profile the cross-source rename storm; expose the server PID to the resource sampler. - `bench/tag-rename-525.sh`, `docs/perf/README.md`, `docs/perf/baseline.json`, `docs/perf/runs/2026-09-30T170130Z-ed2c0d91-tag-rename.json`: record and compare the hot-path profile. Commits: `ed2c0d913b87417b13b038f51ac2b1826ec1d6db`, `c9a7f90d6c1728500613e40f8c07a7db1202afea`, and merge of `origin/dev` at `f36ee68520622f8a3c4b34284f583335b988e546`. ## Gates `cargo fmt --check`: exit 0; stdout and stderr were empty. `cargo clippy -p calternal-tags --all-targets -- -D warnings`: ```text Finished `dev` profile [unoptimized + debuginfo] target(s) in 17m 39s ``` `cargo test -p calternal-tags`: ```text Finished `test` profile [unoptimized + debuginfo] target(s) in 9m 47s Running unittests src/lib.rs (/mnt/hdd/targets/jobs/crash-525/debug/deps/calternal_tags-ea0194c857e496e9) running 11 tests test result: ok. 11 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 3.56s Doc-tests calternal_tags running 0 tests 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`: ```text Finished `dev` profile [unoptimized + debuginfo] target(s) in 39m 22s ``` `cargo test -p calternal-server`: ```text Finished `test` profile [unoptimized + debuginfo] target(s) in 9m 30s Running unittests src/main.rs (/mnt/hdd/targets/jobs/crash-525/debug/deps/calternal_server-fcbe95c5650c499e) running 96 tests test result: ok. 93 passed; 0 failed; 3 ignored; 0 measured; 0 filtered out; finished in 29.93s ``` `python3 -m py_compile tests/adversarial/attack.py` and `bash -n tests/adversarial/run.sh bench/tag-rename-525.sh` passed. Benchmark comparison output: ```text Compared /home/kayg/Developer/calternal-wt/crash-525/docs/perf/baseline.json with docs/perf/runs/2026-09-30T170130Z-ed2c0d91-tag-rename.json No regressions over the published budgets. ``` `cargo clean` output: ```text Removed 15263 files, 8.4GiB total ``` ## Performance The local profile completed 100 renames with 16 concurrent Tag reads each. It used a 477-file, 54-directory Home with 12 Markdown Notes. Results: p50 2529.87 ms, p95 6741.14 ms, mean CPU 12.37%, average RSS 667,215,650 bytes, peak RSS 667,656,192 bytes, and 328.12 s elapsed. Host load average was 42.23/40.61/37.79 before and 39.84/38.80/37.89 after. This was a busy local host profile; the largest Home was not measured. ## Known findings - The earlier API campaign saw one immediate Tag page missing the Note kind after rename; the complete kind set appeared after the rename storm. The post-merge run did not reproduce this. The existing expectation remains unchanged; evidence is in the comments on this issue. - The adversarial run also reported the existing DAV expectation mismatch (expected 201, received 204). The expectation was not changed. - Merged `origin/dev` Appearance probes accepted a 25 MiB background Tus create (201; expected 413) and a non-image background Tus install (204; expected 400). I left both assertions unchanged and filed these findings as #553. - The measured Home is smaller than the large Home workload, and the profile ran locally under high host load. ## Decision The design docs do not set a Tokio worker stack size. I chose 4 MiB because it clears the measured failing call chain and matches the stack size already used by the cross-source Tags test. Head SHA: `f36ee68520622f8a3c4b34284f583335b988e546`.
Author
Owner

Additional reproduction during the one API-only adversarial round for #421: after the Files Note rename/move cases, tag rename across sources received no response (Remote end closed connection without response). Subsequent tag, recovery and Task probes received connection refused. The runner then reported its local server as Aborted; the command exited 120. This matches the failure pattern tracked here. The round did not retain its temporary server log or core, so it does not identify the abort cause or prove which request triggered it. No second round was run.

Additional reproduction during the one API-only adversarial round for #421: after the Files Note rename/move cases, `tag rename across sources` received no response (`Remote end closed connection without response`). Subsequent tag, recovery and Task probes received connection refused. The runner then reported its local server as `Aborted`; the command exited 120. This matches the failure pattern tracked here. The round did not retain its temporary server log or core, so it does not identify the abort cause or prove which request triggered it. No second round was run.
Author
Owner

Shipped in merge round 4, deployed to calternal.cloud in 1af8ead26 (healthy).

Shipped in merge round 4, deployed to calternal.cloud in 1af8ead26 (healthy).
kayg closed this issue 2026-10-01 09:17:56 +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#525
No description provided.