bin/bench.jl reports stage 2 as a single throughput number, which can't
distinguish slow extraction from a slow spawn — and those have opposite fixes.
bin/bench_stage2.jl times each component in isolation, then times the real
handle_known_job end to end. It draws its corpus from real files (default
data/done) because random bytes make exiftool bail out early and understate the
stage by ~10x, and it prices both fork-free alternatives (batched, -stay_open)
so the cost of one-fork-per-file is a measurement rather than a guess.
The benchmark found stage 2 to be ~98% exiftool, and found two problems in
run_with_timeout, which stages 2 and 4 share:
1. The watchdog polled with sleep(0.1) and then joined the polling task, so
every call paid the remainder of an in-flight sleep after the child had
already exited: ~25 ms per file, and a measured 101 ms on a process that
exits instantly. Replaced with a one-shot Timer cancelled when the child
exits. Stage 2 goes from 164.6 ms to 138.3 ms per file (6 -> 8 files/s on one
worker); the wrapper is now within noise of a bare Base.run.
2. Writing the missing tests showed the timeout was never enforceable, in the
old implementation as much as the new. wait(proc) returns only once the
captured stdout pipe closes, and grandchildren inherit that pipe, so
signalling the child alone left the worker blocked until the whole process
tree finished on its own — a `sh -c "trap '' TERM; sleep 30"` child ran the
full 30 s against a 1 s timeout. The child now runs in its own process group
and the timeout signals the group. The trade is that a hard crash of the
server orphans an in-flight child rather than taking it down with it.
Three new tests cover the fast path, the timeout, and the SIGTERM-ignoring
escalation; the second was previously unexercised, which is why the bug stood.
Not addressed here, but measured and documented in the README: Perl interpreter
startup is 76.7 ms of the remaining 135.9 ms call, so a persistent exiftool
(-stay_open, 40.1 ms/file) would cut the stage by roughly another 70%. And
fsync_dir measures 1.75 us, too fast to be a real flush — commit_enriched!'s
durability may not hold on this filesystem, which is a correctness question
left open.
Claude-Session: https://claude.ai/code/session_01Xy9At7HNLHWNmfh1yw71Uy
Jeffrey Ward
341b61f806