204 lines
14 KiB
Markdown
204 lines
14 KiB
Markdown
# Pipeline duration: what the ten minutes were spent on
|
|
|
|
Werkbaum node: `#pipeline-duration`. This package changes how the pipeline runs, never what it
|
|
verifies. No scenario, test, assertion or acceptance artefact was removed, and the gherkin files,
|
|
the tag lists and the operations tests are untouched.
|
|
|
|
## Where the time went
|
|
|
|
Measured on the trunk build of `f20fc73`, which took 733 s, with the task boundaries read from its
|
|
own log and the per-task figures from a local Gradle profile.
|
|
|
|
| Phase | Before |
|
|
|---|---|
|
|
| `clean` and the first Gradle start-up | 18 s |
|
|
| Operations tests (Python) | 1 s |
|
|
| Code generation and compilation | 75 s |
|
|
| `test`: Chromium acceptance, 22 scenarios | 146 s |
|
|
| `test`: unit and service tests | 55 s |
|
|
| Frontend tests (Node) | under 1 s |
|
|
| Second Gradle start-up | 12 s |
|
|
| Firefox acceptance, the same 22 scenarios | 250 s |
|
|
| Production acceptance, 7 scenarios | 155 s |
|
|
| Deployment | 20 s |
|
|
|
|
Everything ran strictly one after another: one test JVM, one Cucumber thread, two Gradle
|
|
invocations. The three acceptance suites alone were 550 s, and a large part of that was lifecycle
|
|
rather than verification.
|
|
|
|
## What changed
|
|
|
|
### Three database tests migrate once per pool instead of once per file
|
|
|
|
`AccountDeletionTest`, `AccountDeletionProofsTest` and `PushSubscriptionsTest` created an H2 file
|
|
per test method and ran the whole Liquibase changelog against it. That was 57 s for 27 tests whose
|
|
assertions never mention file storage. They now use the isolated in-memory database that
|
|
`EmailAccountsTest` already used: **57.0 s to 7.5 s**, same tests, same assertions.
|
|
|
|
`H2PersistencePrototypeTest` keeps its files. It asserts that data survives separate JVM processes,
|
|
which is the one thing an in-memory database cannot show.
|
|
|
|
### One browser process for the suite instead of one per scenario
|
|
|
|
Every scenario started Playwright and a browser process and stopped both again. The isolation a
|
|
scenario needs is the browser *context*: cookies, storage, permissions and service workers all live
|
|
there. Each scenario still opens its own context, and `BrowserSteps` now records every context it
|
|
opens and closes them all in the `@After` hook, so the shared browser is left as it was found.
|
|
|
|
Measured on six Firefox scenarios, alternating baseline and change on the same machine to keep the
|
|
comparison fair: **139.5 s on average before, 126.3 s after**. The scenario teardown alone falls
|
|
from 7.3 s to 1.7 s, which is the browser process that no longer stops between scenarios.
|
|
|
|
The login artefacts are recorded by the first initial sign-in of a run instead of all seven. Six
|
|
full-page screenshots per further scenario produced identical pictures.
|
|
|
|
### The seven production scenarios run two at a time
|
|
|
|
Each scenario owns its temporary directory, its ephemeral port and its report file, so they cannot
|
|
observe one another. `productionAcceptance` passes `--threads`, default two: **216 s sequential,
|
|
167 s in pairs**. Two rather than four because every scenario starts its own 256 MB application
|
|
JVM, sometimes two, and this pipeline has already been killed once at a memory peak.
|
|
`-PproductionThreads=N` raises it when the host allows.
|
|
|
|
### One Gradle invocation for the whole JVM pipeline
|
|
|
|
`tools/ci-jvm` called Gradle twice and paid a second start-up. Both acceptance tasks already depend
|
|
on `test` and `bootJar`, so a single invocation runs the suite exactly once. The frontend tests
|
|
moved after it; they need the Node installation the production frontend build leaves behind either
|
|
way.
|
|
|
|
### Build cache
|
|
|
|
Werkator keeps `GRADLE_USER_HOME` between runs — the build log downloads nothing — so a trunk build
|
|
whose sources a branch build already compiled can take the compilation results from the cache.
|
|
`generateJooq` and `generatePrototypeJooq` opt in as well; they are functions of the changelog.
|
|
|
|
`test` is excluded on purpose. A cached pass would be an honest statement about identical inputs,
|
|
but a build that deploys should run its tests.
|
|
|
|
Checked where it has to work: a second working tree of the same commit, in a different directory,
|
|
took `compileKotlin`, `compileTestKotlin` and `compileSchemaGeneratorKotlin` from the cache and
|
|
finished in 57 s. Werkator gives each branch its own worktree, so this is exactly the trunk build
|
|
following a green branch build.
|
|
|
|
### Configuration cache
|
|
|
|
Two task actions had to stop reaching back into the build script, and the two jOOQ generators now
|
|
delete their output directories with plain file operations instead of `Project.delete`. Storing the
|
|
entry costs nothing measurable; reusing it saves the four seconds of configuration per invocation.
|
|
|
|
It brought a second effect that is worth more than the four seconds: with the configuration cache,
|
|
Gradle runs independent tasks of the same project in parallel. `firefoxAcceptance` and
|
|
`productionAcceptance` depend on `test` but not on each other, so they now overlap. In the branch
|
|
build the production suite finished at 20:19:16 while Firefox ran until about 20:22:30 — the seven
|
|
production scenarios cost the pipeline nothing at all. In the previous trunk log the two ran
|
|
strictly one after the other.
|
|
|
|
That overlap raises the peak: a Firefox process, the scenario's application, and two production
|
|
scenarios each with their own application JVM, at the same moment. If it stops holding,
|
|
`-PproductionThreads=1` is the first thing to turn down. That is not free: the production suite ran
|
|
2 minutes 51 seconds with two threads against Firefox's 4 minutes 6 seconds, so a single thread
|
|
makes it the longer of the two and costs about a minute.
|
|
|
|
The peak showed itself once, in the trunk build of 98e582d on 2026-10-03. The first Firefox
|
|
scenario's application needed 15.6 seconds to start, where every later scenario needed 1.2 to 2.4,
|
|
and the production suite was starting its own JVMs in the same seconds. The scenario then missed
|
|
Playwright's fifteen second default while waiting for the login redirect. The overlap was kept,
|
|
because werkjournal is built rarely and a minute of wall clock is worth more than a scenario that
|
|
runs under a starved host once; instead that one wait was given headroom, with the destination
|
|
unchanged. The knob above remains the answer if this repeats.
|
|
|
|
It did repeat, twice, while Werkator itself was being rebuilt and redeployed on the same host:
|
|
its version went from 1.30.4 to 1.30.5 to 1.32.0 within 45 minutes, and the trunk builds of
|
|
98e582d and 4d1f324 each failed in a different scenario, both on a timeout, both after the same
|
|
tree had passed its branch build and the local pipeline. The browser suite turned out to allow
|
|
fifteen seconds for every action but to leave assertions at Playwright's own default of five, which
|
|
no line configured. Assertions now use the same fifteen seconds, set once in the step class. No
|
|
expected value changed; a host busy with another build now costs time instead of a red build.
|
|
|
|
## An H2 defect found on the way
|
|
|
|
Switching the three tests to in-memory databases made `PushSubscriptionsTest` fail on a plain
|
|
`UPDATE app_user SET language = 'de'` with `Check constraint invalid: "CONSTRAINT_76: "`. The
|
|
schemas of the file and in-memory databases are identical, and the failure reproduces without jOOQ,
|
|
without Liquibase and without the application:
|
|
|
|
```sql
|
|
-- session 1
|
|
CREATE TABLE t (id INT, language VARCHAR(2) CHECK (language IN ('en','de')));
|
|
INSERT INTO t(id) VALUES (1);
|
|
-- session 1 closes, the database stays open
|
|
-- session 2
|
|
UPDATE t SET language = 'de' WHERE id = 1; -- Check constraint invalid
|
|
```
|
|
|
|
H2 2.4.240 leaves a check constraint over a character column unusable for every later session once
|
|
the session that created the table has closed while the database remains open. A numeric check
|
|
(`version >= 0`) is unaffected, and naming the constraint or writing it as `= 'en' OR = 'de'`
|
|
changes nothing. Closing and reopening the database repairs it, because the stored DDL is parsed
|
|
again — which is exactly why the file-backed tests never saw it: they closed between connections.
|
|
|
|
The running application is not affected in the shape it has. Its pool holds the connection that ran
|
|
Liquibase, and a pooled run of the same sequence passes on all five connections. The exposure is
|
|
narrow and real all the same: a database whose tables were created in the current process, after
|
|
that particular connection has been retired. It is worth its own decision and is not fixed here.
|
|
|
|
## Verification on 2026-09-12
|
|
|
|
Complete local pipeline on 0.1.112-SNAPSHOT with `JAVA_HOME=$HOME/opt/jdk25`.
|
|
|
|
| Run | Result |
|
|
|---|---|
|
|
| `./tools/ci-jvm` end to end, after `clean` | 673 s, every gate passed |
|
|
| Operations tests (Python) | 68 tests, OK |
|
|
| `test`, including the Chromium acceptance suite | 257 tests, 46 skipped, 0 failures |
|
|
| `firefoxAcceptance` | 22 scenarios, 146 steps, all passed |
|
|
| `productionAcceptance` | 7 scenarios, 32 steps, all passed |
|
|
| `./tools/test-frontend` | 20 tests, 0 failures |
|
|
|
|
The counts are the ones the pipeline produced before this package: 22 browser scenarios in each
|
|
engine, 7 production scenarios, 68 operations tests, 20 frontend tests.
|
|
|
|
In CI the branch job went green on `5305362` in **528 s**. The comparable runs before it are the
|
|
`ui-refresh@branch` job at 664 s and the trunk job at 733 s, the one this package measured phase by
|
|
phase. The branch job does not deploy; the trunk job adds about 20 s for that.
|
|
|
|
| Build | Before | After |
|
|
|---|---|---|
|
|
| Branch job | 664 s | 528 s |
|
|
| Trunk job, including deployment | 733 s | 447 s |
|
|
|
|
The trunk job on the merge commit `7f2e223` took **447 s** and deployed:
|
|
`{"result": "PASS", "commit": "7f2e223ac31b…", "url": "https://werkjournal.javagil.de"}`. The live
|
|
instance reports v0.1.112-SNAPSHOT. Its log shows `compileSchemaGeneratorKotlin`, `compileKotlin`
|
|
and `compileTestKotlin` `FROM-CACHE`, filled by the branch build of the same sources, and `test`
|
|
executed rather than restored — which is the arrangement this package asked for. The scenario
|
|
counts are unchanged: 68 operations tests, 22 Firefox scenarios, 7 production scenarios, 20
|
|
frontend tests.
|
|
|
|
Where the remaining 447 s go: about 200 s in the `test` task, of which the Chromium suite is the
|
|
larger half, about 250 s of Firefox acceptance that the production suite now hides inside, and
|
|
roughly 30 s of code generation, packaging and deployment. The next thing worth attacking is the
|
|
Spring context that starts once per browser scenario.
|
|
|
|
## What was deliberately not done
|
|
|
|
- The Firefox repetition stays. It found a real difference in the previous package.
|
|
- No scenario was dropped and no tag list was shortened.
|
|
- Signing in through a server fixture instead of the user interface would halve the Given steps,
|
|
but it changes what each scenario actually exercises. That is a decision about coverage, not a
|
|
speed-up.
|
|
- The Spring context still starts per scenario, about four seconds each and now the largest single
|
|
item in the browser suites. Sharing it would mean sharing the database, which is the isolation
|
|
boundary these scenarios depend on. A separate node could look at resetting the schema instead.
|
|
|
|
On 2026-10-12 the branch build of the import package failed twice without a defect in the release. The first run lost its Gradle process mid-suite ("the daemon has disappeared") with no failing test anywhere in the log, while Werkator's system page reported the machine overloaded at load 65 on three threads with 3 GiB of swap in use; the JVM tests, the Chromium suite and all seven production scenarios had already passed. The retry on a calmer host failed in two migration-rollback scenarios instead: one application start took 17.1 seconds where one to three is normal, and the next had not finished its migration after 25 seconds, so the fixture's sixty-second readiness window expired. tools/test-migration-rollback now allows three minutes for readiness, a minute for the graceful database close and a minute for its H2 shell calls, and the failed-rollback worker waits ten minutes, since raising the inner waits alone would only move the failure out to that worker. No assertion changed: the application must still become ready and close its database cleanly, and only a starved host spends the extra time.
|
|
|
|
Raising those inner waits alone did move the failure outward, as the third and fourth runs showed: the rollback step allowed the whole script 240 seconds, and Gradle stopped firefoxAcceptance at its fifteen-minute deadline. The step now allows fifteen minutes, above every wait the script performs, and the task deadline thirty. A deadline is the last resort, not a schedule.
|
|
|
|
A claim made in passing during that investigation was wrong and is corrected here: three repositories were not building at once. Werkator's repositories page showed two running builds, werkregie and werkbaum, both started at 16:35 — after this build had already ended at about 16:33, and its own row read failed, not running. The configured limit of two was respected; a snapshot taken after the fact was misread as concurrency. With one retained build per branch the history is too thin to say what else ran during the failing window. What is demonstrable is the load this pipeline makes on its own: firefoxAcceptance and productionAcceptance run concurrently by design, which puts two browser contexts and their applications against two more application JVMs of 256 MB each, plus the H2 shell JVMs, on three threads.
|
|
|
|
That is the contention the branch build now avoids. Since the second engine repeats the very scenarios the Chromium suite has already run in the same build — both cover the same twenty-two tags, with no scenario exclusive to Firefox — the branch job runs tools/ci-jvm --without-firefox and keeps every behavioural check, while the trunk job still runs everything before anything is deployed. A pull request therefore no longer gates on engine drift; the trunk build does, and a red trunk build blocks the release exactly as before. The Playwright action and assertion deadlines, fifteen seconds and separate until now, became one PATIENCE constant of thirty seconds: the same busy server answers both, and WJ-037 failed on the action side at fifteen on 2026-10-12.
|
|
|
|
The host gains a fourth thread and 4 GiB of RAM in the night to 2026-10-14, reaching about 9.8 GiB. Memory was plausibly the harder limit of the two: swap stood at 3 of 4 GiB, and a Gradle process that disappears with nothing in its log is consistent with an out-of-memory kill, though the system page recorded none. That removes the kill, but not the concurrency this pipeline asks for, so the split gate stays until it is measured rather than guessed: build a throwaway branch with the full pipeline and put its duration against the deadlines. Comfortably under ten minutes argues for putting the second engine back on the pull-request gate; otherwise the split earns its keep.
|