fix: three hangs that wedged the MCP server while it looked healthy (v2.67.1)

CHANGELOG.md

@@ -4,6 +4,66 @@ All notable changes to Code Context Control (C3) are documented here.
 The format is loosely based on [Keep a Changelog](https://keepachangelog.com/en/1.1.0/),
 and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.html).
 
+## [2.67.1] - 2026-08-07
+
+### Fixed — a startup thread could wedge the whole MCP server, silently
+
+Three separate hangs, all of which left a process that looked healthy. The
+event loop stayed alive and idle throughout, so nothing logged, nothing
+crashed, and no health check noticed; the only visible symptom was every c3
+tool call dying at the client's 120s timeout.
+
+- **`collection.delete(where=...)` never returns.** `EmbeddingIndex.build()`
+  runs on the `c3-embed-index` thread spawned from `cli/mcp_server.py` and
+  calls `_remove_file_chunks()` for each changed file. That used chromadb's
+  `delete(where={"doc_id": ...})`, which was caught wedged inside the Rust
+  bindings (`chromadb/api/rust.py`, `RustBindingsAPI._delete`): two py-spy
+  dumps four minutes apart with byte-identical frames, 0.031s of CPU over
+  3s, and no writes to `chroma.sqlite3` for ten hours. `_remove_file_chunks`
+  now resolves the ids with `get(where=...)` first and deletes by explicit
+  id, moving the metadata filtering onto the read path, which does return.
+
+  The old code already carried a get-ids-then-delete fallback, and its
+  comment already suspected the where-delete — but the fallback sat behind
+  `except`, and an `except` clause cannot catch a call that never comes
+  back. It was unreachable by construction. It is now the only path.
+
+- **An unbounded lock turned one slow call into a dead server.** `build()`
+  took `self._lock` with a bare `with` and held it across the whole build
+  loop, so the wedged delete parked every later caller behind it forever. It
+  now acquires with a timeout (`_acquire_build_lock`, mirroring the
+  `_init_lock` pattern `_ensure_ready` already used correctly), logs once at
+  WARNING, and returns a `degraded` result carrying the normal stats shape so
+  callers reading it with `.get()` defaults keep working. A redundant build
+  is worth far less than a responsive server. This is the part that makes a
+  *future* backend hang survivable instead of fatal.
+
+- **`subprocess.run(timeout=...)` hangs inside its own timeout handler.**
+  `check_gemini` / `check_codex` / `check_claude` passed `stdin=DEVNULL` and
+  `timeout=10` and hung anyway: on Windows, when the timeout fires, CPython's
+  handler kills only the direct child and then calls `communicate()` a
+  *second* time with **no timeout** (the `_mswindows` branch of `run()` in
+  `Lib/subprocess.py`). That join never completes while a surviving
+  grandchild still holds the stdout/stderr write-ends. Observed wedging the
+  `c3-delegate-prewarm` thread for 10h and leaking its two reader threads, so
+  delegate health checks never completed and every first `c3_agent` call paid
+  full preflight. All three now go through `_probe_cli_version`: Popen, a
+  `taskkill /T` process-*tree* kill, and a bounded `communicate()` in
+  `finally`. `tests/test_cli_smoke.py` documented this exact footgun for test
+  code back in 2.43.0; production code now follows the same convention.
+
+### Tests
+
+- `tests/test_embedding_index_deadlock.py` — pins the chunk-removal contract
+  (a `doc_id`'s chunks are removed without ever passing `where=` to
+  `delete`), reproduces the hang against a blocking fake collection with a
+  bounded join so a regression *fails* rather than wedging pytest, and proves
+  the busy-lock path degrades instead of blocking.
+- `tests/test_delegate_version_probe.py` — asserts the second `communicate()`
+  is bounded, that the kill is a tree kill, and that the pipes close on every
+  exit path.
+- 22 of the 26 new tests fail against the pre-fix source.
+
 ## [2.67.0] - 2026-07-31
 
 ### Added — The Discipline tab grows search, evidence, and controls (Hub)

cli/c3.py

