morluto/rea

Fork 0

mirror of https://github.com/morluto/rea.git synced 2026-11-05 06:45:22 +00:00

[GH-ISSUE #3543] [Bug] macOS demangle validation test exceeds 20s after emitting VALIDATION_ERROR #1319

New issue

Open

opened 2026-10-16 21:04:11 +00:00 by bsakaguchi · 4 comments

bsakaguchi commented

2026-10-16 21:04:11 +00:00

Owner

Originally created by @N0zoM1z0 on GitHub (Oct 14, 2026).
Original GitHub issue: https://github.com/morluto/rea/issues/3543

Originally assigned to: @N0zoM1z0 on GitHub.

Before submitting

I searched the open and closed issues for a related report.
I removed credentials, private paths and sensitive target data.

Area

CLI — macOS test subprocess completion

Observed behavior

Main CI run 38587680181, source eb44921c4c3682e33c78508285629926e8ef241e, failed in Real Apple artifact CLI/MCP E2E, job 115934862587.

tests/boundary/cli/nativeDemangleCli.test.ts / rejects a symbol spanning lines as input exceeded its owned 20,000 ms subprocess deadline. The child was terminated with SIGTERM, exitCode=null, stderr empty. Its captured stdout already contains the expected structured rejection:

{"code":"VALIDATION_ERROR","fieldErrors":[{"path":"symbols.1","missing":false}]}

The runner reported 18 files: 224 passed / 4 skipped / 1 failed. Final workflow: 33 successful jobs / Apple failed / required gate failed. The gate correctly rejected the failed lane.

Reproduction and comparison

Actual hosted failure: run/job above, Node 24.18.0, macos-15. The workflow runs npm run test:focused -- ... tests/boundary/cli/nativeDemangleCli.test.ts ... as part of its existing native/process regression family.
Same Git tree PR run 38585311071, Apple job 115926826182, passed. Thus this evidence does not establish a deterministic source regression. Actual compiled archive byte equality was not measured.
On Linux x64, the identical invalid-input test passed: 1 passed / 1 explicit Darwin-only skip, 1.91 s test duration on eb44921c4. After synchronizing main 1438422df, it passed again as part of the affected six-file run (248 passed / 1 skipped).
The test, fixture registry, CLI command and CI job were unchanged by the later managed-only update 1438422df; the observed hosted failure remains tied to its actual executed revision.
No hosted retry was dispatched and no timeout was raised.

Minimal CLI input is demangle-swift <absent-target> '$s4main3FooV' <symbol-containing-LF> --json; preserve the exact test's malformed-symbol argument and missing target. A fresh macOS reproduction is NOT_ENOUGH_INFO: the audit host is Linux, and the hosted logs do not record spawn-to-output and output-to-exit timings.

Expected behavior

Return the typed input rejection and exit with code 1, no signal, within the existing bound. Invalid multiline symbols should not admit the absent target or run a demangler.

Impact and scope

One observed macOS lane failure blocks required CI despite the same-tree PR passing. Failure frequency and root cause are unknown; this report does not label it a proven infrastructure flake or production hang. The Linux portable run remains complete and successful: 1,284 unique files, 14,650 passed, 125 skipped.

REA version

Hosted failure: eb44921c4c3682e33c78508285629926e8ef241e. Latest inspected main: 1438422dfedf1de29368b595e09a04f1fc10750d.

Runtime and platform

Hosted: macOS 15 runner, Node 24.18.0 / npm 11.16.0. Local control: Linux x64 with the same pinned Node/npm.

Interface / earliest failure stage

CLI; cleanup/cancellation/lifecycle completion is where the test observes the failure. Earliest underlying cause: Unknown.

Analysis and proposed next check

The final buffered output has no timestamp. It cannot establish whether validation happened early followed by blocked exit, or only near the deadline after slow startup/scheduling. Instrument those two intervals and owned handle/child state on macOS, comparing cold and warm runs. Fix the demonstrated owner/lifecycle cause once identified; retain malformed-input, cancellation and cleanup assertions. Do not hide the observation with blanket retries or an arbitrary timeout increase.

Earlier closed #1137 concerns cold ownership-helper compilation for source-map execution. The current invalid-input case has not been shown to share that cause. No causal link to the two-file cache-input change in #3522 has been established.

Originally created by @N0zoM1z0 on GitHub (Oct 14, 2026). Original GitHub issue: https://github.com/morluto/rea/issues/3543 Originally assigned to: @N0zoM1z0 on GitHub. ### Before submitting - [x] I searched the open and closed issues for a related report. - [x] I removed credentials, private paths and sensitive target data. ### Area CLI — macOS test subprocess completion ### Observed behavior Main CI [run 38587680181](https://github.com/morluto/rea/actions/runs/38587680181), source `eb44921c4c3682e33c78508285629926e8ef241e`, failed in [Real Apple artifact CLI/MCP E2E, job 115934862587](https://github.com/morluto/rea/actions/runs/38587680181/job/115934862587). `tests/boundary/cli/nativeDemangleCli.test.ts` / `rejects a symbol spanning lines as input` exceeded its owned **20,000 ms** subprocess deadline. The child was terminated with `SIGTERM`, exitCode=null, stderr empty. Its captured stdout already contains the expected structured rejection: ```json {"code":"VALIDATION_ERROR","fieldErrors":[{"path":"symbols.1","missing":false}]} ``` The runner reported 18 files: **224 passed / 4 skipped / 1 failed**. Final workflow: **33 successful jobs / Apple failed / required gate failed**. The gate correctly rejected the failed lane. ### Reproduction and comparison - Actual hosted failure: run/job above, Node 24.18.0, `macos-15`. The workflow runs `npm run test:focused -- ... tests/boundary/cli/nativeDemangleCli.test.ts ...` as part of its existing native/process regression family. - Same **Git tree** PR run [38585311071](https://github.com/morluto/rea/actions/runs/38585311071), [Apple job 115926826182](https://github.com/morluto/rea/actions/runs/38585311071/job/115926826182), passed. Thus this evidence does not establish a deterministic source regression. Actual compiled archive byte equality was not measured. - On Linux x64, the identical invalid-input test passed: 1 passed / 1 explicit Darwin-only skip, 1.91 s test duration on `eb44921c4`. After synchronizing main `1438422df`, it passed again as part of the affected six-file run (248 passed / 1 skipped). - The test, fixture registry, CLI command and CI job were unchanged by the later managed-only update `1438422df`; the observed hosted failure remains tied to its actual executed revision. - No hosted retry was dispatched and no timeout was raised. Minimal CLI input is `demangle-swift <absent-target> '$s4main3FooV' <symbol-containing-LF> --json`; preserve the exact test's malformed-symbol argument and missing target. A fresh macOS reproduction is **NOT_ENOUGH_INFO**: the audit host is Linux, and the hosted logs do not record spawn-to-output and output-to-exit timings. ### Expected behavior Return the typed input rejection and exit with code 1, no signal, within the existing bound. Invalid multiline symbols should not admit the absent target or run a demangler. ### Impact and scope One observed macOS lane failure blocks required CI despite the same-tree PR passing. Failure frequency and root cause are unknown; this report does not label it a proven infrastructure flake or production hang. The Linux portable run remains complete and successful: 1,284 unique files, 14,650 passed, 125 skipped. ### REA version Hosted failure: `eb44921c4c3682e33c78508285629926e8ef241e`. Latest inspected main: `1438422dfedf1de29368b595e09a04f1fc10750d`. ### Runtime and platform Hosted: macOS 15 runner, Node 24.18.0 / npm 11.16.0. Local control: Linux x64 with the same pinned Node/npm. ### Interface / earliest failure stage CLI; cleanup/cancellation/lifecycle completion is where the test observes the failure. Earliest underlying cause: **Unknown**. ### Analysis and proposed next check The final buffered output has no timestamp. It cannot establish whether validation happened early followed by blocked exit, or only near the deadline after slow startup/scheduling. Instrument those two intervals and owned handle/child state on macOS, comparing cold and warm runs. Fix the demonstrated owner/lifecycle cause once identified; retain malformed-input, cancellation and cleanup assertions. Do not hide the observation with blanket retries or an arbitrary timeout increase. Earlier closed #1137 concerns cold ownership-helper compilation for source-map execution. The current invalid-input case has not been shown to share that cause. No causal link to the two-file cache-input change in #3522 has been established.

bsakaguchi commented

2026-10-16 21:04:12 +00:00

Author

Owner

@N0zoM1z0 commented on GitHub (Oct 14, 2026):

Investigation update: #3542 and #3473 are now merged separately. A temporary, manual-only diagnostic branch based on current main 1579b6865e8ee87873036a39af3e257cc70d6f21 is running one real macos-15 job: 38601270148, head 25d62a0958c28667dc8b1203c25202befd5aebd9.

It retains the original six artifact verifiers, all 18 boundary test files, and the unchanged 20-second process deadline. Parent-side timestamps record spawn / first stdout / first stderr / close without persisting arguments, output, or the environment. A still-live CLI receives a diagnostic-report signal after 15 seconds with Node's environment and network fields excluded; a pinned-Node sentinel control verified environment exclusion locally. The two-test demangle family also runs independently to test a specific cross-family-load hypothesis; its result cannot erase any original family failure.

Local instrumented Linux smoke passed the invalid-input case (exit 1, first stdout ~1.35s, close ~1.43s); the positive Darwin case is explicitly skipped there. No runtime fix, retry-based cure, timeout change, actual macOS success, or speedup is claimed before the diagnostic results. This branch replaces CI only for investigation and will not be proposed for integration.

@N0zoM1z0 commented on GitHub (Oct 14, 2026): Investigation update: #3542 and #3473 are now merged separately. A temporary, manual-only diagnostic branch based on current main `1579b6865e8ee87873036a39af3e257cc70d6f21` is running one real `macos-15` job: [38601270148](https://github.com/morluto/rea/actions/runs/38601270148), head `25d62a0958c28667dc8b1203c25202befd5aebd9`. It retains the original six artifact verifiers, all 18 boundary test files, and the unchanged 20-second process deadline. Parent-side timestamps record spawn / first stdout / first stderr / close without persisting arguments, output, or the environment. A still-live CLI receives a diagnostic-report signal after 15 seconds with Node's environment and network fields excluded; a pinned-Node sentinel control verified environment exclusion locally. The two-test demangle family also runs independently to test a specific cross-family-load hypothesis; its result cannot erase any original family failure. Local instrumented Linux smoke passed the invalid-input case (exit 1, first stdout ~1.35s, close ~1.43s); the positive Darwin case is explicitly skipped there. No runtime fix, retry-based cure, timeout change, actual macOS success, or speedup is claimed before the diagnostic results. This branch replaces CI only for investigation and will not be proposed for integration.

bsakaguchi commented

2026-10-16 21:04:13 +00:00

Author

Owner

@N0zoM1z0 commented on GitHub (Oct 14, 2026):

Bounded diagnostic result: run 38601270148 succeeded on real macos-15 at diagnostic head 25d62a0958c28667dc8b1203c25202befd5aebd9 (production baseline main 1579b6865e8ee87873036a39af3e257cc70d6f21). The original complete family passed 18 files / 225 tests, with 4 explicit skips, in 188.63s; the isolated demangle family passed both tests, including the Darwin positive path.

Invalid-symbol subprocess	First stdout	Close	Result
Full original family	674ms	684ms	exit 1, no signal, no timeout
Isolated family	712ms	764ms	exit 1, no signal, no timeout

The full and isolated positive demangle children also exited normally (~3.42s and ~3.33s). All 44 instrumented run calls closed, no observed run deadline fired, and no 15-second diagnostic signal was needed. This describes instrumented registry invocations, not proof that no other child process ever existed. The raw timing artifact is macos-deadline-diagnostics (ID 11915145325).

This did not reproduce the original failure or recover its missing first-output timestamp, so it establishes neither a cure nor whether that historical event was startup starvation, delayed exit, or another transient. The observed successful calls alone do not prove the cross-family-load hypothesis. No production fix, timeout increase, blanket retry or assertion change is proposed; the issue remains open as an unconfirmed root cause. The diagnostic workflow replacement will not be merged. Stop further repetitions until another failure yields discriminating evidence. Hosted process-family CPU/RSS and agent token costs were not measured; no suite-wide speedup is claimed.

@N0zoM1z0 commented on GitHub (Oct 14, 2026): Bounded diagnostic result: [run 38601270148](https://github.com/morluto/rea/actions/runs/38601270148) succeeded on real `macos-15` at diagnostic head `25d62a0958c28667dc8b1203c25202befd5aebd9` (production baseline main `1579b6865e8ee87873036a39af3e257cc70d6f21`). The original complete family passed **18 files / 225 tests**, with **4 explicit skips**, in 188.63s; the isolated demangle family passed both tests, including the Darwin positive path. | Invalid-symbol subprocess | First stdout | Close | Result | | --- | ---: | ---: | --- | | Full original family | 674ms | 684ms | exit 1, no signal, no timeout | | Isolated family | 712ms | 764ms | exit 1, no signal, no timeout | The full and isolated positive demangle children also exited normally (~3.42s and ~3.33s). All 44 instrumented `run` calls closed, no observed `run` deadline fired, and no 15-second diagnostic signal was needed. This describes instrumented registry invocations, **not** proof that no other child process ever existed. The raw timing artifact is `macos-deadline-diagnostics` (ID 11915145325). This did not reproduce the original failure or recover its missing first-output timestamp, so it establishes neither a cure nor whether that historical event was startup starvation, delayed exit, or another transient. The observed successful calls alone do not prove the cross-family-load hypothesis. No production fix, timeout increase, blanket retry or assertion change is proposed; the issue remains open as an unconfirmed root cause. The diagnostic workflow replacement will not be merged. Stop further repetitions until another failure yields discriminating evidence. Hosted process-family CPU/RSS and agent token costs were not measured; no suite-wide speedup is claimed.

bsakaguchi commented

2026-10-16 21:04:13 +00:00

Author

Owner

@N0zoM1z0 commented on GitHub (Oct 15, 2026):

Additional observed scope: the same invalid-input subprocess deadline now fails on Linux in scheduled full qualification run 38714082679, source 47b4628bac7300e5486dd6018663b1cc5dfbf01c, shard 5/6. The report retains complete VALIDATION_ERROR JSON for symbols.1, exitCode=null and SIGTERM after 20,038 ms. This run has 15,368 passed / 136 skipped / 1 failed; the merge and required gates correctly reject it.

Current cb18d4c9 differs only in documentation. Local Node 24.18.0/npm 11.16.0 Linux control using npm run test:ci:shard:run -- --project cli-boundary tests/boundary/cli/nativeDemangleCli.test.ts --shard=1/1 passed its one enabled test (one Darwin-only skip). Total instrumented command: 20.44 s including collection/reporting, 26.03/5.71 s wait-accounted user/system CPU, 1.0 GiB sampled descendant RSS. This is a focused coverage run with deliberately zero shard thresholds, not proof of full qualification thresholds or a fix.

No timeout increase or hosted retry was introduced. The buffered CI log still cannot separate startup, output, and exit latency; the underlying cause remains unknown. Draft #4038 addresses a separate truncated-pipe diagnostic defect and should not be treated as proof of this timeout's cause.

@N0zoM1z0 commented on GitHub (Oct 15, 2026): Additional observed scope: the same invalid-input subprocess deadline now fails on Linux in scheduled full qualification [run 38714082679](https://github.com/morluto/rea/actions/runs/38714082679), source `47b4628bac7300e5486dd6018663b1cc5dfbf01c`, [shard 5/6](https://github.com/morluto/rea/actions/runs/38714082679/job/116352777369). The report retains complete `VALIDATION_ERROR` JSON for `symbols.1`, exitCode=null and SIGTERM after 20,038 ms. This run has 15,368 passed / 136 skipped / 1 failed; the merge and required gates correctly reject it. Current `cb18d4c9` differs only in documentation. Local Node 24.18.0/npm 11.16.0 Linux control using `npm run test:ci:shard:run -- --project cli-boundary tests/boundary/cli/nativeDemangleCli.test.ts --shard=1/1` passed its one enabled test (one Darwin-only skip). Total instrumented command: 20.44 s including collection/reporting, 26.03/5.71 s wait-accounted user/system CPU, 1.0 GiB sampled descendant RSS. This is a focused coverage run with deliberately zero shard thresholds, not proof of full qualification thresholds or a fix. No timeout increase or hosted retry was introduced. The buffered CI log still cannot separate startup, output, and exit latency; the underlying cause remains unknown. Draft #4038 addresses a separate truncated-pipe diagnostic defect and should not be treated as proof of this timeout's cause.

bsakaguchi commented

2026-10-16 21:04:14 +00:00

Author

Owner

@dollarsmoney commented on GitHub (Oct 15, 2026):

macOS reproduction data, since the earlier note marked a fresh macOS reproduction as NOT_ENOUGH_INFO. It was not reproduced on this host.

Host: macOS 15 (Darwin 24.3.0, arm64), Node 26.9.0 (not the pinned 24.18.0), main c7697595d, npm ci + npm run build:cached.

npm run test:focused -- tests/boundary/cli/nativeDemangleCli.test.ts ×20: 20/20 passed. "rejects a symbol spanning lines as input" took 358–3,672 ms per run against the unchanged 20,000 ms deadline.

Direct spawn of the exact invocation (demangle-swift <absent> '$s4main3FooV' $'$s4main\n3FooV' --json, env REA_LOG_LEVEL=silent, REA_ANALYSIS_PROVIDER=auto), timing spawn → first stdout → close:

condition	runs	spawn→close median / max	first stdout → close
warm compile cache	30	450 / 658 ms	~5 ms
fresh `NODE_COMPILE_CACHE` per run	10	567 / 602 ms	~80 ms
fresh cache + 8 busy-loop CPU burners	15	831 / 1,088 ms	~100–140 ms

Every run exited with code 1 and no signal, with the expected VALIDATION_ERROR on stdout.

A --require probe with an unref'd 3 s timer, which dumps process._getActiveHandles() / getActiveResourcesInfo() if the process is still alive at 3 s, never fired in any of the 55 direct runs. So no handle or child was observed keeping the CLI alive after the rejection on this host.

On macOS arm64 the output-to-exit interval stays in the low milliseconds even when cold and under CPU contention. The hosted ~20 s stall is not explained by ordinary cold start or load here, so whatever keeps the process alive after the full stdout write didn't occur in 75 local attempts. I can rerun the timing harness on a specific revision or condition if that helps narrow it down.

@dollarsmoney commented on GitHub (Oct 15, 2026): macOS reproduction data, since the earlier note marked a fresh macOS reproduction as NOT_ENOUGH_INFO. It was **not reproduced** on this host. Host: macOS 15 (Darwin 24.3.0, arm64), Node 26.9.0 (not the pinned 24.18.0), main `c7697595d`, `npm ci` + `npm run build:cached`. 1. `npm run test:focused -- tests/boundary/cli/nativeDemangleCli.test.ts` ×20: **20/20 passed**. "rejects a symbol spanning lines as input" took 358–3,672 ms per run against the unchanged 20,000 ms deadline. 2. Direct spawn of the exact invocation (`demangle-swift <absent> '$s4main3FooV' $'$s4main\n3FooV' --json`, env `REA_LOG_LEVEL=silent`, `REA_ANALYSIS_PROVIDER=auto`), timing spawn → first stdout → close: | condition | runs | spawn→close median / max | first stdout → close | | --- | --- | --- | --- | | warm compile cache | 30 | 450 / 658 ms | ~5 ms | | fresh `NODE_COMPILE_CACHE` per run | 10 | 567 / 602 ms | ~80 ms | | fresh cache + 8 busy-loop CPU burners | 15 | 831 / 1,088 ms | ~100–140 ms | Every run exited with code 1 and no signal, with the expected `VALIDATION_ERROR` on stdout. 3. A `--require` probe with an unref'd 3 s timer, which dumps `process._getActiveHandles()` / `getActiveResourcesInfo()` if the process is still alive at 3 s, **never fired** in any of the 55 direct runs. So no handle or child was observed keeping the CLI alive after the rejection on this host. On macOS arm64 the output-to-exit interval stays in the low milliseconds even when cold and under CPU contention. The hosted ~20 s stall is not explained by ordinary cold start or load here, so whatever keeps the process alive after the full stdout write didn't occur in 75 local attempts. I can rerun the timing harness on a specific revision or condition if that helps narrow it down.

bsakaguchi referenced this issue

2026-10-17 21:10:23 +00:00

[PR #1319] [MERGED] test(artifacts): verify extraction races with real filesystem changes #2797

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

morluto/rea#1319

No description provided.

Rows
Columns