MM-Embed ran on the CPU because /cache was full, and nothing said so

It reported "ready on cpu" while holding 9756 MiB of VRAM, 33 GB of host RAM
and 1100% CPU. The cause was not the model and not the GPU: /cache had reached
11 MB free of 141 GB -- 15 GB of it pip's download cache from building these
venvs, plus two 6 GB venvs put there by this code -- and HF_HOME is on that
partition, so the shard download died with

    OSError: I/O error: IO Error: No space left on device (os error 28)

the GPU load aborted part-way, and the fallback loaded the model again on the
CPU. Everything about that was invisible:

* The child's stderr was read only if it exited silently, so the reason sat in
  a pipe nobody drained -- which is also a pipe that fills, at which point the
  child blocks writing to it and looks like a model that hangs. It is now
  pumped into the engine log for the child's whole life.
* "ready on cpu" said nothing about whether the CPU was asked for or fallen
  into, and the difference is 30x and tens of GB. The fallback now carries its
  reason (gpu_error) and the parent logs it loudly.
* The aborted GPU load kept what it had already allocated for the life of the
  process: 9756 MiB that the manager's ledger could not see and nothing else
  could use. The card is now released (gc + empty_cache + ipc_collect) before
  the CPU retry.

And the placement that caused it is fixed: a NEW venv goes on the roomiest
candidate root, not the first one named. The engines' own CODERAI_CACHE_DIR is
/AI/guffcache with 197 GB free while the default cache root had 15 GB; six GB
has to go somewhere, and it should not be the fullest disk. An existing venv
still wins over a roomier empty root, so nothing is built twice.

One of this file's own tests was also writing a pointer file into the REAL
config root, naming a pytest tmpdir, which a later process would then have
resolved the venv from. Removed, and a test now fails if any test here calls
ensure_installed() without redirecting _pointer_file.
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_014T3rZozi1Ehk96NG1WesgC

codai/api/tf4_embed_server.py

@@ -121,16 +121,37 @@ def main():
     want_gpu = torch.cuda.is_available() and not force_cpu
     device = "cuda" if want_gpu else "cpu"
     quant = _quantization_config(quant_spec, torch) if want_gpu else None
+    fell_back = ""
     try:
         model = _load(model_id, family, device, quant, torch)
-    except Exception:
+    except Exception as exc:
         if device == "cpu":
             raise
         # GPU first, CPU as the fallback -- and without quantization, which
-        # bitsandbytes cannot do on the CPU anyway.
-        print(f"[tf4-embed] {model_id} would not load on the GPU; retrying on "
-              f"the CPU", file=sys.stderr, flush=True)
+        # bitsandbytes cannot do on the CPU anyway. The REASON travels with the
+        # fallback: a model quietly running on the CPU is 30x slower and tens
+        # of GB of host RAM, and "ready on cpu" alone does not say whether that
+        # was asked for or fallen into.
+        import gc
+        import traceback
+        fell_back = f"{type(exc).__name__}: {exc}"
+        print(f"[tf4-embed] {model_id} would not load on the GPU "
+              f"({fell_back}); retrying on the CPU\n{traceback.format_exc()}",
+              file=sys.stderr, flush=True)
+        # Give the card back first. A load that failed part-way has already
+        # allocated, and those allocations live in this process's CUDA context
+        # for the rest of its life -- measured on zeiss 2026-10-31, where this
+        # model held 9756 MiB of VRAM while running on the CPU, invisible to
+        # the manager's ledger and unusable by anything else.
+        try:
+            gc.collect()
+            if torch.cuda.is_available():
+                torch.cuda.empty_cache()
+                torch.cuda.ipc_collect()
+        except Exception:
+            pass
         device = "cpu"
+        quant = None
         model = _load(model_id, family, device, None, torch)
 
     def _norm(rows):
@@ -175,7 +196,8 @@ def main():
         probe = _embed({"texts": ["dimension probe"]})
     dim = int(np.asarray(probe).shape[-1])
     _say({"ready": True, "device": device, "dim": dim, "family": family,
-          "quantized": bool(quant), "transformers": transformers.__version__})
+          "quantized": bool(quant), "transformers": transformers.__version__,
+          **({"gpu_error": fell_back} if fell_back else {})})
 
     for line in sys.stdin:
         line = line.strip()

