Files
werkator/docs/prs/2026-09-15-PR#68-a-fifth-of-a-second.md
miandmhoennig 762afb589a
werkator build succeeded after 01:45
werkator/deploy build succeeded after 00:07
Cpu sample rate (#68)
Co-authored-by: mhoennig <michael@hoennig.de>
Reviewed-on: #68
2026-09-15 13:29:58 +02:00

4.1 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#67 — the measurement this corrects

The Problem

PR#67 reads a build's processor time once a second and keeps the largest reading. Everything the tree burns after the last reading is lost, because the tree is gone by the time anyone could ask again.

For a build of minutes that loss is a rounding error, which is what the PR claimed and what it checked. For a build of a second or two it is most of the figure. Its own test found this on the first CI run: a burn of about three seconds was recorded as less than one, and the assertion on whole seconds read zero.

Two smaller things came with it, both mine:

  • the CI build of the branch was red before the merge, and it was reported as ready on the strength of the local build alone;
  • the test tightened in PR#66 assumed that two builds submitted in order reach the one concurrency slot in that order, which the executor does not promise.

Non-Goals

  • No change to how the tree is walked, what is summed, or where the figure is shown.
  • No attempt to capture the final fraction exactly. That would mean reading the tree at the moment it exits, which is the one moment it cannot be read.

The Scenarios

Feature: the figure is as fine as the sampling

Scenario#68.01: A build of a second records the time it used

So that the measurement is not limited to builds that last minutes.

  • Given a build that burns processor time for about a second
  • When it ends
  • Then its recorded processor time is greater than zero, measured in milliseconds
Verified by

The Solution

The interval goes from one second to a fifth of one. The reading costs about a millisecond for a tree of a few dozen processes, so five a second is roughly half a percent of one core — the reason the cheap descent through /proc/<pid>/task/<tid>/children was chosen in the first place. The worst-case loss is now a fifth of a second: still the whole error of the method, and now small against anything one would look at.

The test asserts milliseconds rather than whole seconds, which is what the figure is.

The queue test (Scenario#65.05) had a defect of its own, and it is fixed rather than waited out. It submitted the deployment and the second build one after the other and expected them to reach the single slot in that order. They run in worker threads of their own, so whichever gets there first takes it: with the order reversed the second build ran to completion before the deployment started, and the scenario's premise — a build waiting while the deployment ends — never held. Raising the timeout would only have made that failure rarer. The second build is now enqueued once the deployment is running, which is the situation the scenario describes and the only one in which it can be observed.

A claim in the fallback path is corrected while passing: without CONFIG_PROC_CHILDREN a build records only the root process and what it has already reaped, and since the reaping happens as the build ends, that is little — not "most of it", as the comment said. The kernel on the host we run on lists children, verified directly; no host we know is on that path.

Open Questions

  • The last fraction of a second before a tree exits stays unmeasurable by this method. Making it exact would mean the JVM's own reaped-child accounting, which cannot be attributed to one build when several run at once — the trade PR#67 decided and this does not reopen.

Prerequisite PRs

Follow-up PRs

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