The fixture's step deadlines are fixed when it starts: the near-deadline browser spec fails once it has been up 2 minutes #134

Closed
opened 2026-10-02 23:58:35 -04:00 by cmoriarty · 1 comment
Owner

ui/e2e/step-failure.spec.ts:91 ("a running step near its deadline says so in the spine and in Step details") expects the clock step's activity line to read /1[23]m left/. Against a fixture backend that has been up for 2 minutes or more, the line reads 11m left and the spec fails. It failed that way in a fast lane on 2026-10-02 under heavy machine load. It passes when run alone.

Why

ui/dev/fakeosfd.py sets the deadline once, when the module loads:

# Thirteen minutes from now, taken when the fixture starts: the specs run within a minute of it.
_clock_step.update(timeout_s=3600.0, deadline_at=time.time() + 13 * 60)

The console rounds the time left up to the minute (leftWords). So the line reads 13m left in the fixture's first minute, 12m left in its second, and 11m left from 120 s on. Two ways to get there:

  • A slow lane. Playwright starts the fixture before the first spec. Under load, the browser stage can take more than 2 minutes to reach this one.
  • A reused fixture. ui/playwright.config.ts has reuseExistingServer: true, so a run reuses whatever fixture is already on its port, however old it is. Another session's run can leave one on 8719.

Reproduced on 2026-10-02 against a fixture started on a private port at 23:54:44. The spec passed at 61 s and failed at 141 s:

Expected pattern: /1[23]m left/
Received string:  "Starting · 11m left"

_retry_step (run_mediated, used by e2e/failure-mediation.spec.ts) has the same problem, with 100 minutes. After 85 minutes its spine line turns amber. After 100 minutes the gauge reads time is up (2h limit), and that spec's / of 2h$/ fails.

Fix

Take these two deadlines from the moment the step is served, not from when the fixture started. Keep each step's time left (13 and 100 minutes) and add it to the time of the request wherever the step and its running attempt are served: GET /api/runs/{id}, the stream's snapshot, and GET /api/steps/{id}.

The spec keeps its meaning: a 1h step with 13 minutes left is in the last quarter of its limit, so it is amber in the spine and in Step details. Check the fix against a fixture started 3 minutes before the run.

`ui/e2e/step-failure.spec.ts:91` ("a running step near its deadline says so in the spine and in Step details") expects the clock step's activity line to read `/1[23]m left/`. Against a fixture backend that has been up for 2 minutes or more, the line reads `11m left` and the spec fails. It failed that way in a fast lane on 2026-10-02 under heavy machine load. It passes when run alone. ## Why `ui/dev/fakeosfd.py` sets the deadline once, when the module loads: ```python # Thirteen minutes from now, taken when the fixture starts: the specs run within a minute of it. _clock_step.update(timeout_s=3600.0, deadline_at=time.time() + 13 * 60) ``` The console rounds the time left up to the minute (`leftWords`). So the line reads `13m left` in the fixture's first minute, `12m left` in its second, and `11m left` from 120 s on. Two ways to get there: - **A slow lane.** Playwright starts the fixture before the first spec. Under load, the browser stage can take more than 2 minutes to reach this one. - **A reused fixture.** `ui/playwright.config.ts` has `reuseExistingServer: true`, so a run reuses whatever fixture is already on its port, however old it is. Another session's run can leave one on 8719. Reproduced on 2026-10-02 against a fixture started on a private port at 23:54:44. The spec passed at 61 s and failed at 141 s: ``` Expected pattern: /1[23]m left/ Received string: "Starting · 11m left" ``` `_retry_step` (`run_mediated`, used by `e2e/failure-mediation.spec.ts`) has the same problem, with 100 minutes. After 85 minutes its spine line turns amber. After 100 minutes the gauge reads `time is up (2h limit)`, and that spec's `/ of 2h$/` fails. ## Fix Take these two deadlines from the moment the step is served, not from when the fixture started. Keep each step's time left (13 and 100 minutes) and add it to the time of the request wherever the step and its running attempt are served: `GET /api/runs/{id}`, the stream's snapshot, and `GET /api/steps/{id}`. The spec keeps its meaning: a 1h step with 13 minutes left is in the last quarter of its limit, so it is amber in the spine and in Step details. Check the fix against a fixture started 3 minutes before the run.
Author
Owner

