flaky: verify-e2e hangs on catalogus.spec.ts (beheerder ziet catalogus) #161

Closed
opened 2026-09-03 12:23:47 +00:00 by eho · 1 comment
Owner

What happened

CI / verify-stack failed on PR #160 (a documentation-only change — markdown and mkdocs.yml).
Every check before the e2e suite passed: stack health, observability, objecttypen, objecten,
registerrecord, all 8 ACL integration tests, tracing, metrics. The job then entered
make verify-e2e and failed on the first of 5 Playwright tests:

Running 5 tests using 1 worker
  ✘  1 [chromium] › catalogus.spec.ts:7:5 › a beheerder sees the published zaaktypen in the catalogus (1.8m)

That is tests/e2e/catalogus.spec.ts — S-15a, the beheerder login → catalogus walking skeleton.

Why this looks like a flake, not a regression

  • PR #160 touches no application code, no test code, and no infra config. There is no plausible
    path from a docs/mkdocs change to a beheer-portal login flow.
  • A separate docs-only PR (#158, MFA-on-medewerker-realm write-up) ran the same verify-stack
    job on the same day and passed cleanly, so the job is not broken outright.
  • A push straight to main three days earlier (94742a2) also failed verify-stack, but at a
    different point entirely — Tempo container startup — fixed by the very next commit (#157,
    "stop single-binary Tempo evicting its only ingester"). Two distinct, unrelated verify-stack
    failures inside one week points at general instability in that job rather than one root cause.

The odd part: a ~24-minute gap

The job's total run time was 35m55s. The log stream above stops at the failure line, roughly
11.5 minutes after the job started (09:38:5909:50:30). The remaining ~24 minutes
produced no further log output before the job was marked failed. Worth checking whether
Playwright hung capturing a trace/video after the assertion failure, or whether the runner is
waiting out a default timeout before killing the job — either way, that gap is its own thing
to look at, separate from why the login/assertion failed the first time.

Evidence

Suggested next step

Re-run make verify-e2e (or the full verify-stack) against current main a few times outside
a PR to see how often catalogus.spec.ts actually fails, and check whether Playwright's
trace/video artifact is retained on that failed run — the job log gives no assertion detail
beyond the one-line summary, so the artifact (if the runner kept it) is the next thing to pull.

CLAUDE.md is explicit that flaky tests are fixed, not retried — filing this instead of retrying
CI on #160.

## What happened `CI / verify-stack` failed on PR #160 (a documentation-only change — markdown and `mkdocs.yml`). Every check before the e2e suite passed: stack health, observability, objecttypen, objecten, registerrecord, all 8 ACL integration tests, tracing, metrics. The job then entered `make verify-e2e` and failed on the **first** of 5 Playwright tests: ``` Running 5 tests using 1 worker ✘ 1 [chromium] › catalogus.spec.ts:7:5 › a beheerder sees the published zaaktypen in the catalogus (1.8m) ``` That is `tests/e2e/catalogus.spec.ts` — S-15a, the beheerder login → catalogus walking skeleton. ## Why this looks like a flake, not a regression - PR #160 touches no application code, no test code, and no infra config. There is no plausible path from a docs/mkdocs change to a beheer-portal login flow. - A separate docs-only PR (#158, MFA-on-medewerker-realm write-up) ran the same `verify-stack` job on the same day and passed cleanly, so the job is not broken outright. - A push straight to `main` three days earlier (`94742a2`) also failed `verify-stack`, but at a different point entirely — Tempo container startup — fixed by the very next commit (#157, "stop single-binary Tempo evicting its only ingester"). Two distinct, unrelated `verify-stack` failures inside one week points at general instability in that job rather than one root cause. ## The odd part: a ~24-minute gap The job's total run time was **35m55s**. The log stream above stops at the failure line, roughly **11.5 minutes** after the job started (`09:38:59` → `09:50:30`). The remaining ~24 minutes produced no further log output before the job was marked failed. Worth checking whether Playwright hung capturing a trace/video after the assertion failure, or whether the runner is waiting out a default timeout before killing the job — either way, that gap is its own thing to look at, separate from why the login/assertion failed the first time. ## Evidence - PR: `eho/register-referentie` #160 - Failed run: `actions/runs/739`, job `verify-stack` (job id 2836, task id 2660) - Failed run (unrelated, different cause): `actions/runs/733`, job id 2807, commit `94742a2` - Passing baseline on the same job, same day: `actions/runs/737` ## Suggested next step Re-run `make verify-e2e` (or the full `verify-stack`) against current `main` a few times outside a PR to see how often `catalogus.spec.ts` actually fails, and check whether Playwright's trace/video artifact is retained on that failed run — the job log gives no assertion detail beyond the one-line summary, so the artifact (if the runner kept it) is the next thing to pull. CLAUDE.md is explicit that flaky tests are fixed, not retried — filing this instead of retrying CI on #160.
eho added the area:portal-beheertype:bug labels 2026-09-03 12:23:47 +00:00
Contributor

Picked this up — PR #165. Two findings worth recording here, since one of them changes how the issue reads.

The ~24-minute gap is the job being stopped, not silence. Run 739's job metadata (job id 2836,
attempt 1) shows the e2e step running 09:48:17 → 10:14:54 and then every later step as a
zero-length failure stamped at that same instant:

14 failure  09:48:17 -> 10:14:54  Self-service e2e (Playwright …)
15 failure  10:14:54 -> 10:14:54  verify-stack check summary       ← if: always()
16 failure  10:14:54 -> 10:14:54  e2e spec summary                 ← if: always()
17 failure  10:14:54 -> 10:14:54  Dump container logs on failure   ← if: failure()
18 failure  10:14:54 -> 10:14:54  Tear down                        ← if: always()

if: always() only covers an earlier step failing — it does not survive the job itself being
stopped, so the per-spec summary, the container-log dump and the teardown never ran, and the log
lost whatever the killed process had buffered. That is why the only surviving output was one
line. Also note run 739 now reports run_attempt: 2 (hence its green conclusion today), and
concurrency.cancel-in-progress: true cancels an in-flight run on any re-run or new push — so the
stop may simply have been the re-run, and there may never have been a 24-minute hang at all.
Recorded as gotchas §9, including how to read step timings via the API instead of trusting a
truncated log.

Why the spec cost 1.8 minutes rather than failing at an expect timeout. Playwright actions
(fill, click) auto-wait until the test timeout, not expect.timeout — so when the login form
never appears, #username.fill() burns the full 90s and reports locator.fill: Test timeout of 90000ms exceeded: the symptom, with no hint at the cause. The suspected shape is a portal that
serves its page but never bootstraps (main.ts does a one-shot
fetch('config.json').then(bootstrap).catch(console.error), and authorize() needs the OIDC
discovery document), which leaves a blank page with nothing in the DOM and nothing on screen.

What #165 changes: globalTimeout bounds the run so Playwright stops and reports (the report
and the if: always() steps survive); both Keycloak forms are asserted visible first with a 20s
budget and a message naming the step that never happened — verified against a deliberately broken
portal, failing in 20.2s instead of 90; and the per-spec summary now carries the failing spec's
error, so a red e2e explains itself without a log dive.

What it does not do: prove why the login failed that once — the evidence for that was destroyed
by the second defect. I ran the suite green five times locally today (catalogus.spec 1.1–5.3s), but
a local box is not the loaded CI runner, so that is weak evidence. Suggest keeping this issue open
until the next occurrence reports itself with the new diagnostics, and closing it then — #165 says
closes #161, so say the word and I will drop that footer and let this issue stand on its own.

Spun out of the investigation, not included: all four portals show a permanently blank page if
their startup fetch fails
, with no UI and no recovery. That is a product gap rather than test
infra and wants its own slice — happy to file it.

Picked this up — PR #165. Two findings worth recording here, since one of them changes how the issue reads. **The ~24-minute gap is the job being stopped, not silence.** Run 739's job metadata (job id 2836, attempt 1) shows the e2e step running 09:48:17 → 10:14:54 and then *every* later step as a zero-length `failure` stamped at that same instant: ``` 14 failure 09:48:17 -> 10:14:54 Self-service e2e (Playwright …) 15 failure 10:14:54 -> 10:14:54 verify-stack check summary ← if: always() 16 failure 10:14:54 -> 10:14:54 e2e spec summary ← if: always() 17 failure 10:14:54 -> 10:14:54 Dump container logs on failure ← if: failure() 18 failure 10:14:54 -> 10:14:54 Tear down ← if: always() ``` `if: always()` only covers *an earlier step failing* — it does not survive the job itself being stopped, so the per-spec summary, the container-log dump and the teardown never ran, and the log lost whatever the killed process had buffered. That is why the only surviving output was one `✘` line. Also note run 739 now reports `run_attempt: 2` (hence its green conclusion today), and `concurrency.cancel-in-progress: true` cancels an in-flight run on any re-run or new push — so the stop may simply have been the re-run, and there may never have been a 24-minute hang at all. Recorded as gotchas §9, including how to read step timings via the API instead of trusting a truncated log. **Why the spec cost 1.8 minutes rather than failing at an expect timeout.** Playwright actions (`fill`, `click`) auto-wait until the *test* timeout, not `expect.timeout` — so when the login form never appears, `#username.fill()` burns the full 90s and reports `locator.fill: Test timeout of 90000ms exceeded`: the symptom, with no hint at the cause. The suspected shape is a portal that serves its page but never bootstraps (`main.ts` does a one-shot `fetch('config.json').then(bootstrap).catch(console.error)`, and `authorize()` needs the OIDC discovery document), which leaves a blank page with nothing in the DOM and nothing on screen. **What #165 changes:** `globalTimeout` bounds the run so Playwright stops and *reports* (the report and the `if: always()` steps survive); both Keycloak forms are asserted visible first with a 20s budget and a message naming the step that never happened — verified against a deliberately broken portal, failing in 20.2s instead of 90; and the per-spec summary now carries the failing spec's error, so a red e2e explains itself without a log dive. **What it does not do: prove why the login failed that once** — the evidence for that was destroyed by the second defect. I ran the suite green five times locally today (catalogus.spec 1.1–5.3s), but a local box is not the loaded CI runner, so that is weak evidence. Suggest keeping this issue open until the next occurrence reports itself with the new diagnostics, and closing it then — #165 says `closes #161`, so say the word and I will drop that footer and let this issue stand on its own. Spun out of the investigation, not included: **all four portals show a permanently blank page if their startup fetch fails**, with no UI and no recovery. That is a product gap rather than test infra and wants its own slice — happy to file it.
not closed this issue 2026-09-04 10:53:37 +00:00
Sign in to join this conversation.
2 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: eho/register-referentie#161