codai/api/tf4_embedders.py

@@ -270,6 +270,22 @@ def _candidate_dirs(pin: str) -> list:
     names = [f"embedders-tf-{pin}-venv"]
     if pin == "4.49.0":
         names += ["tf4-embedders-venv", "jinaclip-venv"]
+    # Roomiest root first for a venv that does not exist yet. Six GB has to go
+    # somewhere, and the cache roots are not equivalent: on zeiss the engines'
+    # CODERAI_CACHE_DIR is /AI/guffcache with 197 GB free while the default
+    # cache root had 15 GB, and building there took that partition to 11 MB
+    # free -- at which point HF_HOME, also on it, failed every download with
+    # "No space left on device" and MM-Embed fell back to the CPU. An EXISTING
+    # venv still wins over a roomier empty root: the order below is only
+    # consulted after the caller has looked for one.
+    def _free(d: Path) -> int:
+        try:
+            st = os.statvfs(d if d.exists() else d.parent)
+            return st.f_bavail * st.f_frsize
+        except Exception:
+            return 0
+
+    roots.sort(key=_free, reverse=True)
     out = []
     for root in roots:
         for name in names:
@@ -517,6 +533,21 @@ def _create_venv_on(version: str, venv: Path, say) -> Path:
     return made
 
 
+def _pump_stderr(proc: subprocess.Popen, model_id: str) -> None:
+    """Copy the child's stderr into this process's log until it closes."""
+    def _run():
+        try:
+            for line in proc.stderr:
+                line = line.rstrip()
+                if line:
+                    print(f"[tf4-embed:{model_id}] {line}", flush=True)
+        except Exception:
+            pass
+
+    threading.Thread(target=_run, daemon=True,
+                     name=f"tf4-stderr-{model_id}").start()
+
+
 def _die_with_parent():
     try:
         import ctypes
@@ -567,18 +598,23 @@ def spawn(model_id: str, device: str = "cuda", load_timeout: float = 900.0,
         stdin=subprocess.PIPE, stdout=subprocess.PIPE,
         stderr=subprocess.PIPE, env=env, text=True, bufsize=1,
         preexec_fn=_die_with_parent)
+    # Pump stderr into the engine log, in a thread, for the whole life of the
+    # child. Not only on a silent exit, which is all this used to do: a child
+    # that falls back from the GPU to the CPU says so on stderr, and MM-Embed
+    # did exactly that on zeiss 2026-10-31 -- "ready on cpu" in the log, 33 GB
+    # of host RAM, 1100% CPU, and the reason sitting unread in a pipe. A pipe
+    # nobody drains is also a pipe that fills: 64 KB of warnings and the child
+    # blocks writing to it, which looks like a model that hangs.
+    _pump_stderr(proc, model_id)
     deadline = time.time() + float(load_timeout)
     while time.time() < deadline:
         line = proc.stdout.readline()
         if not line:
-            err = ""
-            try:
-                err = (proc.stderr.read() or "")[-800:]
-            except Exception:
-                pass
+            # stderr is being pumped to the log by the thread above, so the
+            # reason is already there rather than read from the pipe here.
             raise RuntimeError(
-                f"the {spec.family} server exited while loading"
-                + (f": {err.strip()}" if err.strip() else ""))
+                f"the {spec.family} server for {model_id} exited while "
+                f"loading; its output is in the engine log")
         line = line.strip()
         if not line.startswith("{"):
             continue
@@ -589,7 +625,16 @@ def spawn(model_id: str, device: str = "cuda", load_timeout: float = 900.0,
         if msg.get("ready"):
             print(f"[tf4-embed] {model_id} ready on {msg.get('device')} "
                   f"({msg.get('dim')}-d, transformers "
-                  f"{msg.get('transformers')})", flush=True)
+                  f"{msg.get('transformers')}"
+                  + (", quantized" if msg.get("quantized") else "")
+                  + ")", flush=True)
+            if msg.get("gpu_error"):
+                # Loud, because the difference is 30x and tens of GB of host
+                # RAM: a model on the CPU because it was pinned there and a
+                # model on the CPU because the GPU load failed look identical
+                # in the log otherwise.
+                print(f"[tf4-embed] {model_id} IS ON THE CPU because the GPU "
+                      f"load failed: {msg['gpu_error']}", flush=True)
             return proc
         if msg.get("error"):
             proc.kill()