Shipped in 58385a6. The proposal is 71c62a4 and the archive is 7b6a101. All three carry [skip ci]: osfd's image ships only ui/dist, and nothing in it changed, so production was not redeployed.

What changed

  • The fixture. ui/dev/fakeosfd.py keeps each clocked step's time left in TIME_LEFT: 13 minutes for run_clock's agent.test.browser, and 100 for run_mediated's. Every response adds that to its own time:

    • in the run fetch and the stream's snapshot (_timed);
    • in GET /api/steps/{id}, on the step and on its attempt in flight.

    The attempt that already timed out keeps its fixed deadline.

  • A new spec. ui/e2e/fixture-clock.spec.ts uses the API only. It checks that each deadline_at is the step's time left after the response's own ts. A fixture that took the deadline at start fails it once that fixture is half a second old, so a lane catches a regression without waiting 2 minutes.

  • The spec of record. test-lanes has a new requirement: "The fixture backend's deadlines are taken from the request".

  • Unchanged. step-failure.spec.ts still expects /1[23]m left/, amber, in the spine and in Step details.

Verified

  • A fixed fixture, 3 min 16 s old: step-failure, failure-mediation, step-last-call and fixture-clock passed, 16 of 16. In the console, 4 minutes in, the spine read Starting · 13m left in the signal colour, and Step details read 13m left of 1h.
  • The unfixed fixture, 30 minutes old: the near-deadline spec read Starting · time is up, and fixture-clock received -1029 s against 780. Both failed, as expected.
  • A fresh fixture: 16 of 16 passed.
  • Lanes: the fast lane passed (2,355 backend, 524 vitest, 138 browser), and so did the full lane (2,363, 524, 155).
Shipped in 58385a6. The proposal is 71c62a4 and the archive is 7b6a101. All three carry `[skip ci]`: osfd's image ships only `ui/dist`, and nothing in it changed, so production was not redeployed. ## What changed - **The fixture.** `ui/dev/fakeosfd.py` keeps each clocked step's time left in `TIME_LEFT`: 13 minutes for `run_clock`'s `agent.test.browser`, and 100 for `run_mediated`'s. Every response adds that to its own time: - in the run fetch and the stream's snapshot (`_timed`); - in `GET /api/steps/{id}`, on the step and on its attempt in flight. The attempt that already timed out keeps its fixed deadline. - **A new spec.** `ui/e2e/fixture-clock.spec.ts` uses the API only. It checks that each `deadline_at` is the step's time left after the response's own `ts`. A fixture that took the deadline at start fails it once that fixture is half a second old, so a lane catches a regression without waiting 2 minutes. - **The spec of record.** `test-lanes` has a new requirement: "The fixture backend's deadlines are taken from the request". - **Unchanged.** `step-failure.spec.ts` still expects `/1[23]m left/`, amber, in the spine and in Step details. ## Verified - **A fixed fixture, 3 min 16 s old:** `step-failure`, `failure-mediation`, `step-last-call` and `fixture-clock` passed, 16 of 16. In the console, 4 minutes in, the spine read `Starting · 13m left` in the signal colour, and Step details read `13m left of 1h`. - **The unfixed fixture, 30 minutes old:** the near-deadline spec read `Starting · time is up`, and `fixture-clock` received -1029 s against 780. Both failed, as expected. - **A fresh fixture:** 16 of 16 passed. - **Lanes:** the fast lane passed (2,355 backend, 524 vitest, 138 browser), and so did the full lane (2,363, 524, 155).
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
cmoriarty/braid#134
No description provided.