@@ -92,7 +92,7 @@
 # Config
 CONFIG_DIR = ".c3"
 CONFIG_FILE = ".c3/config.json"
-__version__ = "2.67.0"
+__version__ = "2.67.1"
 
 
 def _compress_file_cli(compressor, path, mode="smart", **kw):

cli/tools/delegate.py

@@ -112,6 +112,60 @@ def _popen_kwargs():
     return kwargs
 
 
+def _probe_cli_version(exe: str, timeout: int = 10):
+    """Run ``<exe> --version`` without subprocess.run's timeout footgun.
+
+    ``subprocess.run(cmd, capture_output=True, timeout=N)`` reads as safe and
+    is not. When the timeout fires on Windows, CPython's own handler kills the
+    direct child and then calls ``process.communicate()`` a *second* time with
+    **no timeout** (the ``_mswindows`` branch of ``run()`` in Lib/subprocess.py).
+    That second call joins the stdout/stderr reader threads, which never see
+    EOF while any surviving grandchild still holds the pipe write-ends — so
+    ``run()`` blocks forever inside its own timeout handler. Observed wedging
+    the c3-delegate-prewarm thread for 10h and leaking its two reader threads,
+    so delegate health checks never completed and every first c3_agent call
+    paid full preflight.
+
+    Popen + a process-*tree* kill + a bounded communicate() in ``finally``
+    closes the write-ends no matter which way we leave. ``_kill_proc_tree``
+    uses ``taskkill /T`` on Windows, so grandchildren die too — the exact case
+    CPython's bare ``process.kill()`` misses.
+
+    Returns (stdout, stderr, returncode), or None if it timed out.
+    """
+    timed_out = False
+    proc = subprocess.Popen(
+        harden_win_argv([exe, "--version"]),
+        stdout=subprocess.PIPE, stderr=subprocess.PIPE,
+        stdin=subprocess.DEVNULL,
+        text=True, encoding="utf-8", errors="replace",
+        **_popen_kwargs(),
+    )
+    try:
+        try:
+            out, err = proc.communicate(timeout=timeout)
+        except subprocess.TimeoutExpired:
+            timed_out = True
+            return None
+        return (out or "").strip(), (err or "").strip(), proc.returncode
+    finally:
+        if proc.poll() is None:
+            _kill_proc_tree(proc)
+        if timed_out:
+            # Reap the reader threads with a bound. This is the call CPython
+            # makes with no timeout at all; the bound is the whole fix.
+            try:
+                proc.communicate(timeout=5)
+            except Exception:
+                pass
+            for stream in (proc.stdout, proc.stderr):
+                try:
+                    if stream is not None:
+                        stream.close()
+                except Exception:
+                    pass
+
+
 # ---------------------------------------------------------------------------
 # Codex CLI backend
 # ---------------------------------------------------------------------------
@@ -198,19 +252,16 @@ def check_claude() -> dict:
         _claude_available = False
         return {"status": "not_installed", "detail": "claude CLI not found on PATH"}
     try:
-        proc = subprocess.run(
-            [exe, "--version"],
-            capture_output=True, text=True, timeout=10,
-            stdin=subprocess.DEVNULL,
-        )
-        if proc.returncode == 0:
+        probed = _probe_cli_version(exe, timeout=10)
+        if probed is None:
+            _claude_available = False
+            return {"status": "timeout", "detail": "claude --version timed out (10s)"}
+        out, err, code = probed
+        if code == 0:
             _claude_available = True
-            return {"status": "ok", "version": proc.stdout.strip()}
-        _claude_available = False
-        return {"status": "error", "detail": proc.stderr.strip() or f"exit {proc.returncode}"}
-    except subprocess.TimeoutExpired:
+            return {"status": "ok", "version": out}
         _claude_available = False
-        return {"status": "timeout", "detail": "claude --version timed out (10s)"}
+        return {"status": "error", "detail": err or f"exit {code}"}
     except Exception as e:
         _claude_available = False
         return {"status": "error", "detail": str(e)}
@@ -286,21 +337,17 @@ def check_gemini() -> dict:
         _gemini_available = False
         return {"status": "not_installed", "detail": "gemini CLI not found on PATH"}
     try:
