diff --git a/lib/dev/build_watcher.rb b/lib/dev/build_watcher.rb index 9039584..dcc71fb 100644 --- a/lib/dev/build_watcher.rb +++ b/lib/dev/build_watcher.rb @@ -21,12 +21,21 @@ module Dev # - exit 0 -> success # - alive, stalled (no output for # stall_after AND container CPU - # ~0%) -> a hang: kill the container and retry + # ~0% AND guest load ~0) -> a hang: kill the container and retry # - non-zero exit: # * Rosetta/clang crash sig -> a transient crash: retry # * real compile-error sig -> fail fast (don't retry) # * neither -> fail fast (surface the unknown failure) # + # Guest load matters because container CPU alone misreads I/O-bound phases: + # a build reading a big tree through virtiofs (a cold engine mount) spends + # its time in D-state while the host-side VM process does the work — the + # container's cgroup shows ~0% CPU and UBT prints nothing until the first + # action completes, which reads exactly like the deadlock. D-state processes + # count into the guest's load average, so "CPU idle but load busy" is an + # I/O-bound build to leave alone, while the real zombie-deadlock (UBT + # sleeping on a child that will never report) shows load ~0 as well. + # # Retries are capped (max_attempts) and rely on the build tool's atomic # intermediate writes, so a retry resumes incrementally rather than from scratch. # @@ -36,11 +45,16 @@ class BuildWatcher extend T::Sig # Seconds without any build output before the build is *eligible* to be judged - # stalled (combined with near-zero CPU, to avoid killing a slow-but-working - # compile action). - DEFAULT_STALL_AFTER = 300 + # stalled (combined with near-zero CPU and load, to avoid killing a + # slow-but-working compile action). Sized for the worst legitimate silence: + # a cold Win64 compile start under wine+Rosetta (prefix init + the first + # SharedPCH batch) produces no output for well over five minutes. + DEFAULT_STALL_AFTER = 900 # Container CPU percent at or below which it counts as "doing nothing". DEFAULT_CPU_FLOOR = 5.0 + # Guest 1-minute load average at or below which it counts as "doing + # nothing". One build owns the VM, so any D-state I/O work shows up here. + DEFAULT_LOAD_FLOOR = 0.5 # How often to probe liveness/CPU while the build runs. DEFAULT_POLL = 15 # Total attempts before giving up (fail fast on a genuinely broken build). @@ -75,6 +89,7 @@ class BuildWatcher # same daemon the build runs on # @param stall_after [Integer] seconds of no output before stall-eligible # @param cpu_floor [Float] CPU% at/under which counts as idle + # @param load_floor [Float] guest 1-min load at/under which counts as idle # @param poll [Integer] probe interval in seconds # @param max_attempts [Integer] retry cap # @param out [IO, StringIO] progress/diagnostic stream @@ -84,17 +99,20 @@ class BuildWatcher engine: Dev::ContainerEngine, stall_after: Integer, cpu_floor: Float, + load_floor: Float, poll: Integer, max_attempts: Integer, out: T.any(IO, StringIO), ).void end def initialize(container_name:, engine:, stall_after: DEFAULT_STALL_AFTER, cpu_floor: DEFAULT_CPU_FLOOR, - poll: DEFAULT_POLL, max_attempts: DEFAULT_MAX_ATTEMPTS, out: $stderr) + load_floor: DEFAULT_LOAD_FLOOR, poll: DEFAULT_POLL, max_attempts: DEFAULT_MAX_ATTEMPTS, + out: $stderr) @container_name = container_name @engine = engine @stall_after = stall_after @cpu_floor = cpu_floor + @load_floor = load_floor @poll = poll @max_attempts = max_attempts @out = out @@ -119,16 +137,18 @@ def run(argv) false end - # Whether a still-running build looks hung: silent long enough AND idle CPU. - # Both are required so a legitimately slow (but working) compile action — which - # keeps the CPU busy — is never killed. + # Whether a still-running build looks hung: silent long enough AND idle CPU + # AND idle guest load. All three are required so a legitimately slow (but + # working) compile action — CPU-busy, or I/O-bound in D-state where only + # the load average registers — is never killed. # # @param idle_seconds [Numeric] seconds since the last build output # @param cpu_percent [Numeric] current container CPU percent + # @param load_avg [Numeric] current guest 1-minute load average # @return [Boolean] - sig { params(idle_seconds: Numeric, cpu_percent: Numeric).returns(T::Boolean) } - def stalled?(idle_seconds:, cpu_percent:) - idle_seconds >= @stall_after && cpu_percent <= @cpu_floor + sig { params(idle_seconds: Numeric, cpu_percent: Numeric, load_avg: Numeric).returns(T::Boolean) } + def stalled?(idle_seconds:, cpu_percent:, load_avg:) + idle_seconds >= @stall_after && cpu_percent <= @cpu_floor && load_avg <= @load_floor end # Classify a failed (non-zero) run's output. Crash signatures take precedence @@ -201,7 +221,7 @@ def wait_or_kill(wait_thr, &blk) while wait_thr.alive? sleep @poll next unless wait_thr.alive? - next unless stalled?(idle_seconds: yield, cpu_percent: container_cpu) + next unless stalled?(idle_seconds: yield, cpu_percent: container_cpu, load_avg: container_load) kill_container wait_thr.join @@ -221,6 +241,19 @@ def container_cpu out.strip.delete("%").to_f end + # Guest 1-minute load average, read from inside the container. /proc/loadavg + # is kernel-global, so this is the whole VM's load — the right scope, since + # one build owns the VM and D-state virtiofs I/O (invisible to the cgroup + # CPU stat) counts into it. Best-effort like container_cpu: an unreadable + # value reports as idle so a truly dead container can still be reclaimed. + # + # @return [Float] + sig { returns(Float) } + def container_load + out = @engine.capture(["exec", @container_name, "cat", "/proc/loadavg"]) + out.split.first.to_f + end + # @return [void] sig { void } def kill_container diff --git a/test/dev/build_watcher_test.rb b/test/dev/build_watcher_test.rb index fd00524..bd991bf 100644 --- a/test/dev/build_watcher_test.rb +++ b/test/dev/build_watcher_test.rb @@ -48,14 +48,23 @@ def result(outcome, output = "") Dev::BuildWatcher::Result.new(outcome, output) end - test "stalled? is true only when both silent long enough and idle CPU" do + test "stalled? is true only when silent long enough, idle CPU, and idle load" do Given "a watcher with default thresholds" w = watcher - Expect "silent + idle is a stall; busy CPU or recent output is not" - w.stalled?(idle_seconds: 400, cpu_percent: 0.0) == true - w.stalled?(idle_seconds: 400, cpu_percent: 80.0) == false - w.stalled?(idle_seconds: 10, cpu_percent: 0.0) == false + Expect "all three signals idle is a stall; any sign of life is not" + w.stalled?(idle_seconds: 400, cpu_percent: 0.0, load_avg: 0.0) == true + w.stalled?(idle_seconds: 400, cpu_percent: 80.0, load_avg: 0.0) == false + w.stalled?(idle_seconds: 10, cpu_percent: 0.0, load_avg: 0.0) == false + w.stalled?(idle_seconds: 400, cpu_percent: 0.0, load_avg: 8.0) == false + end + + test "stalled? treats I/O-bound builds (idle CPU, busy load) as alive" do + Given "a watcher with default thresholds" + w = watcher + + Expect "virtiofs-bound compile starts: container CPU ~0 but D-state work keeps load up" + w.stalled?(idle_seconds: 2000, cpu_percent: 1.0, load_avg: 3.2) == false end test "classify_failure retries on a Rosetta/clang crash signature" do @@ -221,6 +230,39 @@ def result(outcome, output = "") FileUtils.rm_rf(tmpdir) end + test "container_load parses the 1-minute load average from /proc/loadavg" do + Given "a fake docker whose exec reports a loadavg line" + tmpdir = Dir.mktmpdir("bw-fake-docker-") + fake_docker = File.join(tmpdir, "docker") + File.write(fake_docker, "#!/bin/sh\nprintf '3.36 2.90 2.50 4/1290 12345\\n'\n") + FileUtils.chmod(0o755, fake_docker) + original_path = ENV["PATH"] + ENV["PATH"] = "#{tmpdir}:#{original_path}" + w = watcher + + Expect "the first field is parsed as a Float" + w.send(:container_load) == 3.36 + + Cleanup + ENV["PATH"] = original_path + FileUtils.rm_rf(tmpdir) + end + + test "container_load reports idle when docker cannot be executed at all" do + Given "a PATH with no docker" + tmpdir = Dir.mktmpdir("bw-empty-path-") + original_path = ENV["PATH"] + ENV["PATH"] = tmpdir + w = watcher + + Expect "the unreadable value counts as idle so a dead container is reclaimable" + w.send(:container_load) == 0.0 + + Cleanup + ENV["PATH"] = original_path + FileUtils.rm_rf(tmpdir) + end + test "now returns a monotonic Float for stall timing" do Given "a watcher" w = watcher