report a complete load once llama-server is healthy (#6790)
* report a complete load once llama-server is healthy load_progress() derived its fraction purely from the llama-server's VmRSS over the GGUF shard total. With layers offloaded to VRAM (-ngl) the process releases the mmap'd weight pages after upload, so VmRSS sinks back well below the shard total: the fraction climbs toward ~1.0 during mmap, then collapses to a small value (~8%) once the weights are on the GPU. A fraction-driven progress bar therefore restarts and sticks there indefinitely even though the model is loaded and serving, which reads as a hang at "Starting model...". Once the server is healthy the load is complete by definition, so report fraction 1.0 (and bytes_loaded == bytes_total) in the ready phase regardless of resident set size. The VmRSS read is factored into _read_rss_bytes() with its original semantics preserved (0 on a missing VmRSS line, None when /proc is unavailable) so it can be unit-tested off Linux. Fixes #5740 * [pre-commit.ci] auto fixes from pre-commit.com hooks for more information, see https://pre-commit.ci * stub heavy deps in the load-progress test and guard a valueless VmRSS Two review fixes: 1. The new test imported core.inference.llama_cpp at module top, which pulls in loggers/structlog/httpx and fails collection with ModuleNotFoundError in the lightweight backend test env when the file is run on its own. Stub loggers, structlog and httpx via sys.modules.setdefault before the import, mirroring test_llama_cpp_load_progress_matrix.py; setdefault keeps the real modules when installed. Verified the file now collects and passes with only pytest present. 2. Catch IndexError in _read_rss_bytes: a "VmRSS:" line with no value column would make line.split()[1] raise and crash a load-progress poll. Return None instead, with a test for the valueless line. * Hold load-progress high-water mark and explain a never-healthy load (#5740) load_progress() now holds a per-process VmRSS high-water mark, so the bar no longer regresses to ~8% when -ngl offloads the weights and frees the mmap pages mid-load. A live server that never returns 200 on /health now gets a specific error (context/VRAM too large, or a local proxy/VPN intercepting the loopback probe) instead of the generic invalid-GGUF/out-of-memory message. * [pre-commit.ci] auto fixes from pre-commit.com hooks for more information, see https://pre-commit.ci --------- Co-authored-by: Hakan Baysal <hakan.baysal@trmix.com> Co-authored-by: pre-commit-ci[bot] <66853113+pre-commit-ci[bot]@users.noreply.github.com> Co-authored-by: Daniel Han <danielhanchen@gmail.com> Co-authored-by: Lee Jackson <130007945+Imagineer99@users.noreply.github.com>
This commit is contained in:
parent
d918245834
commit
abdc968e8d
4 changed files with 236 additions and 10 deletions
|
|
@ -1273,6 +1273,7 @@ class LlamaCppBackend:
|
|||
self._is_diffusion: bool = False
|
||||
self._diffusion_visual_bin: Optional[str] = None
|
||||
self._healthy = False
|
||||
self._load_rss_hwm = (None, 0) # (pid, peak VmRSS) for load_progress
|
||||
self._stats_logger = None # vLLM-style engine-stats poller, set on load
|
||||
# Set by _classify_gpu_offload after _wait_for_health.
|
||||
self._gpu_offload_active: Optional[bool] = None
|
||||
|
|
@ -1480,6 +1481,21 @@ class LlamaCppBackend:
|
|||
"""Return the model's native context length from GGUF metadata."""
|
||||
return self._context_length
|
||||
|
||||
@staticmethod
|
||||
def _read_rss_bytes(pid: int) -> Optional[int]:
|
||||
"""Resident set size of ``pid`` in bytes, from /proc/<pid>/status (Linux).
|
||||
0 when the status has no VmRSS line (zombie / kernel thread); None where
|
||||
/proc is unavailable (macOS/Windows) or the value is unreadable."""
|
||||
try:
|
||||
with open(f"/proc/{pid}/status", "r", encoding = "utf-8") as f:
|
||||
for line in f:
|
||||
if line.startswith("VmRSS:"):
|
||||
# IndexError guards a "VmRSS:" line with no value column.
|
||||
return int(line.split()[1]) * 1024 # kB -> bytes
|
||||
except (FileNotFoundError, PermissionError, ValueError, IndexError, OSError):
|
||||
return None
|
||||
return 0 # readable but no VmRSS line
|
||||
|
||||
def load_progress(self) -> Optional[dict]:
|
||||
"""Return live model-load progress, or None if not loading.
|
||||
|
||||
|
|
@ -1539,22 +1555,32 @@ class LlamaCppBackend:
|
|||
except OSError:
|
||||
pass
|
||||
|
||||
# Read VmRSS from /proc/<pid>/status (kilobytes on Linux).
|
||||
bytes_loaded = 0
|
||||
try:
|
||||
with open(f"/proc/{pid}/status", "r", encoding = "utf-8") as f:
|
||||
for line in f:
|
||||
if line.startswith("VmRSS:"):
|
||||
kb = int(line.split()[1])
|
||||
bytes_loaded = kb * 1024
|
||||
break
|
||||
except (FileNotFoundError, PermissionError, ValueError, OSError):
|
||||
# VmRSS of the llama-server; None where /proc is unavailable.
|
||||
bytes_loaded = LlamaCppBackend._read_rss_bytes(pid)
|
||||
if bytes_loaded is None:
|
||||
return None
|
||||
|
||||
# RSS climbs as weights page in, then drops once -ngl offloads them to
|
||||
# VRAM and the mmap pages are freed. Hold a per-process high-water mark
|
||||
# so the bar never regresses to ~8% mid-load (#5740).
|
||||
hwm_pid, hwm = getattr(self, "_load_rss_hwm", (None, 0))
|
||||
hwm = bytes_loaded if hwm_pid != pid else max(hwm, bytes_loaded)
|
||||
self._load_rss_hwm = (pid, hwm)
|
||||
bytes_loaded = hwm
|
||||
|
||||
phase = "ready" if self._healthy else "mmap"
|
||||
fraction = 0.0
|
||||
if bytes_total > 0:
|
||||
fraction = min(1.0, bytes_loaded / bytes_total)
|
||||
# Once llama-server is healthy the load is complete by definition. With
|
||||
# layers offloaded to VRAM (-ngl) the process releases the mmap'd weight
|
||||
# pages, so VmRSS sinks back well below the shard total; the raw RSS
|
||||
# fraction would then report a partial (~8%) load indefinitely and freeze
|
||||
# a fraction-driven progress bar even though the model is ready (#5740).
|
||||
if self._healthy:
|
||||
if bytes_total > 0:
|
||||
bytes_loaded = bytes_total
|
||||
fraction = 1.0
|
||||
return {
|
||||
"phase": phase,
|
||||
"bytes_loaded": bytes_loaded,
|
||||
|
|
@ -4232,6 +4258,17 @@ class LlamaCppBackend:
|
|||
"expected; otherwise check the llama-server log for the cause."
|
||||
)
|
||||
|
||||
# A live server that never answered 200 on /health is not a bad GGUF:
|
||||
# the load is too large for VRAM/context, or a local proxy/VPN grabbed
|
||||
# the loopback probe (#5740).
|
||||
if "health check timed out" in lowered:
|
||||
return (
|
||||
"llama-server started but never became healthy on its local "
|
||||
"/health endpoint. Try a smaller context length or a more "
|
||||
"quantized GGUF, and if you use a VPN or HTTP proxy make sure "
|
||||
"localhost bypasses it (NO_PROXY=127.0.0.1,localhost)."
|
||||
)
|
||||
|
||||
# Fallback: genuinely unknown failure (OOM, missing binary ...).
|
||||
return (
|
||||
"llama-server failed to start. "
|
||||
|
|
@ -7501,6 +7538,10 @@ class LlamaCppBackend:
|
|||
|
||||
time.sleep(interval)
|
||||
|
||||
# Leave a marker so _classify_llama_start_failure tells a live but
|
||||
# never-healthy load (too large, or a proxy hijacking the loopback
|
||||
# probe) apart from a bad GGUF (#5740).
|
||||
self._stdout_lines.append(f"llama-server health check timed out after {timeout}s")
|
||||
logger.error(f"llama-server health check timed out after {timeout}s")
|
||||
return False
|
||||
|
||||
|
|
|
|||
|
|
@ -140,6 +140,16 @@ class TestOllamaAndFallback:
|
|||
msg = _classify("", None, None)
|
||||
assert "llama-server failed to start" in msg
|
||||
|
||||
def test_health_timeout_names_probe_not_generic(self):
|
||||
# A live server that never returns 200 on /health must name the probe and
|
||||
# proxy/context causes, not blame a bad GGUF (#5740).
|
||||
msg = _classify(
|
||||
"llama-server health check timed out after 600.0s", "/models/x.gguf", "local/x"
|
||||
)
|
||||
assert "/health" in msg
|
||||
assert "NO_PROXY" in msg
|
||||
assert "GGUF file is valid" not in msg
|
||||
|
||||
|
||||
class TestOsKillReturncode:
|
||||
"""SIGKILL (-9) with no diagnostic output is the OOM killer and gets a named,
|
||||
|
|
|
|||
|
|
@ -67,6 +67,15 @@ class TestWaitForHealthResilience:
|
|||
monkeypatch.setattr(httpx, "get", lambda *a, **kw: ok_resp)
|
||||
assert b._wait_for_health(timeout = 1.0, interval = 0.01) is True
|
||||
|
||||
def test_timeout_records_marker_for_classification(self, monkeypatch):
|
||||
"""A live-but-never-healthy server leaves a marker so the failure is
|
||||
classified as a /health timeout, not a bad GGUF (#5740)."""
|
||||
b = _make_backend()
|
||||
b._process.poll.return_value = None
|
||||
monkeypatch.setattr(httpx, "get", lambda *a, **kw: mock.Mock(status_code = 503))
|
||||
assert b._wait_for_health(timeout = 0.02, interval = 0.01) is False
|
||||
assert any("health check timed out" in ln for ln in b._stdout_lines)
|
||||
|
||||
def test_read_error_loops_to_subprocess_poll(self, monkeypatch):
|
||||
"""WinError 10054 (httpx.ReadError) must be swallowed; the next iteration sees the dead subprocess and returns False with a structured exit-code log."""
|
||||
b = _make_backend()
|
||||
|
|
|
|||
166
studio/backend/tests/test_load_progress_ready_fraction.py
Normal file
166
studio/backend/tests/test_load_progress_ready_fraction.py
Normal file
|
|
@ -0,0 +1,166 @@
|
|||
# SPDX-License-Identifier: AGPL-3.0-only
|
||||
# Copyright 2026-present the Unsloth AI Inc. team. All rights reserved. See /studio/LICENSE.AGPL-3.0
|
||||
|
||||
"""load_progress() must report a complete load once llama-server is healthy.
|
||||
|
||||
With layers offloaded to VRAM (-ngl) the server releases the mmap'd weight pages
|
||||
after upload, so its VmRSS sinks back well below the shard total. The raw RSS
|
||||
fraction would then sit at a partial (~8%) value forever and freeze a
|
||||
fraction-driven progress bar even though the model is ready -- the "stuck around
|
||||
8% on the second pass" symptom in #5740. In the ready phase the fraction must be
|
||||
1.0 regardless of resident set size.
|
||||
"""
|
||||
|
||||
from __future__ import annotations
|
||||
|
||||
import io
|
||||
import sys
|
||||
import types
|
||||
from pathlib import Path
|
||||
from unittest.mock import patch
|
||||
|
||||
import pytest
|
||||
|
||||
# Stub heavy/unavailable deps before importing the module under test, so a
|
||||
# targeted run in the lightweight backend env (no structlog/httpx) still
|
||||
# collects. setdefault keeps the real modules when they are installed. Mirrors
|
||||
# test_llama_cpp_load_progress_matrix.py.
|
||||
_BACKEND_DIR = str(Path(__file__).resolve().parent.parent)
|
||||
if _BACKEND_DIR not in sys.path:
|
||||
sys.path.insert(0, _BACKEND_DIR)
|
||||
|
||||
_loggers_stub = types.ModuleType("loggers")
|
||||
_loggers_stub.get_logger = lambda name: __import__("logging").getLogger(name)
|
||||
sys.modules.setdefault("loggers", _loggers_stub)
|
||||
|
||||
sys.modules.setdefault("structlog", types.ModuleType("structlog"))
|
||||
|
||||
_httpx_stub = types.ModuleType("httpx")
|
||||
for _exc_name in (
|
||||
"ConnectError",
|
||||
"TimeoutException",
|
||||
"ReadTimeout",
|
||||
"ReadError",
|
||||
"RemoteProtocolError",
|
||||
"CloseError",
|
||||
):
|
||||
setattr(_httpx_stub, _exc_name, type(_exc_name, (Exception,), {}))
|
||||
|
||||
|
||||
class _FakeTimeout:
|
||||
def __init__(self, *a, **kw):
|
||||
pass
|
||||
|
||||
|
||||
_httpx_stub.Timeout = _FakeTimeout
|
||||
_httpx_stub.Client = type(
|
||||
"Client",
|
||||
(),
|
||||
{
|
||||
"__init__": lambda self, **kw: None,
|
||||
"__enter__": lambda self: self,
|
||||
"__exit__": lambda self, *a: None,
|
||||
},
|
||||
)
|
||||
sys.modules.setdefault("httpx", _httpx_stub)
|
||||
|
||||
from core.inference.llama_cpp import LlamaCppBackend # noqa: E402
|
||||
|
||||
|
||||
def _backend(
|
||||
gguf_path,
|
||||
*,
|
||||
healthy,
|
||||
pid = 4321,
|
||||
):
|
||||
# Bare instance: exercise load_progress() without the heavy real __init__.
|
||||
be = object.__new__(LlamaCppBackend)
|
||||
be._process = types.SimpleNamespace(pid = pid)
|
||||
be._gguf_path = str(gguf_path)
|
||||
be._healthy = healthy
|
||||
return be
|
||||
|
||||
|
||||
def _gguf(tmp_path, size_bytes):
|
||||
f = tmp_path / "model-Q4_K_M.gguf"
|
||||
f.write_bytes(b"\0" * size_bytes)
|
||||
return f
|
||||
|
||||
|
||||
def test_ready_reports_complete_despite_low_rss(tmp_path, monkeypatch):
|
||||
# Healthy, but VmRSS has dropped to ~8% of the shard total after VRAM upload.
|
||||
monkeypatch.setattr(LlamaCppBackend, "_read_rss_bytes", staticmethod(lambda pid: 800))
|
||||
be = _backend(_gguf(tmp_path, 10000), healthy = True)
|
||||
p = be.load_progress()
|
||||
assert p["phase"] == "ready"
|
||||
assert p["fraction"] == 1.0 # not 0.08
|
||||
assert p["bytes_loaded"] == p["bytes_total"] == 10000
|
||||
|
||||
|
||||
def test_mmap_phase_reports_raw_rss_fraction(tmp_path, monkeypatch):
|
||||
# Still loading: the bar should track real residency, not jump to 1.0.
|
||||
monkeypatch.setattr(LlamaCppBackend, "_read_rss_bytes", staticmethod(lambda pid: 800))
|
||||
be = _backend(_gguf(tmp_path, 10000), healthy = False)
|
||||
p = be.load_progress()
|
||||
assert p["phase"] == "mmap"
|
||||
assert p["fraction"] == 0.08
|
||||
assert p["bytes_loaded"] == 800
|
||||
assert p["bytes_total"] == 10000
|
||||
|
||||
|
||||
def test_progress_fraction_is_monotonic(tmp_path, monkeypatch):
|
||||
# RSS peaks during page-in, then drops after -ngl offload; the bar must hold
|
||||
# its high-water mark instead of collapsing back to ~8% (#5740).
|
||||
be = _backend(_gguf(tmp_path, 10000), healthy = False)
|
||||
monkeypatch.setattr(LlamaCppBackend, "_read_rss_bytes", staticmethod(lambda pid: 9000))
|
||||
assert be.load_progress()["fraction"] == 0.9
|
||||
monkeypatch.setattr(LlamaCppBackend, "_read_rss_bytes", staticmethod(lambda pid: 800))
|
||||
p = be.load_progress()
|
||||
assert p["fraction"] == 0.9
|
||||
assert p["bytes_loaded"] == 9000
|
||||
|
||||
|
||||
def test_ready_without_shard_size_still_completes(tmp_path, monkeypatch):
|
||||
# bytes_total unknown (file unstattable): fraction must still read complete.
|
||||
monkeypatch.setattr(LlamaCppBackend, "_read_rss_bytes", staticmethod(lambda pid: 800))
|
||||
be = _backend(tmp_path / "missing.gguf", healthy = True)
|
||||
p = be.load_progress()
|
||||
assert p["phase"] == "ready"
|
||||
assert p["fraction"] == 1.0
|
||||
assert p["bytes_total"] == 0
|
||||
|
||||
|
||||
def test_none_when_no_process(tmp_path):
|
||||
be = _backend(_gguf(tmp_path, 10000), healthy = True)
|
||||
be._process = None
|
||||
assert be.load_progress() is None
|
||||
|
||||
|
||||
def test_none_when_rss_unreadable(tmp_path, monkeypatch):
|
||||
# /proc unavailable (macOS/Windows) or unreadable -> no progress payload.
|
||||
monkeypatch.setattr(LlamaCppBackend, "_read_rss_bytes", staticmethod(lambda pid: None))
|
||||
be = _backend(_gguf(tmp_path, 10000), healthy = False)
|
||||
assert be.load_progress() is None
|
||||
|
||||
|
||||
def test_read_rss_bytes_absent_pid_is_none():
|
||||
# A pid with no readable /proc entry (or no /proc at all) yields None, never
|
||||
# raises.
|
||||
assert LlamaCppBackend._read_rss_bytes(2**31 - 1) is None
|
||||
|
||||
|
||||
def test_read_rss_bytes_valueless_line_is_none():
|
||||
# A "VmRSS:" line with no value column must not raise (IndexError) -> None.
|
||||
def fake_open(path, *a, **kw):
|
||||
if str(path).startswith("/proc/"):
|
||||
return io.StringIO("Name:\ttest\nVmRSS:\n")
|
||||
return open(path, *a, **kw)
|
||||
|
||||
with patch("builtins.open", side_effect = fake_open):
|
||||
assert LlamaCppBackend._read_rss_bytes(4321) is None
|
||||
|
||||
|
||||
@pytest.mark.skipif(not sys.platform.startswith("linux"), reason = "/proc is Linux-only")
|
||||
def test_read_rss_bytes_reads_self_on_linux():
|
||||
rss = LlamaCppBackend._read_rss_bytes(__import__("os").getpid())
|
||||
assert isinstance(rss, int) and rss > 0
|
||||
Loading…
Add table
Add a link
Reference in a new issue