-        proc = subprocess.run(
-            [exe, "--version"],
-            capture_output=True, text=True, timeout=10,
-            stdin=subprocess.DEVNULL,
-        )
-        if proc.returncode == 0:
-            version = proc.stdout.strip()
+        probed = _probe_cli_version(exe, timeout=10)
+        if probed is None:
+            _gemini_available = False
+            return {"status": "timeout", "detail": "gemini --version timed out (10s)"}
+        out, err, code = probed
+        if code == 0:
             _gemini_available = True
-            return {"status": "ok", "version": version}
+            return {"status": "ok", "version": out}
         else:
             _gemini_available = False
-            return {"status": "error", "detail": proc.stderr.strip() or f"exit code {proc.returncode}"}
-    except subprocess.TimeoutExpired:
-        _gemini_available = False
-        return {"status": "timeout", "detail": "gemini --version timed out (10s)"}
+            return {"status": "error", "detail": err or f"exit code {code}"}
     except Exception as e:
         _gemini_available = False
         return {"status": "error", "detail": str(e)}
@@ -545,21 +592,17 @@ def check_codex() -> dict:
         _codex_available = False
         return {"status": "not_installed", "detail": "codex CLI not found on PATH"}
     try:
-        proc = subprocess.run(
-            [exe, "--version"],
-            capture_output=True, text=True, timeout=10,
-            stdin=subprocess.DEVNULL,
-        )
-        if proc.returncode == 0:
-            version = proc.stdout.strip()
+        probed = _probe_cli_version(exe, timeout=10)
+        if probed is None:
+            _codex_available = False
+            return {"status": "timeout", "detail": "codex --version timed out (10s)"}
+        out, err, code = probed
+        if code == 0:
             _codex_available = True
-            return {"status": "ok", "version": version}
+            return {"status": "ok", "version": out}
         else:
             _codex_available = False
-            return {"status": "error", "detail": proc.stderr.strip() or f"exit code {proc.returncode}"}
-    except subprocess.TimeoutExpired:
-        _codex_available = False
-        return {"status": "timeout", "detail": "codex --version timed out (10s)"}
+            return {"status": "error", "detail": err or f"exit code {code}"}
     except Exception as e:
         _codex_available = False
         return {"status": "error", "detail": str(e)}

pyproject.toml

@@ -4,7 +4,7 @@ build-backend = "setuptools.build_meta"
 
 [project]
 name = "code-context-control"
-version = "2.67.0"
+version = "2.67.1"
 description = "Local MCP code-intelligence for AI coding tools: surgical search/read/edit, agent-config version history, path-level access + masking guards, and a multi-project hub."
 readme = "README.md"
 requires-python = ">=3.10"

services/embedding_index.py

@@ -14,6 +14,10 @@
 
 log = logging.getLogger("c3.embedding_index")
 _SEARCH_INIT_WAIT_SECONDS = 0.25
+# Upper bound on how long a caller will park waiting for an in-flight build.
+# A redundant build is worth far less than a responsive server, so we give up
+# and degrade rather than block. See _acquire_build_lock().
+_BUILD_LOCK_WAIT_SECONDS = 30.0
 
 
 class EmbeddingIndex:
