Files
werkator/docs/prs/2026-09-15-PR#67-what-a-build-actually-cost.md
008cd3c987
werkator build failed after 02:08
feat(build): record the processor time a build consumed (#67) (#67)
A duration cannot say whether a build worked or waited. The half hour in
which the instance could not start a single child process (PR#64) looked
like a slow half hour; a processor figure of nearly zero beside a normal
duration would have said what it was.

A sampler follows the build's process tree through the kernel's own
/proc/<pid>/task/<tid>/children once a second and keeps the largest sum
of utime+stime+cutime+cstime over the live processes, summed over the
build's commands. ProcessHandle.descendants() would have walked the whole
of /proc -- measured at 12 ms for 426 processes, and a shared hive has
thousands, for a tree of a few dozen.

Null where nothing was measured, never zero: a recorded zero reads as a
build that ran without using the processor. Shown on the build page beside
the duration with its factor against the wall clock, served as cpuSeconds.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Co-authored-by: mhoennig <michael@hoennig.de>
Reviewed-on: #67
2026-09-15 13:00:22 +02:00

6.2 KiB

WARNING: This document describes only the change applied in this PR. It may already be outdated once the next PR is merged. Historic PR-documentation is not maintained along with new PRs — treat it as a snapshot, not as current documentation.

  • PR#64 — the outage this number would have shown
  • RFC 0004 — a resource is sized by whether something waited

The Problem

Werkator records how long a build took and nothing about what it cost. Those are different questions, and the difference is exactly where the interesting failures live.

A build that takes 140 seconds instead of 95 may be doing more work, or it may be waiting — for a disk, for a core it does not get, for a lock. The duration cannot tell them apart, so every such observation ends in a guess.

The case that made this concrete: during the half hour of PR#64, the running instance could not start a single child process. Its builds looked like slow builds. A processor figure of nearly zero beside a normal duration would have said what it was, without anybody noticing a symptom first.

Non-Goals

  • No sizing advice and no health verdict is derived from the number. RFC 0004's order applies: collect first, judge later.
  • No history, no chart, no trend card. The figure is recorded per build and shown on the build's page; whether it belongs in the duration trends is a later question.
  • Not a per-command breakdown: the commands of one build are summed, exactly as their seconds are.
  • IO wait time (/proc/pressure/io) stays open; it is a host measurement, not a per-build one.

The Scenarios

Feature: what a build cost

Background

  • Linux accounts processor time per process. A build is a tree: the shell, the sandbox, the build tool, its workers.
  • /proc/<pid>/stat gives a process's own utime + stime and, in cutime + cstime, the time of the descendants it has already reaped.
  • The two never overlap: a reaped process is no longer live, and a live one is counted once.

Scenario#67.01: Time burned deep in the tree is counted

So that the figure describes the build and not the shell that started it.

  • Given a process whose grandchild burns processor time
  • When the tree is sampled while it runs
  • Then the measured time is that of the grandchild, not zero
Verified by

Scenario#67.02: A tree that is gone reports nothing, not zero

So that the end of a build is not recorded as a build that used no processor.

  • Given a process that has exited and been reaped
  • When it is sampled
  • Then the sample is null
Verified by

Scenario#67.03: A build records what its commands consumed

So that the figure is on the build, where it can be compared with its duration.

  • Given a build whose command burns processor time in a child of its shell
  • When it ends
  • Then its recorded processor time is greater than zero
Verified by

Scenario#67.04: A build too short to measure records nothing

So that an unmeasured build is not read as a free one.

  • Given a build whose command returns immediately
  • When it ends
  • Then its processor time is null, not zero
Verified by

The Solution

ProcessTreeCpuTime.sample(rootPid) descends the tree and sums, per live process, utime + stime + cutime + cstime. The descent uses the kernel's own /proc/<pid>/task/<tid>/children rather than ProcessHandle.descendants(), and that choice was measured rather than assumed: descendants() walks the whole of /proc, which costs 12 ms for the 426 processes of a developer machine and would be several thousand processes on a shared hive — for a tree of a few dozen. The children files cost one read per process of the tree, about a millisecond, once a second.

A sampler thread per command keeps the largest reading; BuildExecutor sums them over the build's commands into BuildResult.cpuTime. The sampling interval is the accuracy: what the tree burns after the last reading is lost, at most a second of it, which on a build of minutes changes no judgement. The alternative — the delta of the JVM's own cutime/cstime around waitFor, which is exact to the tick — was rejected because it attributes to the build everything the JVM reaps in that window, including other concurrent builds and the watcher's git fetch.

The field is nullable and stays null where nothing was measured: every build recorded before this, a build that never started, a host whose /proc does not account it, and a build too short for one sample. Zero would read as a build that ran without using the processor, which is a different statement.

The build page shows it beside the duration with the factor against the wall clock — 3:07 (2.4x) — because the factor is the part that says something: below one the build waited more than it worked, above one it used more than one core. GET /api/builds/… carries it as cpuSeconds.

Open Questions

  • A kernel without CONFIG_PROC_CHILDREN is handled by falling back to the root process's own figure, which covers everything it has reaped and therefore most of the build. It is logged once, and no host we run on is in that position.
  • The History table was left alone. One more column for a figure that is interesting occasionally is a poor trade; the natural home is the duration trend card, and that is its own change.

Prerequisite PRs

  • None beyond what is on main.

Follow-up PRs

  • /proc/pressure/io beside CPU and memory pressure.