koala73 / koala73/worldmonitor
test(e2e): capture Playwright protocol logs in CI so the guid signature can be diagnosed on its next occurrence
- Dominant language
- TypeScript
- Stars
- 86.6k
- Forks
- 13.1k
- Avg merge
- 8h 4m
- Merged PRs (30d)
- 825
Description
Blocks #7880 (the `Object with guid response@… was not bound in the connection` signature). Nobody has run this on #5685, #6501, or #7837 — it is the only step that produces the evidence needed to name the cause.
**Written to be picked up cold by an agent.** All numbers below are measured, not estimated; the method is stated so they can be re-checked.
## Why this is needed
The signature has never reproduced locally (~50 runs across two sessions, including the full shard at `--workers=4 --retries=0`). It only appears on CI, where no protocol logging is captured. The open question — **did the browser die, or did the protocol reorder?** — is answerable from one line of `pw:channel` / `pw:browser` output and from nothing else currently collected.
## Measured cost (2026-09-08, `e2e/map-overlay-marker-budget.spec.ts`, 14 tests, `--workers=4 --retries=0`, macOS)
| Setting | Runtime | stderr volume |
| --- | --- | --- |
| none (baseline) | 19.5 s | — |
| `DEBUG=pw:browser` | **20.6 s** | **231 KB** |
| `DEBUG=pw:channel,pw:browser` | **34.4 s** | **21.0 MB** |
`pw:channel` costs ~75% runtime and ~21 MB **for one spec file of six**. The shard is 6 specs / 60 tests / ~3.5 min, so extrapolate ~90-130 MB raw per shard. gzip only reaches ~3.9x (21.0 MB → 5.4 MB) because the stream is high-entropy JSON carrying ANSI colour codes.
`pw:browser` is ~1 MB per shard and costs no measurable time. **These two tiers therefore need different treatment.** In the 14,277-line combined log, only 991 lines were `pw:browser` and only 55 were `__dispose__` — the diagnostic signal is a tiny fraction of the volume.
## Proposed shape
### Tier 1 — `pw:browser`, always on
Cheap enough to run on every `variant-smoke` job. Catches browser death outright, which is one of the two candidate verdicts.
Edit `.github/workflows/test.yml:787`:
```yaml
- run: |
mkdir -p pw-debug
DEBUG=pw:browser DEBUG_COLORS=0 npm run test:e2e:ci-smoke:${{ matrix.shard }} \
2> >(tee "pw-debug/browser-${{ matrix.shard }}.log" >&2)
```
and extend the existing upload at `:795` (`actions/upload-artifact` accepts a multi-line `path`):
```yaml
path: |
test-results/
pw-debug/
```
### Tier 2 — `pw:channel`, opt-in
Too expensive for every PR. Gate it behind a `workflow_dispatch` input so it can be switched on for a window when the flake is being hunted, and bound the size with a tail ring buffer — the throw kills the worker, so the **tail** is exactly the part that matters:
```yaml
env:
PW_DEBUG_SCOPES: ${{ inputs.debug_channel && 'pw:channel,pw:browser' || 'pw:browser' }}
```
```bash
DEBUG="$PW_DEBUG_SCOPES" DEBUG_COLORS=0 npm run test:e2e:ci-smoke:${{ matrix.shard }} \
2> >(tail -c 50000000 > "pw-debug/channel-${{ matrix.shard }}.log")
```
`tail -c` emits only at stream close, which is the desired behaviour and bounds the artifact at 50 MB.
### Implementation notes
- `DEBUG` output goes to **stderr**. The `list` reporter writes test results to **stdout**, so redirecting stderr does not hide test output — verify this holds before relying on it.
- Do **not** write the log into `test-results/`: Playwright clears that directory at run start. Use a sibling directory added to the upload `path`.
- `DEBUG_COLORS=0` strips ANSI escapes, which makes the log greppable and compresses better. Confirm the variable name against the bundled `debug` package version rather than trusting it.
- Process substitution (`2> >(...)`) needs bash; GitHub's default `run:` shell on ubuntu is bash, so this works, but a `shell: bash` line makes it explicit.
- Tier 2 must not become permanently on. If it ships always-on it will add ~2 minutes and ~100 MB to every PR's required job.
## How to read the log when it fires
Run these against the captured log, in order:
```bash
grep -n "was not bound in the connection" pw-debug/channel-1.log # locate the throw
grep -n "__dispose__" pw-debug/channel-1.log | tail -20 # what was disposed, and when
grep -n "pw:browser" pw-debug/channel-1.log | tail -40 # browser lifecycle around it
```
Then take the guid from the error message (`response@<32-hex>`) and trace it:
```bash
grep -n "" pw-debug/channel-1.log
```
### Decision table
| Evidence immediately before the throw | Verdict |
| --- | --- |
| `pw:browser` shows a process exit, crash, or signal — or a `[pid=N]` whose `` never arrives | **Browser death.** Pursue OOM/crash: runner memory, `--disable-dev-shm-usage` behaviour, concurrent worker count. Same root cause as #6501; resolve them together. |
| A `__dispose__` naming the page/context that owns the errored guid, with the browser still alive and closing normally afterwards | **Protocol ordering.** A serialized result raced a dispose of its subtree. No product bug; the decision becomes whether `retries: 1` stays the accepted mitigation. |
| Neither — the guid was never `__create__`d in this connection | New shape. Record it; do not force it into either bucket. |
Note that `unhandledError` (`node_modules/playwright/lib/worker/workerMain.js:144-161`) fails whichever test is current, and with `workers: 4` that test may be unrelated to the affected context. Correlate by **guid and timestamp**, never by the failing test's name.
## Non-goals
- Not a fix for the flake. This issue only makes the next occurrence diagnosable.
- Do not change `retries`, worker count, or test selection here. Those belong to #7880 and require measured evidence.
- Do not enable tier 2 permanently.
## Acceptance criteria
- [ ] Tier 1 shipped: `pw:browser` captured on every `variant-smoke` shard and present in the uploaded artifact, verified by downloading one artifact from a real run and confirming the file is non-empty.
- [ ] Measured CI cost of tier 1 reported (job duration before vs after, artifact size delta). If it exceeds ~5% runtime or ~5 MB, say so and reconsider.
- [ ] Tier 2 available behind an explicit opt-in, with a documented one-line command to trigger a run with it on.
- [ ] The reading procedure above verified against a **deliberately provoked** capture — e.g. kill the browser mid-run locally — so the decision table is known to discriminate before the real event arrives, rather than being theory.
- [ ] `.github/workflows/test.yml` change does not alter which tests run or their pass/fail semantics; the shard partition contract in `tests/deploy-config.test.mjs` still passes.
- [ ] Result linked back to #7880 when a real occurrence is captured.
https://claude.ai/code/session_016A8cnsVeV48ZuySUJN4caU
Contributor guide
Research direction
Start in .github/workflows/test.yml around lines 787-795, reviewing the variant-smoke command, shell behavior, and existing artifact upload. Verify the tiered logs with a real CI run and a deliberately provoked capture, measure runtime and artifact size, and run tests/deploy-config.test.mjs to confirm the shard contract is unchanged.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- bash, github-actions, playwright
- Domain
- ci-cd, devops, testing-qa
- Issue type
- Feature
- Difficulty
- 4/5
- Estimated time
- 3-5 days
- Activity status
- Active
- Clarity
- Clearly specified
- Newbie friendliness
- 58/100