diff --git a/studio/backend/core/inference/llama_cpp.py b/studio/backend/core/inference/llama_cpp.py index 8054bd2a19..1874deca66 100644 --- a/studio/backend/core/inference/llama_cpp.py +++ b/studio/backend/core/inference/llama_cpp.py @@ -1010,8 +1010,8 @@ class LlamaCppBackend: self._is_vision = is_vision self._model_identifier = model_identifier - # Wait for llama-server to become healthy - if not self._wait_for_health(timeout = 120.0): + # Wait for llama-server to become healthy (no timeout — let it take as long as needed) + if not self._wait_for_health(): self._kill_process() raise RuntimeError( "llama-server failed to start. " @@ -1129,39 +1129,49 @@ class LlamaCppBackend: """atexit handler to ensure llama-server is terminated.""" self._kill_process() - def _wait_for_health(self, timeout: float = 120.0, interval: float = 0.5) -> bool: + def _wait_for_health(self, interval: float = 0.5) -> bool: """ Poll llama-server's /health endpoint until it responds 200. + No timeout — waits indefinitely so large models on slow hardware + (e.g. HF Spaces) have time to load. Logs elapsed time every 30s. Also monitors subprocess for early exit/crash. """ - deadline = time.monotonic() + timeout + start = time.monotonic() + last_log = start url = f"http://127.0.0.1:{self._port}/health" - while time.monotonic() < deadline: + while True: # Check if process crashed if self._process.poll() is not None: # Give the drain thread a moment to collect final output if self._stdout_thread is not None: self._stdout_thread.join(timeout = 2) output = "\n".join(self._stdout_lines[-50:]) + elapsed = time.monotonic() - start logger.error( - f"llama-server exited with code {self._process.returncode}. " - f"Output: {output[:2000]}" + f"llama-server exited with code {self._process.returncode} " + f"after {elapsed:.1f}s. Output: {output[:2000]}" ) return False try: resp = httpx.get(url, timeout = 2.0) if resp.status_code == 200: + elapsed = time.monotonic() - start + logger.info(f"llama-server healthy after {elapsed:.1f}s") return True except (httpx.ConnectError, httpx.TimeoutException): pass - time.sleep(interval) + # Periodic progress logging + now = time.monotonic() + if now - last_log >= 30.0: + elapsed = now - start + logger.info(f"Waiting for llama-server health check... {elapsed:.0f}s elapsed") + last_log = now - logger.error(f"llama-server health check timed out after {timeout}s") - return False + time.sleep(interval) # ── Message building (OpenAI format) ────────────────────────── diff --git a/studio/backend/core/inference/orchestrator.py b/studio/backend/core/inference/orchestrator.py index 6ff7fd2cbf..fd9bfd1cc9 100644 --- a/studio/backend/core/inference/orchestrator.py +++ b/studio/backend/core/inference/orchestrator.py @@ -262,28 +262,56 @@ class InferenceOrchestrator: except (EOFError, OSError, ValueError): return None - def _wait_response(self, expected_type: str, timeout: float = 120.0) -> dict: + def _wait_response(self, expected_type: str, timeout: Optional[float] = None) -> dict: """Block until a response of the expected type arrives. Also handles 'status' and 'error' events during the wait. Returns the matching response dict. - Raises RuntimeError on timeout or subprocess crash. + Raises RuntimeError on subprocess crash. + If timeout is None, waits indefinitely (logs progress every 30s). """ - deadline = time.monotonic() + timeout + start = time.monotonic() + last_log = start - while time.monotonic() < deadline: - remaining = max(0.1, deadline - time.monotonic()) - resp = self._read_resp(timeout = min(remaining, 1.0)) + while True: + if timeout is not None: + remaining = timeout - (time.monotonic() - start) + if remaining <= 0: + raise RuntimeError( + f"Timeout waiting for '{expected_type}' response after {timeout}s" + ) + poll_timeout = min(remaining, 1.0) + else: + poll_timeout = 1.0 + + resp = self._read_resp(timeout = poll_timeout) if resp is None: # Check subprocess health if not self._ensure_subprocess_alive(): - raise RuntimeError("Inference subprocess crashed during wait") + elapsed = time.monotonic() - start + raise RuntimeError( + f"Inference subprocess crashed during wait after {elapsed:.1f}s" + ) + # Periodic progress logging + now = time.monotonic() + if now - last_log >= 30.0: + elapsed = now - start + logger.info( + "Waiting for '%s' response... %.0fs elapsed", + expected_type, + elapsed, + ) + last_log = now continue rtype = resp.get("type", "") if rtype == expected_type: + elapsed = time.monotonic() - start + logger.info( + "Received '%s' response after %.1fs", expected_type, elapsed + ) return resp if rtype == "error": @@ -301,10 +329,6 @@ class InferenceOrchestrator: expected_type, ) - raise RuntimeError( - f"Timeout waiting for '{expected_type}' response after {timeout}s" - ) - def _drain_queue(self) -> list: """Drain all pending responses.""" events = [] @@ -614,7 +638,7 @@ class InferenceOrchestrator: needed_major, ) self._spawn_subprocess(sub_config) - resp = self._wait_response("loaded", timeout = 180) + resp = self._wait_response("loaded") # Update local state from response if resp.get("success"): diff --git a/studio/backend/core/inference/worker.py b/studio/backend/core/inference/worker.py index 2eb46f3217..432377a9b6 100644 --- a/studio/backend/core/inference/worker.py +++ b/studio/backend/core/inference/worker.py @@ -156,6 +156,7 @@ def _handle_load(backend, config: dict, resp_queue: Any) -> None: except Exception as e: logger.warning("Could not read adapter_config.json: %s", e) + load_start = time.monotonic() success = backend.load_model( config = mc, max_seq_length = config.get("max_seq_length", 2048), @@ -163,6 +164,8 @@ def _handle_load(backend, config: dict, resp_queue: Any) -> None: hf_token = hf_token, trust_remote_code = config.get("trust_remote_code", False), ) + load_elapsed = time.monotonic() - load_start + logger.info("Inference model load took %.1fs (success=%s)", load_elapsed, success) if success: # Build model_info for the parent to mirror diff --git a/studio/backend/core/training/worker.py b/studio/backend/core/training/worker.py index ccd805b7ac..31c528fbad 100644 --- a/studio/backend/core/training/worker.py +++ b/studio/backend/core/training/worker.py @@ -415,6 +415,7 @@ def run_training_process( # ── 4c. Load training model (uses VRAM — dataset already formatted) ── _send_status(event_queue, "Loading model...") + load_start = time.monotonic() success = trainer.load_model( model_name = model_name, max_seq_length = config["max_seq_length"], @@ -425,6 +426,8 @@ def run_training_process( is_dataset_audio = config.get("is_dataset_audio", False), trust_remote_code = config.get("trust_remote_code", False), ) + load_elapsed = time.monotonic() - load_start + logger.info("Training model load took %.1fs (success=%s)", load_elapsed, success) if not success or trainer.should_stop: if trainer.should_stop: event_queue.put(