morluto/rea

Fork 0

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

[GH-ISSUE #2760] bug(process): startup deadline can expire before its monotonic budget #993

New issue

Closed

opened 2026-10-15 18:30:10 +00:00 by bsakaguchi · 3 comments

bsakaguchi commented

2026-10-15 18:30:10 +00:00

Owner

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

Originally assigned to: @N0zoM1z0 on GitHub.

Problem

ProviderStartupDeadline can abort startup as a timeout before its own absolute monotonic deadline has expired. Its timer callback unconditionally sets #interruption = "timeout" and aborts; remainingMs() independently calculates the positive budget from performance.now(). Consequently the public deadline state can simultaneously report timeout and a remaining budget of 1ms.

This is an independently reproduced baseline issue, not a behavior change in the documentation-only CI/tests audit skill PR #2692. Do not address it by weakening the existing assertion or retrying until green.

Executed revisions and observed evidence

Hosted CI run 38377675396, head 156872ea58bf0b54e193a588dcc38e29dea2bef8, failed src/process/ProviderDeadline.test.ts: after await deadline.wait(500) returned "aborted" for a 40ms deadline, remainingMs() was 1, expected 0.
On feature head debffc44387dda98196aedd1ac8566928499dd96, based on clean main 747e7299141cec0b03774c427f579889d5088d20, 50 sequential real 40ms deadline waits using Node 24.18.0, npm 11.16.0, Vitest 5.0.3 reproduced the discrepancy 3 times. These samples elapsed approximately 39.695ms, 39.432ms and 39.414ms from immediately before construction; all returned "aborted", classified "timeout", and retained 1ms. This is a bounded observation, not an estimated global flake rate.
A deterministic probe mocked only the monotonic reading and timeout scheduling: construction at performance.now() = 0, callback fired with monotonic reading 39 for a 40ms deadline. Observed { aborted: true, interruption: "timeout", remaining: 1 }; the assertion that startup must not abort before its deadline failed.
The original source and test were restored byte-for-byte after the temporary probes. The feature PR has no changes to either file.

Reproduction

The existing real-time regression is:

npm run test:local -- src/process/ProviderDeadline.test.ts

One pass cannot disprove the intermittent timer boundary. For a deterministic reproduction, append the following temporary case to that file (which already imports it, expect, vi and ProviderStartupDeadline), run the command above, and restore the file afterwards:

it("does not expire a future monotonic deadline on an early timer callback", async () => {
  vi.useFakeTimers({ toFake: ["setTimeout", "clearTimeout"] });
  let monotonic = 0;
  vi.spyOn(performance, "now").mockImplementation(() => monotonic);
  const deadline = new ProviderStartupDeadline(40);
  try {
    monotonic = 39;
    await vi.advanceTimersByTimeAsync(40);
    expect(deadline.remainingMs()).toBe(1);
    expect(deadline.signal.aborted).toBe(false); // currently fails
  } finally {
    deadline.dispose();
    vi.useRealTimers();
  }
});

To inspect actual timer behavior, perform 50 sequential new ProviderStartupDeadline(40) / await deadline.wait(500) observations, recording elapsed performance.now(), result, interruption and remaining budget; dispose each deadline in finally. Keep timing logs instead of converting retries into a successful verification claim.

Affected ownership and consumers

The startup deadline owns both its absolute budget and abort timer. Ghidra startup/socket polling, Hopper startup and OwnedCommand consume that shared state. The early callback can prematurely abort a provider handshake; the directly observed discrepancy is sub-millisecond, not evidence of widespread startup failures or a measured performance regression.

Required correction and verification

Correct the monotonic deadline owner so early timer delivery cannot expire a future deadline. Preserve caller cancellation, reason/classification, bounded polling, and disposal of timers/listeners. Inspect consumers before choosing the implementation.

Simply rescheduling the abort timer is insufficient by itself: wait() also clamps its polling timer to the remaining budget, and it may resolve "elapsed" at the deadline before the corrected abort timer. Cover that interaction rather than changing the current expected result. Avoid making cancelled deadlines report an exhausted budget just to force the assertion to pass.

Retain the real-time regression and add deterministic cases for early delivery, exact expiry, late delivery, polling intervals shorter than the budget, caller cancellation before/after expiry, and cleanup with pending waits. Run affected Ghidra/Hopper/OwnedCommand tests. No blanket retries, timeout increases or reduced assertions are justified by this report.

Status

Investigation and reproduction are complete. No production fix is included in #2692; that PR supplies a reusable audit skill. Raw observations are recorded locally in /tmp/rea-ci-tests-skill-deadline-probe.log and the task validation document.

Originally created by @N0zoM1z0 on GitHub (Oct 13, 2026). Original GitHub issue: https://github.com/morluto/rea/issues/2760 Originally assigned to: @N0zoM1z0 on GitHub. ## Problem `ProviderStartupDeadline` can abort startup as a timeout before its own absolute monotonic deadline has expired. Its timer callback unconditionally sets `#interruption = "timeout"` and aborts; `remainingMs()` independently calculates the positive budget from `performance.now()`. Consequently the public deadline state can simultaneously report timeout and a remaining budget of 1ms. This is an independently reproduced baseline issue, not a behavior change in the documentation-only CI/tests audit skill PR #2692. Do not address it by weakening the existing assertion or retrying until green. ## Executed revisions and observed evidence - Hosted CI run [38377675396](https://github.com/morluto/rea/actions/runs/38377675396), head `156872ea58bf0b54e193a588dcc38e29dea2bef8`, failed `src/process/ProviderDeadline.test.ts`: after `await deadline.wait(500)` returned `"aborted"` for a 40ms deadline, `remainingMs()` was **1**, expected **0**. - On feature head `debffc44387dda98196aedd1ac8566928499dd96`, based on clean main `747e7299141cec0b03774c427f579889d5088d20`, 50 sequential real 40ms deadline waits using Node **24.18.0**, npm **11.16.0**, Vitest **5.0.3** reproduced the discrepancy **3 times**. These samples elapsed approximately **39.695ms, 39.432ms and 39.414ms** from immediately before construction; all returned `"aborted"`, classified `"timeout"`, and retained 1ms. This is a bounded observation, not an estimated global flake rate. - A deterministic probe mocked only the monotonic reading and timeout scheduling: construction at `performance.now() = 0`, callback fired with monotonic reading **39** for a **40ms** deadline. Observed `{ aborted: true, interruption: "timeout", remaining: 1 }`; the assertion that startup must not abort before its deadline failed. - The original source and test were restored byte-for-byte after the temporary probes. The feature PR has no changes to either file. ## Reproduction The existing real-time regression is: ```sh npm run test:local -- src/process/ProviderDeadline.test.ts ``` One pass cannot disprove the intermittent timer boundary. For a deterministic reproduction, append the following temporary case to that file (which already imports `it`, `expect`, `vi` and `ProviderStartupDeadline`), run the command above, and restore the file afterwards: ```ts it("does not expire a future monotonic deadline on an early timer callback", async () => { vi.useFakeTimers({ toFake: ["setTimeout", "clearTimeout"] }); let monotonic = 0; vi.spyOn(performance, "now").mockImplementation(() => monotonic); const deadline = new ProviderStartupDeadline(40); try { monotonic = 39; await vi.advanceTimersByTimeAsync(40); expect(deadline.remainingMs()).toBe(1); expect(deadline.signal.aborted).toBe(false); // currently fails } finally { deadline.dispose(); vi.useRealTimers(); } }); ``` To inspect actual timer behavior, perform 50 sequential `new ProviderStartupDeadline(40)` / `await deadline.wait(500)` observations, recording elapsed `performance.now()`, result, interruption and remaining budget; dispose each deadline in `finally`. Keep timing logs instead of converting retries into a successful verification claim. ## Affected ownership and consumers The startup deadline owns both its absolute budget and abort timer. Ghidra startup/socket polling, Hopper startup and `OwnedCommand` consume that shared state. The early callback can prematurely abort a provider handshake; the directly observed discrepancy is sub-millisecond, not evidence of widespread startup failures or a measured performance regression. ## Required correction and verification Correct the monotonic deadline owner so early timer delivery cannot expire a future deadline. Preserve caller cancellation, reason/classification, bounded polling, and disposal of timers/listeners. Inspect consumers before choosing the implementation. Simply rescheduling the abort timer is insufficient by itself: `wait()` also clamps its polling timer to the remaining budget, and it may resolve `"elapsed"` at the deadline before the corrected abort timer. Cover that interaction rather than changing the current expected result. Avoid making cancelled deadlines report an exhausted budget just to force the assertion to pass. Retain the real-time regression and add deterministic cases for early delivery, exact expiry, late delivery, polling intervals shorter than the budget, caller cancellation before/after expiry, and cleanup with pending waits. Run affected Ghidra/Hopper/OwnedCommand tests. No blanket retries, timeout increases or reduced assertions are justified by this report. ## Status Investigation and reproduction are complete. No production fix is included in #2692; that PR supplies a reusable audit skill. Raw observations are recorded locally in `/tmp/rea-ci-tests-skill-deadline-probe.log` and the task validation document.

bsakaguchi

2026-10-15 18:30:10 +00:00

closed this issue
added the
bug
label

bsakaguchi commented

2026-10-15 18:30:11 +00:00

Author

Owner

@nosmile99 commented on GitHub (Oct 13, 2026):

PR #2793 implements the prescribed correction: the timer callback re-checks performance.now() >= #deadlineAt and re-arms for the residual budget on early delivery instead of aborting a still-future deadline; a full-budget wait() resolving exactly at the deadline now reports "aborted". Differs from #2720's masking approach (early abort kept, remainingMs() forced to 0) — happy to rework if maintainers pick one semantic. Regression: 3/8 new fake-timer tests fail pre-fix, 8/8 pass post-fix (6 repeat runs), 63/63 consumer tests green.

@nosmile99 commented on GitHub (Oct 13, 2026): PR #2793 implements the prescribed correction: the timer callback re-checks `performance.now() >= #deadlineAt` and re-arms for the residual budget on early delivery instead of aborting a still-future deadline; a full-budget `wait()` resolving exactly at the deadline now reports `"aborted"`. Differs from #2720's masking approach (early abort kept, `remainingMs()` forced to 0) — happy to rework if maintainers pick one semantic. Regression: 3/8 new fake-timer tests fail pre-fix, 8/8 pass post-fix (6 repeat runs), 63/63 consumer tests green.

bsakaguchi commented

2026-10-15 18:30:11 +00:00

Author

Owner

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

Independent verification of PR #2793 at 3e1a366340f2eae82b17e14694a0a70f31746410 found a remaining necessary case: both the abort timer and the clamped polling timer can fire early.

Its original 8 tests pass. Appending the probe below produces 8 passed / 1 failed through npm run test:local -- src/process/ProviderDeadline.test.ts. At monotonic39 / target40, the observed state is {outcome:"elapsed", aborted:false, remaining:1}. The source was restored after the probe. This moves the intermittent failure from the original real-time test's remaining-budget assertion to its expected "aborted" wait result, rather than completing the full-budget wait contract.

it("keeps a full-budget wait pending when both timers fire early", async () => {
  vi.useFakeTimers({ toFake: ["setTimeout", "clearTimeout"] });
  let monotonic = 0;
  vi.spyOn(performance, "now").mockImplementation(() => monotonic);
  const caller = new AbortController();
  const deadline = new ProviderStartupDeadline(40, caller.signal);
  let outcome: string | undefined;
  const pending = deadline.wait(500).then(result => {
    outcome = result;
    return result;
  });
  try {
    monotonic = 39;
    await vi.advanceTimersByTimeAsync(40);
    expect(deadline.signal.aborted).toBe(false);
    expect(deadline.remainingMs()).toBe(1);
    expect(outcome).toBeUndefined(); // currently "elapsed"
    monotonic = 40;
    await vi.advanceTimersByTimeAsync(1);
    await expect(pending).resolves.toBe("aborted");
    expect(deadline.remainingMs()).toBe(0);
  } finally {
    caller.abort();
    deadline.dispose();
    vi.useRealTimers();
  }
});

The correction should retain an absolute wait target (the earlier of the requested polling interval and the startup deadline) and continue the bounded wait if a timer reports elapsed before that target. Rechecking only now >= #deadlineAt in .then misses the 1ms-positive case. Preserve caller cancellation, reasons and timer/listener cleanup; keep the original real-time assertion.

The same baseline failure has now recurred in skill PR #2692 CI run 38392593863, head 2cb076e9b, shard3. The other five shards and Linux package baseline passed. No blind retry has erased that failure. The skill PR still has only four documentation/metadata files while the independently reproduced deadline defect is addressed.

@N0zoM1z0 commented on GitHub (Oct 13, 2026): Independent verification of PR #2793 at `3e1a366340f2eae82b17e14694a0a70f31746410` found a remaining necessary case: **both the abort timer and the clamped polling timer can fire early**. Its original 8 tests pass. Appending the probe below produces 8 passed / 1 failed through `npm run test:local -- src/process/ProviderDeadline.test.ts`. At monotonic39 / target40, the observed state is `{outcome:"elapsed", aborted:false, remaining:1}`. The source was restored after the probe. This moves the intermittent failure from the original real-time test's remaining-budget assertion to its expected `"aborted"` wait result, rather than completing the full-budget wait contract. ```ts it("keeps a full-budget wait pending when both timers fire early", async () => { vi.useFakeTimers({ toFake: ["setTimeout", "clearTimeout"] }); let monotonic = 0; vi.spyOn(performance, "now").mockImplementation(() => monotonic); const caller = new AbortController(); const deadline = new ProviderStartupDeadline(40, caller.signal); let outcome: string | undefined; const pending = deadline.wait(500).then(result => { outcome = result; return result; }); try { monotonic = 39; await vi.advanceTimersByTimeAsync(40); expect(deadline.signal.aborted).toBe(false); expect(deadline.remainingMs()).toBe(1); expect(outcome).toBeUndefined(); // currently "elapsed" monotonic = 40; await vi.advanceTimersByTimeAsync(1); await expect(pending).resolves.toBe("aborted"); expect(deadline.remainingMs()).toBe(0); } finally { caller.abort(); deadline.dispose(); vi.useRealTimers(); } }); ``` The correction should retain an absolute wait target (the earlier of the requested polling interval and the startup deadline) and continue the bounded wait if a timer reports elapsed before that target. Rechecking only `now >= #deadlineAt` in `.then` misses the 1ms-positive case. Preserve caller cancellation, reasons and timer/listener cleanup; keep the original real-time assertion. The same baseline failure has now recurred in skill PR #2692 CI run [38392593863](https://github.com/morluto/rea/actions/runs/38392593863), head `2cb076e9b`, shard3. The other five shards and Linux package baseline passed. No blind retry has erased that failure. The skill PR still has only four documentation/metadata files while the independently reproduced deadline defect is addressed.

bsakaguchi commented

2026-10-15 18:30:11 +00:00

Author

Owner

@nosmile99 commented on GitHub (Oct 13, 2026):

Confirmed and fixed — thanks for the precise probe. Reproduced locally: expected 'elapsed' to be undefined at monotonic 39 / target 40, exactly as reported.

Root cause: the re-arm in PR #2793 only fixed the abort timer. wait() itself still resolved "elapsed" when its clamped polling timer fired early at the same monotonic instant as the deadline timer, so the intermittent failure moved from the deadline's remaining-budget assertion to the wait's expected "aborted" result.

Structural fix (commit 5460016 on PR #2793): wait() now retains an absolute wait target — the earlier of the requested polling interval and the absolute monotonic deadline — and continues the bounded wait when a timer reports elapsed before that target. Classification: expired deadline → "aborted"; elapsed polling target → "elapsed"; early timer delivery → re-arm and keep waiting. Caller cancellation, reasons, and timer/listener cleanup are unchanged.

Validation: your probe added verbatim as a regression test (fails pre-fix, passes post-fix); ProviderDeadline + ProviderProcessOutput + GhidraProvider.behavior + HopperProvider = 64/64 green, stable across 6 repeat runs; npm run check:fast green.

@nosmile99 commented on GitHub (Oct 13, 2026): Confirmed and fixed — thanks for the precise probe. Reproduced locally: `expected 'elapsed' to be undefined` at monotonic 39 / target 40, exactly as reported. Root cause: the re-arm in PR #2793 only fixed the abort timer. `wait()` itself still resolved `"elapsed"` when its clamped polling timer fired early at the same monotonic instant as the deadline timer, so the intermittent failure moved from the deadline's remaining-budget assertion to the wait's expected `"aborted"` result. Structural fix (commit `5460016` on PR #2793): `wait()` now retains an absolute wait target — the earlier of the requested polling interval and the absolute monotonic deadline — and continues the bounded wait when a timer reports elapsed before that target. Classification: expired deadline → `"aborted"`; elapsed polling target → `"elapsed"`; early timer delivery → re-arm and keep waiting. Caller cancellation, reasons, and timer/listener cleanup are unchanged. Validation: your probe added verbatim as a regression test (fails pre-fix, passes post-fix); ProviderDeadline + ProviderProcessOutput + GhidraProvider.behavior + HopperProvider = 64/64 green, stable across 6 repeat runs; `npm run check:fast` green.

bsakaguchi referenced this issue

2026-10-17 21:07:36 +00:00

[PR #993] [MERGED] feat(website): add a shared back-to-top link #2562

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#993

No description provided.

Rows
Columns