tests/test_tf4_embedders.py

@@ -36,6 +36,7 @@ import pytest
 ROOT = Path(__file__).resolve().parents[1]
 EMB = (ROOT / "codai/api/embeddings.py").read_text(encoding="utf-8")
 SERVER = (ROOT / "codai/api/tf4_embed_server.py").read_text(encoding="utf-8")
+SERVER_SRC = SERVER
 
 
 @pytest.fixture
@@ -51,12 +52,20 @@ def test_an_explicit_venv_path_wins(w, tmp_path, monkeypatch):
     assert w.resolve_venv_dir("4.49.0") == tmp_path / "v"
 
 
-def test_otherwise_it_sits_under_the_cache_root(w, tmp_path, monkeypatch):
-    """Rebuildable derived state, several GB of it -- not the config root."""
+def test_otherwise_it_sits_under_a_cache_root(w, tmp_path, monkeypatch):
+    """Rebuildable derived state, several GB of it -- not the config root.
+
+    Which cache root is a separate question (the roomiest, see below), so this
+    pins the only one on offer.
+    """
     monkeypatch.delenv("CODERAI_TF4_EMBEDDERS_VENV", raising=False)
     monkeypatch.delenv("CODERAI_JINACLIP_VENV", raising=False)
+    monkeypatch.delenv("XDG_CACHE_HOME", raising=False)
     monkeypatch.setenv("CODERAI_CACHE_DIR", str(tmp_path))
     monkeypatch.setattr(w, "_BAKED_VENV", tmp_path / "nothing-here")
+    monkeypatch.setattr(w, "_pointer_file", lambda pin: tmp_path / "none")
+    import codai.platform_paths as pp
+    monkeypatch.setattr(pp, "legacy_style_cache_root", lambda: tmp_path / "xdg")
     assert w.resolve_venv_dir("4.49.0") == tmp_path / "embedders-tf-4.49.0-venv"
 
 
@@ -288,6 +297,10 @@ def test_the_fallback_pins_mirror_the_requirements_file(w):
 def test_a_missing_requirements_file_installs_the_pins_instead(w, monkeypatch, tmp_path):
     seen = []
     monkeypatch.setattr(w, "_REQUIREMENTS", tmp_path / "not-here.txt")
+    # Into tmp_path, NOT the real config root: this test wrote a pointer file
+    # into ~/.coderai naming a pytest directory, which a later process would
+    # then have resolved the venv from.
+    monkeypatch.setattr(w, "_pointer_file", lambda pin: tmp_path / "ptr")
     monkeypatch.setattr(w, "resolve_venv_dir", lambda pin="4.49.0": tmp_path / "venv")
     monkeypatch.setattr(w.venv_env, "create_venv",
                         lambda d, **k: Path(sys.executable))
@@ -696,3 +709,103 @@ def test_the_extras_reach_the_pip_command(w, monkeypatch, tmp_path):
     w.ensure_installed("4.42.4")
     install = [c for c in cmds if "install" in c and "-U" not in c][0]
     assert "peft==0.11.1" in install and "datasets==2.20.0" in install, install