@@ -43,6 +47,7 @@ def __init__(
         self._model_ok = False
         self._file_hashes: dict[str, str] = {}  # doc_id -> content hash
         self._lock = threading.Lock()
+        self._lock_warned = False  # WARN once, not once per blocked caller
         self._chunk_map: dict[str, dict] = {}  # chunk_id -> metadata
 
         # Heavy backend init (chromadb import/client + ollama probe) and hash
@@ -169,6 +174,45 @@ def _content_hash(content: str) -> str:
 
     # ── Build / Update ────────────────────────────────────
 
+    def _acquire_build_lock(self, timeout: float | None = None) -> bool:
+        """Acquire the build lock with a bound. Mirrors ``_ensure_ready``.
+
+        An unbounded ``with self._lock`` turns any slow backend call into a
+        dead server: whoever holds the lock never returns, every later caller
+        parks behind it forever, and the MCP client kills the tool call at its
+        own timeout while the event loop still looks perfectly healthy. A
+        bounded acquire degrades instead — the caller skips the embedding work
+        and serves its request without it.
+
+        Returns True when the lock is held (caller MUST release it).
+        """
+        wait = _BUILD_LOCK_WAIT_SECONDS if timeout is None else timeout
+        if self._lock.acquire(timeout=max(0.0, wait)):
+            return True
+        if not self._lock_warned:
+            self._lock_warned = True
+            log.warning(
+                "Embedding index build lock still held after %.1fs — skipping "
+                "this build. Semantic search keeps serving whatever is already "
+                "indexed; this is logged once per index instance.",
+                wait,
+            )
+        return False
+
+    def _busy_result(self) -> dict:
+        """Build stats shaped like a normal return, marked degraded."""
+        return {
+            "error": "Embedding index busy (build already in flight); skipped",
+            "available": True,
+            "degraded": True,
+            "files_processed": 0,
+            "files_skipped": 0,
+            "chunks_embedded": 0,
+            "chunks_skipped": 0,
+            "errors": 0,
+            "total_embedded": 0,
+        }
+
     def build(self, code_index, force: bool = False, on_progress=None) -> dict:
         """Build or incrementally update the embedding index from CodeIndex chunks.
 
@@ -213,7 +257,9 @@ def _report():
                 except Exception:
                     pass
 
-        with self._lock:
+        if not self._acquire_build_lock():
+            return self._busy_result()
+        try:
             # Detect deleted files — remove their embeddings
             indexed_files = set(self._file_hashes.keys())
             current_files = set(chunks_by_file.keys())
@@ -283,6 +329,8 @@ def _report():
                 _report()
 
             self._save_hashes()
+        finally:
+            self._lock.release()
 
         return {
             "files_processed": files_processed,
@@ -311,20 +359,41 @@ def _embed_batch(self, ids: list, texts: list, metas: list) -> bool:
             return False
 
     def _remove_file_chunks(self, doc_id: str):
-        """Remove all embedded chunks belonging to a file."""
+        """Remove all embedded chunks belonging to a file.
+
+        Resolves the ids first and deletes by id. It never calls
+        ``delete(where=...)``.
+
+        ``collection.delete(where=...)`` has been observed to never return
+        inside the chromadb Rust bindings (``chromadb/api/rust.py``,
+        ``RustBindingsAPI._delete``): two py-spy dumps four minutes apart with
+        byte-identical frames, 0.031s of CPU over 3s, and no writes to
+        chroma.sqlite3 for ten hours. Because this is a *hang* and not an
+        exception, the ``except``-guarded fallback that used to live here could
+        never fire — the comment right below it already suspected the
+        where-delete, but an ``except`` clause cannot catch a thread that never
+        comes back. Worse, build() called this while holding the build lock, so
+        one wedged delete took every later caller down with it.
+
+        Deleting by explicit id keeps the metadata filtering on ``get()``,
+        which does return, and leaves ``delete()`` with the one argument shape
+        that has never been seen to stall.
+        """
         if not self._collection:
             return
         try:
-            self._collection.delete(where={"doc_id": doc_id})
-        except Exception:
-            # Some chromadb versions don't support where-delete well;
-            # fall back to getting IDs first
             try:
-                results = self._collection.get(where={"doc_id": doc_id})
-                if results and results.get("ids"):
-                    self._collection.delete(ids=results["ids"])
+                # include=[] skips fetching documents/embeddings we throw away.
+                results = self._collection.get(
+                    where={"doc_id": doc_id}, include=[])
             except Exception:
-                pass
+                # Older chromadb (we support >=0.4.24) may reject include=[].
+                results = self._collection.get(where={"doc_id": doc_id})
+            ids = (results or {}).get("ids") or []
+            if ids:
+                self._collection.delete(ids=ids)
+        except Exception as e:
+            log.debug("Removing chunks for %s failed: %s", doc_id, e)
 
     # ── Search ────────────────────────────────────────────