bermudalamb
457ecbfb2b
dmesg came back empty, and the evidence that actually settles it was in the original log the whole time. Step 7 `Run migrations` succeeded, then step 9's globalSetup applied all six migrations again from scratch. Both point at the same database — migrate.js reads PGHOST/PGDATABASE and the job sets those and TEST_PG* to the same service and the same redefined_test — so had step 7 migrated it, globalSetup would have printed "No migrations to run!", which is what a local run prints. It found an empty database. The wipe was already happening before the tests started, which makes this a database being reset repeatedly rather than a container dying partway through a heavy run, and accounts cleanly for the empty dmesg: a restart is not a kill. The suspect moves from memory pressure to the runner's handling of `services:`, where act_runner has been uneven across releases. The diagnostics change with it: A3 is dropped because it was designed to catch starvation, A2 is demoted to a fallback, and the new first check needs nothing but the Gitea UI — compare step 7 and step 9's migration output in any failing run. The superseded hypothesis is kept rather than deleted. A future reader finding memory ruled out is better served by seeing why it was suspected and what refuted it than by a document that never mentions it. Refs #154
164 lines
9.3 KiB
Markdown
164 lines
9.3 KiB
Markdown
# Investigating the integration suite's schema loss in CI (#154)
|
||
|
||
A working document for the open investigation into #154. Fill in the output blocks as you go — each command has a slot beneath it and a note saying what the answer would mean. Nothing here changes the repository; it is all read-only inspection on the NAS.
|
||
|
||
## What is known
|
||
|
||
`Backend integration tests with coverage` fails in the SonarQube workflow, taking the whole job with it. Step 9 carries no `continue-on-error`, so the end-to-end run, the coverage merge and the SonarQube scan are all skipped behind it. **The SonarQube analysis has been stale since this started.**
|
||
|
||
Run 445 (job 700) failed 12 of 17 suites and 36 of 238 tests in 145 seconds.
|
||
|
||
The 36 assertion failures are misleading. They read as data-isolation problems — a category create returning 409 immediately after a truncate, an admin price filter returning eleven items instead of one, favorite-sold notifications coming back empty. Chasing those leads nowhere. The real error appears further down the same log:
|
||
|
||
```
|
||
error: relation "items" does not exist
|
||
error: relation "orders" does not exist
|
||
at resetDb (tests/integration/setup/testDb.ts:30:3)
|
||
```
|
||
|
||
`resetDb()` is not failing to clear the tables. The tables are gone.
|
||
|
||
There is a progression across the run, and it is the progression rather than any single error that identifies the problem:
|
||
|
||
1. `globalSetup` migrates successfully — all six migrations apply.
|
||
2. Early suites behave as though `TRUNCATE` had no effect: a `beforeEach` reset runs, and the next test still sees the previous test's rows.
|
||
3. Later suites cannot find the tables at all.
|
||
|
||
A schema that exists, then behaves oddly, then does not exist, across 145 seconds, is not something the test code can cause. There is no `globalTeardown`, `migrate()` runs `direction: 'up'` only, nothing anywhere issues a `DROP`, and `TRUNCATE ... CASCADE` truncates but never drops.
|
||
|
||
## What has been ruled out
|
||
|
||
Recorded so none of it is re-investigated.
|
||
|
||
| Ruled out | How |
|
||
| --- | --- |
|
||
| A code regression | The suite passes locally, 238/238 across 17 suites, using the exact CI command including `--coverage --forceExit` |
|
||
| The commit it correlates with | Failures begin at `5ef97be`, which touches only `frontend/src/cart/*` and the Playwright suite. It cannot affect backend integration tests. The correlation is real and coincidental |
|
||
| Two jobs sharing one database | The paired runs per SHA are `lint` and `sonarqube`, and on a single runner they queue rather than overlap — run 444 ended 14:18:50, run 445 started 14:18:51 |
|
||
| A mismatch between the two pools | `env.setup.ts` derives `PG*` from `TEST_PG*`, and the workflow sets both to the same service container |
|
||
|
||
## SUPERSEDED — read this first
|
||
|
||
The hypothesis below (the container dying under memory pressure) is **wrong**, and the evidence that refutes it was in the original log all along.
|
||
|
||
`dmesg` came back empty — done, A1 is complete and negative. More decisively: step 7 `Run migrations` succeeded, and then step 9's `globalSetup` applied **all six migrations again from scratch**. Both target the same database, since `migrate.js` reads `PGHOST`/`PGDATABASE` and the job points those and `TEST_PG*` at the same service and the same `redefined_test`. Had step 7 migrated it, `globalSetup` would have printed `No migrations to run!`, which is what a local run prints.
|
||
|
||
It found an empty database. **The wipe was already happening before the tests started.**
|
||
|
||
So this is not one container dying partway through a heavy run. The database is being reset repeatedly, and the schema loss the suites hit later is the same cycle coming round again. That also accounts for the empty `dmesg` — a restart is not a kill.
|
||
|
||
**The suspect is now the runner's handling of `services:`**, where `act_runner` has been uneven across releases and "the service container is recreated between steps" is a known shape. Not memory.
|
||
|
||
### What to check instead
|
||
|
||
1. **In any failing run, compare step 7 and step 9 in the Gitea UI.** Both applying all six migrations confirms the wipe outright. Step 7 applying six while step 9 says `No migrations to run!` would mean this reading is wrong and the wipe happens later.
|
||
2. **The `act_runner` version on the NAS**, and whether its config says anything about service container lifetime or reuse.
|
||
|
||
A2 below is still worth running if that comparison is inconclusive, since watching the container is the only direct observation of a restart. A3 is no longer relevant — it was designed to catch memory starvation.
|
||
|
||
## The original hypothesis, kept for the record
|
||
|
||
The Postgres service container is being lost and recreated partway through the run. A recreated `postgres:16` with an empty data directory re-initialises `POSTGRES_DB` and comes back with no schema, which is exactly what the tail of the run sees.
|
||
|
||
The runner is the NAS, which also hosts Gitea, the QA stack and production. `jest --coverage` across 17 suites is memory-hungry, the run takes 145s against a documented ~90s, and this suite already has form: `backend-integration.yml` was made `workflow_dispatch`-only after a run held the runner for 3h12m by hanging after the tests had completed.
|
||
|
||
**This is a hypothesis, not a conclusion.** It cannot be confirmed from the workflow log, which only shows the client side of the connection. If the checks below show the container healthy throughout, the hypothesis is wrong and this document should say so rather than be quietly abandoned.
|
||
|
||
---
|
||
|
||
# Action list
|
||
|
||
## Now — diagnosis
|
||
|
||
- [x] **A1.** OOM kill — **done, negative.** `dmesg` empty
|
||
- [ ] **A5.** Compare step 7 and step 9's migration output in any failing run — Gitea UI, no NAS access needed
|
||
- [ ] **A6.** Record the `act_runner` version and any service-container settings in its config
|
||
- [ ] **A2.** Watch the container live — only if A5 is inconclusive
|
||
- [ ] ~~**A3.** Memory headroom~~ — dropped; the mechanism is not starvation
|
||
|
||
## Next — depends on what A1–A3 say
|
||
|
||
- [ ] **B1.** If the service container is being recreated: pin or upgrade `act_runner`, or stop relying on `services:` and start Postgres as a step the job controls
|
||
- [ ] **B2.** If the wipe turns out to be later than step 7: fall back to A2 and watch it happen
|
||
- [ ] ~~Cap memory on the QA and production stacks~~ — dropped with the OOM hypothesis
|
||
- [ ] **B4.** Give the integration step `continue-on-error: true` so a database problem stops taking the SonarQube scan down with it
|
||
|
||
## Regardless of cause — diagnosability
|
||
|
||
- [ ] **C1.** `resetDb()` asserts the schema is present and fails with one clear message naming what is missing
|
||
- [ ] **C2.** `globalSetup` asserts the same thing immediately after migrating, so the run fails at setup rather than 90 seconds later
|
||
- [ ] **C3.** Confirm the change by dropping a table by hand and checking the message reads as "the database lost its schema" rather than as a suite full of logic errors
|
||
|
||
C1–C3 are mine to do and do not depend on the diagnosis. They only change what the failure *says*, never whether it happens.
|
||
|
||
---
|
||
|
||
# Diagnostics to run
|
||
|
||
## A1 — OOM kill
|
||
|
||
Run at any time after a failing run. This is kernel-level and survives the container being removed, which is why it comes first.
|
||
|
||
```bash
|
||
sudo dmesg -T | grep -iE "oom|killed process" | tail -20
|
||
```
|
||
|
||
**Paste output:**
|
||
|
||
```
|
||
|
||
```
|
||
|
||
**Reading it:** a line naming `postgres` or `node` at around the run's timestamp is conclusive — the hypothesis is confirmed and you can skip to B1. No output at all does not disprove it; a container can be recreated without an OOM kill, so continue to A2.
|
||
|
||
## A2 — Watch the container during a failing run
|
||
|
||
The decisive check. **Timing matters: the service container is deleted when the job finishes**, so this has to run *during* the job, not after.
|
||
|
||
Trigger the workflow (any push, or re-run one from the Gitea UI), wait for the `Backend integration tests with coverage` step to start, then run this and leave it up for the ~2½ minutes the step takes:
|
||
|
||
```bash
|
||
watch -n 5 'docker ps -a --filter "name=postgres" --format "{{.Names}}\t{{.Status}}\t{{.RunningFor}}\t{{.State}}"'
|
||
```
|
||
|
||
**Paste what you see, especially any change:**
|
||
|
||
```
|
||
|
||
```
|
||
|
||
**Reading it:**
|
||
|
||
- `Up 40 seconds` **resetting to a lower number** — the container restarted. Confirmed.
|
||
- Status showing `Restarting` or `Exited (137)` — killed, `137` meaning SIGKILL, which is what an OOM looks like. Confirmed.
|
||
- `Up` climbing steadily the whole time, never resetting — **the hypothesis is wrong.** Go to B3.
|
||
|
||
## A3 — Memory headroom
|
||
|
||
Run once while the integration step is in flight.
|
||
|
||
```bash
|
||
free -m && docker stats --no-stream --format "{{.Name}}\t{{.MemUsage}}\t{{.MemPerc}}"
|
||
```
|
||
|
||
**Paste output:**
|
||
|
||
```
|
||
|
||
```
|
||
|
||
**Reading it:** available memory near zero while both jest and postgres are running is the mechanism, and it tells us which of the other stacks to cap in B1. Comfortable headroom argues against the hypothesis even if A2 showed a restart, and would point at something recreating the container deliberately rather than it dying.
|
||
|
||
---
|
||
|
||
## If you can only do one
|
||
|
||
**A1.** It needs no timing, survives cleanup, and a positive result settles the question outright.
|
||
|
||
## Notes for the review
|
||
|
||
When you hand these back, worth saying alongside them:
|
||
|
||
- roughly how much memory the NAS has, and whether QA was up during the run
|
||
- whether the failing runs are every run now, or intermittent — the issue assumes every run since `5ef97be`, and if it is actually intermittent that changes the shape of the answer
|