+
+
+# ── what the child says, and to whom ─────────────────────────────────────────
+
+def test_the_childs_stderr_reaches_the_log(w, capsys):
+    """A reason nobody reads is a reason nobody has. MM-Embed fell back from the
+    GPU to the CPU on zeiss 2026-10-31 — "ready on cpu" in the log, 33 GB of
+    host RAM, 1100% CPU — and said why on a stderr pipe that was only ever read
+    if the child exited silently."""
+    import io
+    import types
+    proc = types.SimpleNamespace(
+        stderr=io.StringIO("would not load on the GPU (CUDA error)\nretrying\n"))
+    w._pump_stderr(proc, "nvidia/MM-Embed")
+    import time
+    for _ in range(50):
+        if "would not load" in capsys.readouterr().out:
+            return
+        time.sleep(0.02)
+    pytest.fail("the child's stderr never reached the log")
+
+
+def test_the_pipe_is_drained_for_the_childs_whole_life():
+    """Not only on a silent exit: a pipe nobody drains fills at 64 KB and the
+    child blocks writing to it, which looks like a model that hangs."""
+    src = (ROOT / "codai/api/tf4_embedders.py").read_text(encoding="utf-8")
+    i = src.index("proc = subprocess.Popen(")
+    assert "_pump_stderr(proc, model_id)" in src[i:i + 1400]
+    # …and the failure path no longer competes with the pump for the pipe.
+    assert "proc.stderr.read()" not in src
+
+
+def test_a_cpu_fallback_is_loud_and_says_why():
+    """A model pinned to the CPU and a model that fell to it look identical in
+    the log otherwise, and the difference is 30x and tens of GB."""
+    src = (ROOT / "codai/api/tf4_embedders.py").read_text(encoding="utf-8")
+    # The phrase is split across two source lines by the f-string.
+    assert "IS ON THE CPU because the GPU " in src and "load failed" in src
+    assert "gpu_error" in SERVER_SRC and "fell_back" in SERVER_SRC
+
+
+def test_a_failed_gpu_load_gives_the_card_back():
+    """It has already allocated by the time it fails, and those allocations live
+    in the process's CUDA context for the rest of its life: measured at
+    9756 MiB held by a model that was running on the CPU, invisible to the
+    manager's ledger and unusable by anything else."""
+    i = SERVER_SRC.index("fell_back = f\"{type(exc).__name__}")
+    body = SERVER_SRC[i:i + 1200]
+    assert "empty_cache()" in body
+    assert body.index("empty_cache()") < body.index('device = "cpu"')
+
+
+def test_no_test_here_writes_into_the_real_config_root(w):
+    """One did: it ran ensure_installed() without patching _pointer_file and
+    left ~/.coderai/embedders-tf-4.49.0-venv.path naming a pytest tmpdir, which
+    a later process would have resolved the venv from."""
+    src = (ROOT / "tests/test_tf4_embedders.py").read_text(encoding="utf-8")
+    for block in src.split("\ndef test_")[1:]:
+        if "ensure_installed(" in block and "_pointer_file" not in block:
+            pytest.fail("a test calls ensure_installed() without redirecting "
+                        "_pointer_file:\n  " + block.splitlines()[0])
+
+
+def test_a_new_venv_goes_on_the_roomiest_root(w, monkeypatch, tmp_path):
+    """Six GB has to go somewhere, and the cache roots are not equivalent. On
+    zeiss the engines' CODERAI_CACHE_DIR is /AI/guffcache (197 GB free) while
+    the default cache root had 15 GB — building there took that partition to
+    11 MB free, and HF_HOME lives on it too, so every shard download failed
+    with "No space left on device" and MM-Embed fell back to the CPU."""
+    small = tmp_path / "small"
+    big = tmp_path / "big"
+    small.mkdir(); big.mkdir()
+    monkeypatch.setenv("CODERAI_CACHE_DIR", str(small))
+    monkeypatch.setenv("XDG_CACHE_HOME", str(big))
+    free = {str(small): 15 * 2**30, str(big): 400 * 2**30}
+
+    class _St:
+        f_frsize = 1
+
+        def __init__(self, n):
+            self.f_bavail = n
+
+    monkeypatch.setattr(w.os, "statvfs",
+                        lambda d: _St(free.get(str(d), 2**30)))
+    first = w._candidate_dirs("4.42.4")[0]
+    assert str(first).startswith(str(big)), first
+
+
+def test_an_existing_venv_still_wins_over_a_roomier_root(w, monkeypatch, tmp_path):
+    """Otherwise a second copy gets built beside the one already on disk."""
+    small = tmp_path / "small"
+    (small / "embedders-tf-4.42.4-venv" / "bin").mkdir(parents=True)
+    (small / "embedders-tf-4.42.4-venv" / "bin" / "python").write_text("")
+    big = tmp_path / "big"
+    big.mkdir()
+    monkeypatch.setenv("CODERAI_CACHE_DIR", str(small))
+    monkeypatch.setenv("XDG_CACHE_HOME", str(big))
+    monkeypatch.setattr(w, "_pointer_file", lambda pin: tmp_path / "none")
+    monkeypatch.setattr(w, "_BAKED_VENV", tmp_path / "nothing")
+    assert w.resolve_venv_dir("4.42.4") == small / "embedders-tf-4.42.4-venv"