From 699fef4e68a08b3ee22ffb0f2e2505886f663e28 Mon Sep 17 00:00:00 2001 From: Niek Otten Date: Fri, 4 Sep 2026 11:40:35 +0200 Subject: [PATCH 1/5] test(ci): the e2e job summary must name why a spec failed (refs #161) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit #161 lost a 36-minute verify-stack job whose only surviving output was a single ✘ line: the per-spec summary (#136) renders a verdict icon and nothing else, so a red e2e still costs a log dive — and when the log is truncated or the run is killed, there is nothing to dive into. Adds a stdlib assert-based self-check for infra/playwright-summary.py (no framework) and rides it on `make unit` so CI catches a broken summary. Fails with "AssertionError: Test timeout of 90000ms exceeded" not in the rendered markdown. Co-Authored-By: Claude Opus 5 (1M context) --- Makefile | 3 ++ infra/test_playwright_summary.py | 88 ++++++++++++++++++++++++++++++++ 2 files changed, 91 insertions(+) create mode 100644 infra/test_playwright_summary.py diff --git a/Makefile b/Makefile index 75d7163..d9efbc2 100644 --- a/Makefile +++ b/Makefile @@ -71,8 +71,11 @@ build: ## unit: run unit tests (excludes the container-backed Integration lane) # TRX per test project (→ TestResults/) feeds the CI per-service summary (#136); harmless locally. +# The CI reporting scripts are stdlib Python with their own assert-based self-checks (#161) — they +# ride this lane so a broken job summary is caught by CI rather than by the next red pipeline. unit: dotnet test $(SLN) -c Release --filter "Category!=Integration" --logger trx --results-directory TestResults + python3 infra/test_playwright_summary.py ## mutation: run the Stryker.NET ratchet on each service with branching logic (fails below baseline) # Stryker is pinned as a local dotnet tool (.config/dotnet-tools.json); `tool restore` diff --git a/infra/test_playwright_summary.py b/infra/test_playwright_summary.py new file mode 100644 index 0000000..613ac0f --- /dev/null +++ b/infra/test_playwright_summary.py @@ -0,0 +1,88 @@ +#!/usr/bin/env python3 +"""Self-check for infra/playwright-summary.py — stdlib asserts, no framework. + +Run: python3 infra/test_playwright_summary.py (also runs in `make unit`). + +A red e2e is only useful if the job summary says WHY it failed: #161 lost a 36-minute +verify-stack job whose only surviving output was one ✘ line with no assertion detail. +""" +import importlib.util +import io +import json +import os +import tempfile +from contextlib import redirect_stdout + +# The script's filename is not a valid module name, so load it by path. +spec = importlib.util.spec_from_file_location( + "playwright_summary", + os.path.join(os.path.dirname(os.path.abspath(__file__)), "playwright-summary.py"), +) +summary = importlib.util.module_from_spec(spec) +spec.loader.exec_module(summary) + + +def render(report): + """Run the renderer over a report dict and return its markdown.""" + with tempfile.NamedTemporaryFile("w", suffix=".json", delete=False) as fh: + json.dump(report, fh) + path = fh.name + try: + out = io.StringIO() + with redirect_stdout(out): + summary.main(path) + return out.getvalue() + finally: + os.unlink(path) + + +def spec_entry(title, status, errors=()): + return { + "title": title, + "file": "catalogus.spec.ts", + "ok": status == "expected", + "tests": [{"status": status, "results": [{"errors": [{"message": m} for m in errors]}]}], + } + + +def test_failing_spec_reports_why(): + md = render({ + "stats": {"expected": 4, "unexpected": 1, "flaky": 0, "skipped": 0, "duration": 108_000}, + "suites": [{"file": "catalogus.spec.ts", "specs": [ + spec_entry("a beheerder sees the published zaaktypen in the catalogus", "unexpected", + ["locator.fill: Test timeout of 90000ms exceeded.\n" + "Call log:\n - waiting for locator('#username')\n"]), + ]}], + }) + assert "❌" in md, md + # The point of the slice: the summary names the cause, not just the verdict. + assert "Test timeout of 90000ms exceeded" in md, md + assert "waiting for locator('#username')" in md, md + # A multi-line Playwright error must not break out of its table row. + assert not any(line.startswith("Call log:") for line in md.splitlines()), md + + +def test_passing_run_stays_quiet(): + md = render({ + "stats": {"expected": 1, "unexpected": 0, "flaky": 0, "skipped": 0, "duration": 5_000}, + "suites": [{"file": "catalogus.spec.ts", + "specs": [spec_entry("a beheerder sees the catalogus", "expected")]}], + }) + assert "✅" in md, md + assert "timeout" not in md.lower(), md + + +def test_missing_report_is_not_a_crash(): + out = io.StringIO() + with redirect_stdout(out): + rc = summary.main("/nonexistent/playwright-report.json") + assert rc == 0 + assert "did not reach the e2e step" in out.getvalue() + + +if __name__ == "__main__": + for name, fn in sorted(globals().items()): + if name.startswith("test_") and callable(fn): + fn() + print(f" ok {name}") + print("playwright-summary self-check passed") -- 2.54.0 From 779f0deb5a61058fdc4c361af3d352592cbb4ab8 Mon Sep 17 00:00:00 2001 From: Niek Otten Date: Fri, 4 Sep 2026 11:41:45 +0200 Subject: [PATCH 2/5] fix(ci): carry the failing spec's error into the e2e job summary (refs #161) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The per-spec table now has a "Why" column holding the spec's first error, flattened for a markdown cell: ANSI stripped, newlines collapsed, `|` escaped (a real report's message is multi-line, coloured, and embeds source-snippet gutters), clipped to 300 chars. The column only appears when something failed. So a red e2e names its cause in the summary even when the log is truncated or the run is killed mid-stream — which is the state #161 was filed from. Shape verified against an actual @playwright/test 1.61 failing report, not just the fixture. Co-Authored-By: Claude Opus 5 (1M context) --- infra/host-browser.yml | 20 +++++++++++++++ infra/playwright-summary.py | 42 ++++++++++++++++++++++++++++---- infra/test_playwright_summary.py | 20 +++++++++++++++ 3 files changed, 77 insertions(+), 5 deletions(-) create mode 100644 infra/host-browser.yml diff --git a/infra/host-browser.yml b/infra/host-browser.yml new file mode 100644 index 0000000..bb82990 --- /dev/null +++ b/infra/host-browser.yml @@ -0,0 +1,20 @@ +# Overlay: make the CI compose stack usable from a HOST browser. +# Same two mechanisms infra/docker-compose.local.yml already uses — pin Keycloak's issuer to the +# host-published address, and point each portal's runtime config.json at it. The BFF needs no +# change: it discovers metadata over keycloak:8080 and the discovered issuer is the pinned +# localhost:8180, which is what browser tokens carry. +services: + keycloak: + environment: + KC_HOSTNAME: http://localhost:8180 + KC_HOSTNAME_BACKCHANNEL_DYNAMIC: "true" + self-service: + volumes: + - ./local-config/self-service.config.json:/usr/share/nginx/html/config.json:ro,z + behandel: + volumes: + - ./local-config/behandel.config.json:/usr/share/nginx/html/config.json:ro,z + # beheer is the same medewerker realm as behandel, so it reuses behandel's config verbatim. + beheer: + volumes: + - ./local-config/behandel.config.json:/usr/share/nginx/html/config.json:ro,z diff --git a/infra/playwright-summary.py b/infra/playwright-summary.py index 25e1490..c2ed880 100644 --- a/infra/playwright-summary.py +++ b/infra/playwright-summary.py @@ -7,10 +7,34 @@ redirects it into $GITHUB_STEP_SUMMARY. Stdlib only. """ import json import os +import re import sys STATUS_ICON = {"expected": "✅", "unexpected": "❌", "skipped": "⏭️", "flaky": "⚠️"} +# A verdict alone still costs a log dive, and a killed or truncated job leaves no log to dive into +# (#161) — so a failing spec carries its first error into the table. Playwright errors are multi-line +# with a "Call log:", which a markdown table cell cannot hold, so they are flattened and clipped. +ERROR_CLIP = 300 + + +def first_error(spec): + """The first error message across a spec's test results, flattened for one table cell.""" + for test in spec.get("tests", []): + for result in test.get("results", []): + for error in result.get("errors", []): + message = (error.get("message") or "").strip() + if not message: + continue + # Strip ANSI colour, collapse to one line, and keep it inside the cell. + message = re.sub(r"\x1b\[[0-9;]*m", "", message) + message = " ".join(message.split()) + if len(message) > ERROR_CLIP: + message = message[:ERROR_CLIP - 1].rstrip() + "…" + # `|` would end the cell early. + return message.replace("|", "\\|") + return "" + def walk(suite, out): for spec in suite.get("specs", []): @@ -22,7 +46,8 @@ def walk(suite, out): else "expected" if spec.get("ok", False) else "unexpected") out.append({"file": spec.get("file") or suite.get("file") or suite.get("title", ""), - "title": spec.get("title", ""), "status": status}) + "title": spec.get("title", ""), "status": status, + "error": first_error(spec) if status in ("unexpected", "flaky") else ""}) for child in suite.get("suites", []): walk(child, out) @@ -46,10 +71,17 @@ def main(path): if not specs: print("_No specs ran._") return 0 - print("| Spec | Result |") - print("| ---- | :----: |") - for s in specs: - print(f"| {s['file']} › {s['title']} | {STATUS_ICON.get(s['status'], '❔')} |") + # The failure column only earns its width when something failed. + if any(s["error"] for s in specs): + print("| Spec | Result | Why |") + print("| ---- | :----: | --- |") + for s in specs: + print(f"| {s['file']} › {s['title']} | {STATUS_ICON.get(s['status'], '❔')} | {s['error']} |") + else: + print("| Spec | Result |") + print("| ---- | :----: |") + for s in specs: + print(f"| {s['file']} › {s['title']} | {STATUS_ICON.get(s['status'], '❔')} |") return 0 diff --git a/infra/test_playwright_summary.py b/infra/test_playwright_summary.py index 613ac0f..9255ca0 100644 --- a/infra/test_playwright_summary.py +++ b/infra/test_playwright_summary.py @@ -62,6 +62,26 @@ def test_failing_spec_reports_why(): assert not any(line.startswith("Call log:") for line in md.splitlines()), md +def test_real_playwright_error_is_flattened(): + # A real report's message is multi-line and ANSI-coloured, and embeds the source snippet with + # `|` gutters — all three would break the table cell. Shape verified against an actual + # @playwright/test 1.61 JSON report. + md = render({ + "stats": {"expected": 0, "unexpected": 1, "flaky": 0, "skipped": 0, "duration": 1_000}, + "suites": [{"file": "catalogus.spec.ts", "specs": [ + spec_entry("a beheerder sees the catalogus", "unexpected", + ["Error: expect(locator).toBeVisible() failed\n\n" + "\x1b[2mLocator: \x1b[22mgetByRole('heading')\n" + " 12 | await login(page);\n> 13 | await expect(heading).toBeVisible();\n"]), + ]}], + }) + row = [line for line in md.splitlines() if line.startswith("| catalogus.spec.ts")][0] + assert "\x1b" not in row, row + assert "Locator: getByRole('heading')" in row, row + # Every literal `|` from the snippet gutters is escaped, so the row keeps exactly 3 cells. + assert row.count("|") - row.count("\\|") == 4, row + + def test_passing_run_stays_quiet(): md = render({ "stats": {"expected": 1, "unexpected": 0, "flaky": 0, "skipped": 0, "duration": 5_000}, -- 2.54.0 From 27f2607e4e0639ad571d533cf8b51292290bd43d Mon Sep 17 00:00:00 2001 From: Niek Otten Date: Fri, 4 Sep 2026 11:44:30 +0200 Subject: [PATCH 3/5] refactor(e2e): route every portal login through one Keycloak helper (refs #161) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit `medewerker-login.ts` becomes `keycloak-login.ts`: the three citizen specs each duplicated the same three-line password login, so a fix to the login path had to be made four times. They now call `loginBurger`, and both realms share `submitPassword`. No behaviour change — all 6 specs green against a live stack. Co-Authored-By: Claude Opus 5 (1M context) --- tests/e2e/catalogus.spec.ts | 2 +- tests/e2e/default-fill.spec.ts | 2 +- ...r-login.spec.ts => keycloak-login.spec.ts} | 2 +- ...{medewerker-login.ts => keycloak-login.ts} | 19 ++++++++++++++++++- tests/e2e/registration.spec.ts | 6 ++---- tests/e2e/resume.spec.ts | 5 ++--- tests/e2e/withdrawal.spec.ts | 5 ++--- 7 files changed, 27 insertions(+), 14 deletions(-) rename tests/e2e/{medewerker-login.spec.ts => keycloak-login.spec.ts} (92%) rename tests/e2e/{medewerker-login.ts => keycloak-login.ts} (78%) diff --git a/tests/e2e/catalogus.spec.ts b/tests/e2e/catalogus.spec.ts index bb6e85f..5acd400 100644 --- a/tests/e2e/catalogus.spec.ts +++ b/tests/e2e/catalogus.spec.ts @@ -1,5 +1,5 @@ import { expect, test } from '@playwright/test'; -import { loginMedewerker } from './medewerker-login'; +import { loginMedewerker } from './keycloak-login'; // S-15a walking skeleton: a beheerder logs in to the beheer portal (medewerker realm) and sees the // read-only ZTC catalogus. The verify stack seeds and publishes the BIG-REGISTRATIE zaaktype (the diff --git a/tests/e2e/default-fill.spec.ts b/tests/e2e/default-fill.spec.ts index 637fe57..c9bf4e2 100644 --- a/tests/e2e/default-fill.spec.ts +++ b/tests/e2e/default-fill.spec.ts @@ -1,5 +1,5 @@ import { expect, test } from '@playwright/test'; -import { loginMedewerker } from './medewerker-login'; +import { loginMedewerker } from './keycloak-login'; // S-15b: a beheerder edits the ACL default-fill in the beheer portal and gets a saved confirmation. // Runs against the shared verify stack; it edits + saves (the ACL store is in-memory, ADR-0026) and diff --git a/tests/e2e/medewerker-login.spec.ts b/tests/e2e/keycloak-login.spec.ts similarity index 92% rename from tests/e2e/medewerker-login.spec.ts rename to tests/e2e/keycloak-login.spec.ts index b4e83bb..6580c31 100644 --- a/tests/e2e/medewerker-login.spec.ts +++ b/tests/e2e/keycloak-login.spec.ts @@ -1,5 +1,5 @@ import { expect, test } from '@playwright/test'; -import { OTP_PERIOD_MS, nextUnusedCounter } from './medewerker-login'; +import { OTP_PERIOD_MS, nextUnusedCounter } from './keycloak-login'; // Pure check of the TOTP counter guard in loginMedewerker — no browser, no stack. Keycloak refuses // a code it has already accepted (its otpPolicyCodeReusable defaults to false), so two logins as diff --git a/tests/e2e/medewerker-login.ts b/tests/e2e/keycloak-login.ts similarity index 78% rename from tests/e2e/medewerker-login.ts rename to tests/e2e/keycloak-login.ts index 53ba23a..3b7f003 100644 --- a/tests/e2e/medewerker-login.ts +++ b/tests/e2e/keycloak-login.ts @@ -4,6 +4,9 @@ import { tmpdir } from 'node:os'; import { join } from 'node:path'; import type { Page } from '@playwright/test'; +// Every portal login in the suite goes through this module — citizen realms (mock DigiD) and the +// medewerker realm alike — so the shared Keycloak form handling lives in exactly one place. + // The medewerker realm enforces MFA (S-15c), so a staff login is two steps: password, then a TOTP // code. The realm export seeds every medewerker with this fixture secret — Keycloak HMACs the raw // secret bytes — so the e2e can compute a valid code instead of enrolling an authenticator. @@ -42,10 +45,24 @@ function spendCounter(username: string): number { return counter; } -export async function loginMedewerker(page: Page, username: string): Promise { +/** + * Fill Keycloak's login form. Every portal is guarded, so the first navigation redirects here; the + * form ids are stable across themes. + */ +async function submitPassword(page: Page, username: string): Promise { await page.locator('#username').fill(username); await page.locator('#password').fill('test123'); await page.locator('#kc-login').click(); +} + +/** A citizen login on a mock-DigiD realm — no second factor (ADR-0031). */ +export async function loginBurger(page: Page, username: string): Promise { + await submitPassword(page, username); +} + +/** A staff login on the medewerker realm: password, then the enforced TOTP second factor. */ +export async function loginMedewerker(page: Page, username: string): Promise { + await submitPassword(page, username); // Keycloak's conditional-OTP step. Wait out the rest of the window if the counter we may spend is // still in the future; its lookAheadWindow would accept the code a moment early, but only by one diff --git a/tests/e2e/registration.spec.ts b/tests/e2e/registration.spec.ts index a7a9c0e..f02ae1a 100644 --- a/tests/e2e/registration.spec.ts +++ b/tests/e2e/registration.spec.ts @@ -1,5 +1,5 @@ import { expect, request, test } from '@playwright/test'; -import { loginMedewerker } from './medewerker-login'; +import { loginBurger, loginMedewerker } from './keycloak-login'; // Walking-skeleton happy path (S-08d + S-09 + S-09b + S-12 + S-10a + S-19b-2): a zorgprofessional // logs in via mock DigiD and submits through the self-service portal → BFF → domain; the entry @@ -23,9 +23,7 @@ test('DigiD submit → public INGEDIEND → documenten → behandelaar goedkeurt // checks submit as jan-burger (bsn 123456782) before the e2e runs on the shared stack, and // resume-on-load (S-26) would otherwise restore one of those on login — so each self-service spec // uses a dedicated citizen no other actor touches. - await page.locator('#username').fill('emma-burger'); - await page.locator('#password').fill('test123'); - await page.locator('#kc-login').click(); + await loginBurger(page, 'emma-burger'); // Back on the portal, authenticated. await expect(page.getByRole('heading', { name: /Zelfservice/i })).toBeVisible(); diff --git a/tests/e2e/resume.spec.ts b/tests/e2e/resume.spec.ts index cf749e0..fd1b14e 100644 --- a/tests/e2e/resume.spec.ts +++ b/tests/e2e/resume.spec.ts @@ -1,4 +1,5 @@ import { expect, test } from '@playwright/test'; +import { loginBurger } from './keycloak-login'; // S-26: a zorgprofessional submits, then reloads the self-service portal. On load the portal asks the // BFF for the caller's current open registration (owner-scoped by the DigiD token's bsn) and restores @@ -9,9 +10,7 @@ test('DigiD submit → reload → self-service restores the existing registratio // Its own DigiD user (like every self-service spec): on the shared verify stack, resume-on-load // (S-26) restores any open registration for the bsn, so each spec uses a dedicated citizen that no // other spec or verify-* check touches. This one in particular leaves an open registration. - await page.locator('#username').fill('sanne-burger'); - await page.locator('#password').fill('test123'); - await page.locator('#kc-login').click(); + await loginBurger(page, 'sanne-burger'); await expect(page.getByRole('heading', { name: /Zelfservice/i })).toBeVisible(); await page.getByRole('button', { name: /indienen/i }).click(); diff --git a/tests/e2e/withdrawal.spec.ts b/tests/e2e/withdrawal.spec.ts index a13d8f1..d9b2b33 100644 --- a/tests/e2e/withdrawal.spec.ts +++ b/tests/e2e/withdrawal.spec.ts @@ -1,4 +1,5 @@ import { expect, test } from '@playwright/test'; +import { loginBurger } from './keycloak-login'; // S-11 (Flow 3): a zorgprofessional logs in via mock DigiD, submits a registration, then withdraws // it ("trek aanvraag in") from the self-service portal. The withdrawal goes portal → BFF (owner- @@ -10,9 +11,7 @@ test('DigiD submit → trek aanvraag in → self-service confirms ingetrokken', // Its own DigiD user — isolated from the verify-* checks (jan-burger/123456782) so resume-on-load // (S-26) can't restore someone else's registration on the shared stack. - await page.locator('#username').fill('lars-burger'); - await page.locator('#password').fill('test123'); - await page.locator('#kc-login').click(); + await loginBurger(page, 'lars-burger'); await expect(page.getByRole('heading', { name: /Zelfservice/i })).toBeVisible(); -- 2.54.0 From e7d4ed8ad4bf14b5e5d85e42ee4e8396edbe1ed0 Mon Sep 17 00:00:00 2001 From: Niek Otten Date: Fri, 4 Sep 2026 11:46:28 +0200 Subject: [PATCH 4/5] fix(e2e): fail fast when a portal never reaches Keycloak, and bound the run (refs #161) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Two defects behind #161's opaque 36-minute verify-stack job. **A login that never gets its form ate the test timeout.** `fill()` auto-waits until the *test* timeout (90s), not the 15s expect timeout, so a portal that serves its page but never bootstraps — its config.json fetch or the OIDC discovery behind `authorize()` failed, and main.ts only console.errors — spent 90 seconds to report `locator.fill: Test timeout of 90000ms exceeded`: the symptom, not the cause. That is catalogus.spec's 1.8 minutes in the issue. Both Keycloak forms are now asserted visible first, with a 20s budget and a message naming the step that never happened. Verified against a real blank-bootstrap portal (a beheer image served with a config.json that is not JSON): fails in 20.2s with "the Keycloak login form never appeared — the portal did not reach Keycloak (check its config.json fetch and the OIDC discovery …)". **A wedged suite consumed the job.** Nothing bounded the run, so CI killed the job — and with it the `if: always()` steps that would have explained the failure: neither the per-spec summary nor the container-log dump ran (both show 0-second failures at the kill in run 739's metadata). `globalTimeout` makes Playwright stop and *report* instead, so the JSON report is written and those steps still run. 12 minutes over a ~1-minute suite: a backstop, not a budget. Co-Authored-By: Claude Opus 5 (1M context) --- tests/e2e/keycloak-login.ts | 33 +++++++++++++++++++++++++++++---- tests/e2e/playwright.config.ts | 6 ++++++ 2 files changed, 35 insertions(+), 4 deletions(-) diff --git a/tests/e2e/keycloak-login.ts b/tests/e2e/keycloak-login.ts index 3b7f003..4d7aa87 100644 --- a/tests/e2e/keycloak-login.ts +++ b/tests/e2e/keycloak-login.ts @@ -2,7 +2,7 @@ import { createHmac } from 'node:crypto'; import { readFileSync, writeFileSync } from 'node:fs'; import { tmpdir } from 'node:os'; import { join } from 'node:path'; -import type { Page } from '@playwright/test'; +import { expect, type Page } from '@playwright/test'; // Every portal login in the suite goes through this module — citizen realms (mock DigiD) and the // medewerker realm alike — so the shared Keycloak form handling lives in exactly one place. @@ -14,6 +14,18 @@ const OTP_SECRET = 'BIGMEDEWERKEROTPSEED'; export const OTP_PERIOD_MS = 30_000; +/** + * How long a Keycloak form gets to appear. Generous enough for a cold first browser launch and a + * loaded stack, far short of the 90-second test timeout an auto-waiting action would otherwise eat. + */ +const FORM_TIMEOUT_MS = 20_000; +const FORM_NEVER_APPEARED = + 'the Keycloak login form never appeared — the portal did not reach Keycloak (check its ' + + 'config.json fetch and the OIDC discovery on the authority it was built with)'; +const OTP_NEVER_APPEARED = + 'the Keycloak OTP form never appeared — the password step did not complete (check the ' + + 'medewerker realm seeded this user with both a password and a TOTP credential)'; + // RFC 6238 TOTP: HMAC-SHA1 over the 30-second counter, dynamically truncated to 6 digits. export function totp(secret = OTP_SECRET, at = Date.now()): string { const counter = Buffer.alloc(8); @@ -48,8 +60,17 @@ function spendCounter(username: string): number { /** * Fill Keycloak's login form. Every portal is guarded, so the first navigation redirects here; the * form ids are stable across themes. + * + * The form is asserted visible *before* it is filled. A portal that never reaches Keycloak — its + * runtime `config.json` fetch or the OIDC discovery behind `authorize()` failed, so it never + * bootstrapped and shows a blank page (main.ts only logs to the console) — would otherwise leave + * `fill()` auto-waiting until the whole test times out: 90 seconds spent to report + * `locator.fill: Test timeout of 90000ms exceeded`, naming the symptom and not the cause. That is + * how #161's catalogus.spec burned 1.8 minutes. This fails in a quarter of the time and says which + * step never happened. */ async function submitPassword(page: Page, username: string): Promise { + await expect(page.locator('#username'), FORM_NEVER_APPEARED).toBeVisible({ timeout: FORM_TIMEOUT_MS }); await page.locator('#username').fill(username); await page.locator('#password').fill('test123'); await page.locator('#kc-login').click(); @@ -64,9 +85,13 @@ export async function loginBurger(page: Page, username: string): Promise { export async function loginMedewerker(page: Page, username: string): Promise { await submitPassword(page, username); - // Keycloak's conditional-OTP step. Wait out the rest of the window if the counter we may spend is - // still in the future; its lookAheadWindow would accept the code a moment early, but only by one - // counter — waiting keeps a third login in the same window valid too. + // Keycloak's conditional-OTP step. Same reasoning as the password form above: assert it arrived + // rather than letting `fill()` swallow the test timeout. + await expect(page.locator('#otp'), OTP_NEVER_APPEARED).toBeVisible({ timeout: FORM_TIMEOUT_MS }); + + // Wait out the rest of the window if the counter we may spend is still in the future; Keycloak's + // lookAheadWindow would accept the code a moment early, but only by one counter — waiting keeps a + // third login in the same window valid too. const counter = spendCounter(username); await page.waitForTimeout(Math.max(0, counter * OTP_PERIOD_MS - Date.now())); await page.locator('#otp').fill(totp(OTP_SECRET, counter * OTP_PERIOD_MS)); diff --git a/tests/e2e/playwright.config.ts b/tests/e2e/playwright.config.ts index f0106f6..4f23444 100644 --- a/tests/e2e/playwright.config.ts +++ b/tests/e2e/playwright.config.ts @@ -15,6 +15,12 @@ export default defineConfig({ timeout: 90_000, expect: { timeout: 15_000 }, retries: 1, + // Bound the whole run, not just each test (#161). A wedged suite used to run until CI killed the + // job — which also killed the `if: always()` steps that would have said why: the per-spec summary + // and the container-log dump never ran, leaving a 36-minute job whose entire surviving output was + // one ✘ line. On `globalTimeout` Playwright stops and *reports*, so the JSON report is written and + // those steps still run. Generous over the ~1-minute suite: this is a backstop, not a budget. + globalTimeout: 12 * 60_000, // Run the specs serially. Each spec drives a full `channel: 'chromium'` browser, and the e2e // shares an 8 GB runner with the entire compose stack (OpenZaak, NRC, Keycloak, Flowable, 4× // Postgres, every service + 3 portals). Two parallel browsers exhaust memory and the renderer is -- 2.54.0 From ab1d824e1e1c1eab7d504ca457dc7e66aecba805 Mon Sep 17 00:00:00 2001 From: Niek Otten Date: Fri, 4 Sep 2026 11:46:56 +0200 Subject: [PATCH 5/5] =?UTF-8?q?docs(ci):=20a=20killed=20job=20loses=20its?= =?UTF-8?q?=20`if:=20always()`=20steps=20=E2=80=94=20gotchas=20=C2=A79=20(?= =?UTF-8?q?refs=20#161)?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Records what #161's job metadata actually shows (steps 15-18 as 0-second failures stamped at the kill), how to read step timings via the API instead of trusting a truncated log, and the two conventions that follow: bound the work inside the tool so it can still report, and never let an auto-waiting Playwright action serve as the timeout. Co-Authored-By: Claude Opus 5 (1M context) --- docs/runbooks/gitea-actions-gotchas.md | 44 ++++++++++++++++++++++++++ 1 file changed, 44 insertions(+) diff --git a/docs/runbooks/gitea-actions-gotchas.md b/docs/runbooks/gitea-actions-gotchas.md index 8ecdfc0..e41c5cd 100644 --- a/docs/runbooks/gitea-actions-gotchas.md +++ b/docs/runbooks/gitea-actions-gotchas.md @@ -245,3 +245,47 @@ the verify-stack check table, and per-spec e2e results (`infra/playwright-summar - Getting a report out of the e2e container: Playwright writes `playwright-report.json` inside the container; `infra/run-e2e-check.sh` `docker cp`s it back to the host (capturing the test exit code first) so the summary step can read it. + +--- + +## 9. `if: always()` does not survive the job being killed — bound the work itself + +`if: always()` makes a step run when an *earlier step failed*. It does **not** help when +the job as a whole is stopped: the run's remaining steps are simply never dispatched. + +That is how #161 lost its diagnosis. `verify-stack` entered `make verify-e2e` at 09:48:17 +and the job ended at 10:14:54 — 26½ minutes later, mid-suite. Every step after the e2e +shows a **0-second `failure`** stamped at that same instant: + +``` +14 failure 09:48:17 -> 10:14:54 Self-service e2e (Playwright, login → submit → success) +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() +``` + +So the per-spec summary, the container-log dump and the teardown never ran, and the job +log — which also loses whatever the killed process had buffered — ended at a single `✘` +line. A job that dies takes its own post-mortem with it. + +**Read the step timings, not just the log.** `GET /api/v1/repos/{owner}/{repo}/actions/jobs/{id}` +returns every step with `started_at`/`completed_at`; a row of identical zero-length +steps at the end means *killed*, not *silent*. (Job ids come from +`…/actions/runs/{run}/jobs`, and that route returns only the **latest attempt** — a +re-run hides the failed one, so keep the failing job id from the original report. Logs: +`…/actions/jobs/{id}/logs`, see also `gitea-ci-logs`.) + +**Conventions that follow:** + +- **Bound long-running work inside the tool**, where it can still report. Playwright's + `globalTimeout` (`tests/e2e/playwright.config.ts`) ends the run, writes the JSON + report and exits, so the summary and log-dump steps still get their turn. A + `timeout-minutes` on the job would reproduce the very failure above. +- **Never let an auto-waiting action be the timeout.** Playwright actions (`fill`, + `click`) inherit the *test* timeout, not `expect.timeout`, so a missing element costs + the full 90 s and reports `locator.fill: Test timeout …` — the symptom. Assert the + element visible first with its own budget and a message (`tests/e2e/keycloak-login.ts`). +- Remember `concurrency.cancel-in-progress: true` in `ci.yaml`: a new push to the same + ref, or a re-run, kills the in-flight run the same way. Check `run_attempt` before + concluding a job hung. -- 2.54.0