Coverage for src/lilbee/providers/fleet/readback.py: 100%
94 statements
« prev ^ index » next coverage.py v7.15.2, created at 2026-08-14 11:46 +0000
1"""What the engine actually allocated, read back from its own startup report.
3Compares the planner's estimate against reality per device, and warns naming the
4role, the estimate and the reality when they diverge.
6The log is the only source. There is no API: ``llama_model_size`` is the whole
7model's weights and nothing per device, ``llama_state_get_size`` is session
8state, the per-device figures come from ``ggml_backend_buffer_get_size`` on
9handles the server never exposes, and llama-server's HTTP surface carries none of
10it (``/props`` is metadata, ``/metrics`` is token counters; both checked against
11a running server).
13The format, from upstream source:
15 src/llama-model.cpp "%s: %12s model buffer size = %8.2f MiB"
16 src/llama-kv-cache.cpp "%s: %10s KV buffer size = %8.2f MiB"
17 src/llama-context.cpp "%s: %10s compute buffer size = %8.2f MiB"
19These are format strings, not a promised interface. A bundled-engine version bump
20can break this: re-capture the fixture and confirm :func:`parse_device_buffers`
21still finds every line. A build that stops matching is reported, not swallowed
22(see :func:`check_launch`).
23"""
25from __future__ import annotations
27import logging
28import re
29from pathlib import Path
31from lilbee.providers.fleet.devices import FleetDevice
32from lilbee.providers.roles import WorkerRole
34log = logging.getLogger(__name__)
36MIB = 1024 * 1024
38# The build the checked-in fixture was captured from, named in the drift warning
39# so a report says what to compare with. Tracks the fixture, not the shipped
40# engine. A landmark, not a gate: drift is detected by the parse coming back
41# empty on a load that finished, not by a version comparison.
42VERIFIED_ENGINE_BUILD = "9310 (e2ef8fe42)"
44# "load_tensors: MTL0_Mapped model buffer size = 82.41 MiB", and its siblings.
45#
46# Matches the shape rather than a list of buffer kinds, so LoRA, RS and the
47# DeepSeek V4 state buffer parse without being enumerated here.
48#
49# The "= N MiB" is load-bearing: it excludes the three lines carrying these words
50# that are not allocations -- the self-check pair ("compute buffer size is N MiB,
51# matches expectation" / "... does not match expectation") and ggml-opencl's
52# "buffer size reduced from A to B". None uses "=".
53#
54# The device label is whatever the backend calls itself: CUDA0, MTL0, Vulkan1,
55# CPU. A timestamp and level prefix the line under --log-file, so the match is
56# not anchored to the start.
57_BUFFER_RE = re.compile(r"\S+:\s+(?P<device>\S+)\s+.*?buffer size\s*=\s*(?P<mib>[\d.]+)\s*MiB")
58# The engine names an mmapped weight buffer "<device>_Mapped" beside the same
59# device's other buffers. Same memory, so the suffix is folded away rather than
60# splitting one card's total across two keys.
61_MAPPED_SUFFIX = "_Mapped"
62# ggml names a row-split buffer "<backend>_Split", one allocation shared by every
63# card in the split rather than a device of its own.
64_SPLIT_SUFFIX = "_Split"
65# Host memory rather than a GPU, in two shapes from ggml: the CPU backend's own
66# buffers (CPU, CPU_Mapped, and AMX, which is a CPU extension), and every GPU
67# backend's pinned-host allocator, named "<backend>_Host" by ggml-cuda, -sycl,
68# -vulkan, -cann and -hip alike. Observed as CUDA_Host, Vulkan_Host, ROCm_Host.
69# None of it occupies VRAM; charging it to a card reports a phantom overrun on
70# every partially offloaded model.
71_HOST_PREFIXES = ("CPU", "AMX")
72_HOST_SUFFIX = "_Host"
75def _is_host_device(device: str) -> bool:
76 """Whether *device* names host memory rather than a GPU."""
77 return device.startswith(_HOST_PREFIXES) or device.endswith(_HOST_SUFFIX)
80def parse_device_buffers(text: str) -> dict[str, int]:
81 """Bytes the engine reported allocating, per device label, from *text*.
83 Sums the model, KV, compute and output buffers, which is the same total the
84 estimate predicts. Empty when the text carries no buffer report: a load that
85 failed before allocating, a log that has rotated past it, or an engine whose
86 verbosity is below the level that prints it.
87 """
88 totals: dict[str, int] = {}
89 for match in _BUFFER_RE.finditer(text):
90 device = match.group("device")
91 if device.endswith(_SPLIT_SUFFIX):
92 # A row-split buffer is spread across every card in the split, so it
93 # belongs to no single one. Keeping it would invent a device that the
94 # per-device comparison then reports as an unplanned allocation.
95 continue
96 device = device.removesuffix(_MAPPED_SUFFIX)
97 totals[device] = totals.get(device, 0) + int(float(match.group("mib")) * MIB)
98 return totals
101# Printed once the weights are in and slots are being wired up, so its presence
102# separates "the report is not written yet" from "this engine writes none here".
103#
104# Matches only the word the engine has kept: "initializing slots" through b9665,
105# "initializing, n_slots = N" from b9829. This gate arms the format-drift
106# warning, so pinning either exact phrase would silence the warning on the other.
107# The buffer lines held identical across all three builds; only the prose moved.
108_LOAD_FINISHED_RE = re.compile(r"load_model:\s+initializing\b")
109# "common_params_print_info: build 9310 (e2ef8fe42) with AppleClang ...", the
110# engine's own first line. Carried into the format-drift warning so the report
111# names the exact build to re-verify against.
112_BUILD_RE = re.compile(r"build\s+(?P<build>\d+)\s+\((?P<commit>[0-9a-f]+)\)")
115def engine_build(text: str) -> str:
116 """The engine build the log was written by, or empty when it does not say."""
117 match = _BUILD_RE.search(text)
118 return f"{match.group('build')} ({match.group('commit')})" if match else ""
121def load_finished(text: str) -> bool:
122 """Whether the engine got far enough to have reported its buffers."""
123 return _LOAD_FINISHED_RE.search(text) is not None
126def device_footprint(text: str) -> int:
127 """Total GPU bytes the engine reported, host buffers excluded."""
128 return sum(
129 size for device, size in parse_device_buffers(text).items() if not _is_host_device(device)
130 )
133def device_label(device: FleetDevice) -> str:
134 """The name the engine prints for *device*, and the join between the two sides.
136 ``ggml_backend_dev_name`` produces ``CUDA0`` / ``MTL0`` / ``Vulkan1``, which is
137 the same token ``--device`` and ``--tensor-split`` take and the same one the
138 buffer report is keyed by. Joining on it keeps the check out of the index-space
139 ambiguity that ``FleetDevice.from_loader`` exists to mark.
140 """
141 return f"{device.backend}{device.index}"
144def report_divergence(
145 role: WorkerRole,
146 model: str,
147 estimated_bytes: int,
148 actual_bytes: int,
149 *,
150 tolerance: float,
151) -> bool:
152 """Warn when the engine's real footprint diverges materially from the estimate.
154 Returns whether a warning was emitted, so a caller can record that this
155 instance has already been checked and not repeat it on every request.
157 Both directions are worth saying. An under-estimate is how a plan that fit on
158 paper OOMs, and it is the one that ends in a failed load. A large
159 over-estimate is quieter but costs capacity: it is why a role gets fewer
160 slots, a narrower context, or a split it did not need.
161 """
162 if estimated_bytes <= 0 or actual_bytes <= 0:
163 return False
164 ratio = actual_bytes / estimated_bytes
165 if abs(ratio - 1.0) <= tolerance:
166 return False
167 log.warning(
168 "The %s model %s allocated %.1f GiB of GPU memory but was planned for %.1f GiB "
169 "(%+.0f%%). Placement decisions for this model were made on the smaller figure; "
170 "if it fails to load or runs slowly, that gap is why.",
171 role.value,
172 model,
173 actual_bytes / 1024**3,
174 estimated_bytes / 1024**3,
175 (ratio - 1.0) * 100,
176 )
177 return True
180# The engine's own log, one per instance, beside the swap process's log. Named
181# by model id so a role's replicas do not overwrite each other.
182_ENGINE_LOG_TEMPLATE = "engine-{model_id}.log"
183# Env the engine reads for its log destination and threshold. Set through the
184# environment rather than argv: the launch is planned before the data directory
185# holding these logs is chosen, and neither affects sizing.
186#
187# Both spellings, because the engine renamed them. common/arg.cpp registers
188# LLAMA_ARG_LOG_FILE / LLAMA_ARG_LOG_VERBOSITY on master; builds around 9310 read
189# LLAMA_LOG_FILE / LLAMA_LOG_VERBOSITY. Verified against both. An unread variable
190# costs nothing; picking one produced no log at all on half the builds in use.
191ENV_LOG_FILE = "LLAMA_LOG_FILE"
192ENV_LOG_VERBOSITY = "LLAMA_LOG_VERBOSITY"
193ENV_ARG_LOG_FILE = "LLAMA_ARG_LOG_FILE"
194ENV_ARG_LOG_VERBOSITY = "LLAMA_ARG_LOG_VERBOSITY"
195# Level 4 ("trace") is where the per-device buffer report appears. Measured
196# against the bundled engine: the default 3 omits it entirely, and 5 adds a
197# per-layer and per-slot flood for the same six lines.
198LOAD_REPORT_VERBOSITY = "4"
201def engine_log_path(log_dir: Path, model_id: str) -> Path:
202 """Where the engine serving *model_id* writes its own log."""
203 return log_dir / _ENGINE_LOG_TEMPLATE.format(model_id=model_id)
206def engine_log_env(log_dir: Path, model_id: str) -> dict[str, str]:
207 """Environment that makes the engine report what it allocated, and where."""
208 path = str(engine_log_path(log_dir, model_id))
209 return {
210 ENV_LOG_FILE: path,
211 ENV_ARG_LOG_FILE: path,
212 ENV_LOG_VERBOSITY: LOAD_REPORT_VERBOSITY,
213 ENV_ARG_LOG_VERBOSITY: LOAD_REPORT_VERBOSITY,
214 }
217def check_launch(
218 log_dir: Path,
219 model_id: str,
220 role: WorkerRole,
221 model: str,
222 estimated_bytes: int,
223 est_by_device: dict[str, int] | None = None,
224 unreported_bytes: int = 0,
225) -> bool:
226 """Compare the engine's own report for *model_id* against the estimate.
228 Checked per device when *est_by_device* says what each card was planned for,
229 because per device is the only dimension the planner decides in: a split is a
230 ratio, a placement is a card, and a shortfall is recorded against a role on a
231 card. Two cards planned 50/50 that land 80/20 sum to exactly the planned
232 total, so a scalar comparison sees nothing while card 0 is the one that runs
233 out. Falls back to the total for a model the estimator could only size as one
234 number.
236 Three outcomes, and the third is the one that matters. The engine has no API
237 for any of this: /props carries no memory keys and /metrics is token
238 counters, both checked against a running server, so its log is the only
239 place these numbers exist. That makes this the one part of the fleet whose
240 input is a format nobody promises to keep.
242 So a load that finished without a readable report is reported, not swallowed.
243 Left silent it would look exactly like a correct estimate, and the check
244 would quietly become decoration the first time llama.cpp renames a line or
245 renumbers its verbosity levels. Loud, it names itself as the thing to fix.
246 """
247 try:
248 text = engine_log_path(log_dir, model_id).read_text(encoding="utf-8", errors="replace")
249 except OSError:
250 # No log at all. Usually the engine simply has not written one yet, so
251 # this is silent by default. It is also exactly what a wrong environment
252 # variable name looks like, which is how an earlier spelling went
253 # unnoticed: the check returned False forever and read as "estimate fine".
254 # report_missing_log is how a caller that knows the engine is up says so.
255 return False
256 per_device = {
257 label: size
258 for label, size in parse_device_buffers(text).items()
259 if not _is_host_device(label)
260 }
261 actual = sum(per_device.values())
262 if actual > 0 and est_by_device:
263 return _report_per_device(
264 role, model, _without_unreported(est_by_device, unreported_bytes), per_device
265 )
266 if actual <= 0:
267 if load_finished(text):
268 log.warning(
269 "The %s engine (build %s) finished loading but reported no memory usage where "
270 "lilbee reads it, so its estimate could not be checked. The engine's log format "
271 "or verbosity levels have most likely changed since build %s, which lilbee's "
272 "parser was written against; placement estimates are unverified until it is "
273 "updated to match.",
274 role.value,
275 engine_build(text) or "unknown",
276 VERIFIED_ENGINE_BUILD,
277 )
278 return False
279 return report_divergence(
280 role, model, estimated_bytes - unreported_bytes, actual, tolerance=_TOLERANCE
281 )
284def _without_unreported(est_by_device: dict[str, int], unreported: int) -> dict[str, int]:
285 """*est_by_device* less the bytes the engine allocates without reporting them.
287 Charged to the busiest device, which is where the planner put them: a vision
288 projector loads on the main GPU rather than across a split. Comparing the
289 full estimate against a report that structurally cannot contain these bytes
290 warns on every correctly sized vision load.
291 """
292 if unreported <= 0 or not est_by_device:
293 return est_by_device
294 main = max(est_by_device, key=lambda label: est_by_device[label])
295 adjusted = dict(est_by_device)
296 adjusted[main] = max(0, adjusted[main] - unreported)
297 return adjusted
300# How far the engine may land from the estimate before it is worth saying. Wide
301# enough that the estimator's normal error is quiet, narrow enough to catch the
302# whole-slot and whole-cache mistakes this exists to surface.
303_TOLERANCE = 0.25
306def _report_per_device(
307 role: WorkerRole,
308 model: str,
309 estimated: dict[str, int],
310 actual: dict[str, int],
311) -> bool:
312 """Warn about the card that diverged worst, naming both figures.
314 One warning rather than one per card: the operator needs to know the plan did
315 not hold and which card to look at, and a split that skews puts every card out
316 at once by construction.
317 """
318 worst_label, worst_gap, worst_over = "", 0.0, False
319 for label in set(estimated) | set(actual):
320 planned, landed = estimated.get(label, 0), actual.get(label, 0)
321 gap = abs(landed - planned) / planned if planned else float(landed)
322 over = landed > planned
323 # An overrun outranks an equal shortfall: a card holding more than it was
324 # planned for is the one that fails to load, while its partner holding
325 # less is only the symptom of the same skew.
326 if (over, gap) > (worst_over, worst_gap):
327 worst_label, worst_gap, worst_over = label, gap, over
328 if not worst_label or (estimated.get(worst_label) and worst_gap <= _TOLERANCE):
329 return False
330 log.warning(
331 "The %s model %s did not land where it was planned: %s holds %.1f GiB but was "
332 "planned for %.1f GiB. Placement, the tensor split and the context were all "
333 "decided per card, so a total that looks right can still overrun one of them.",
334 role.value,
335 model,
336 worst_label,
337 actual.get(worst_label, 0) / 1024**3,
338 estimated.get(worst_label, 0) / 1024**3,
339 )
340 return True
343def report_missing_log(log_dir: Path, model_id: str, role: WorkerRole) -> bool:
344 """Warn when a ready engine wrote no log where lilbee told it to.
346 Separate from :func:`check_launch` because only the caller knows the engine
347 finished loading; an absent file before that is ordinary. After it, the file
348 should exist, and its absence means the engine never accepted the settings
349 that produce it. That is a silent no-op rather than a wrong answer, which is
350 the harder kind to notice, so it is stated.
351 """
352 if engine_log_path(log_dir, model_id).exists():
353 return False
354 log.warning(
355 "The %s engine is running but wrote no log to %s, so its memory use could not "
356 "be checked against the estimate. The engine build most likely does not read "
357 "the variables lilbee sets to ask for one (%s or %s); placement estimates are "
358 "unverified until that is updated.",
359 role.value,
360 engine_log_path(log_dir, model_id),
361 ENV_LOG_FILE,
362 ENV_ARG_LOG_FILE,
363 )
364 return True