build-watcher: guest-load liveness signal + wider silence tolerance

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

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