I claimed 19s of the Atlas backend's CPU was work no timer accounted
for. It is not, and the 19s was an arithmetic artifact: I subtracted a
serially-measured frontend and a separately-measured gcc from a
PARALLEL build's CPU total. Mixing the two is meaningless.
Measured properly, with new coarse slots — `Stage` for the whole stage
body (so `Process - Stage` is exec + runtime init + config replay +
graph setup) and per-stage `LowerOwned`/`LowerHooks`/`LowerWrite`,
`CgGen`/`CgInit`/`CgFinish`/`CgWrite` — Atlas at batch size 16,
serially:
stage procs process wall in stage startup
frontend 180 9.90 s 0.00 s 9.90 s
lower 14 3.55 s 3.50 s 0.04 s
cg 14 3.27 s 3.23 s 0.05 s
lower: LoadClosure 756ms Owned 917ms Hooks 4ms Write 1681ms
cg: LoadClosure 548ms Gen 1912ms Init 168ms Finish 169ms Write 464ms
So the backend's nim-side work is 6.8s, not 19s, and 6.7s of it is
inside the stage bodies with 0.09s of startup across 28 processes —
batching having already removed the per-process cost that used to
dominate. The two largest items are writing the `.t.bif` (1.68s) and
cg's demand-driven generation (1.91s, of which `genProcBody` is 0.6s).
The bulk of the build is elsewhere: the frontend's 9.9s and gcc's 12.2s.
The dump line now carries `stage=<name>`, and that is not cosmetic. A
`nim m` process arms the profiler through ast2nif but never enters a
backend stage, so untagged, those 180 frontend runs put their entire
runtime in the "startup" column — which is exactly the phantom that made
the 19s look plausible in the first place.
All of it is behind `-d:icBNodeProf` and compiles to nothing without it:
ic 41/41, `koch boot -d:release` equal executables.
d680599038