|
| 1 | +#!/usr/bin/env python3 |
| 2 | +"""vLLM-MLX parallel-NIAH probe (Mac bridge preset ``vllm-mlx-niah``). |
| 3 | +
|
| 4 | +Answers one question on the SAME local MLX gemma verifier we used to reproduce |
| 5 | +the MLX ``B>1, L=1`` batched-decode recall bug: **is vLLM-MLX both parallel AND |
| 6 | +recall-preserving on our config?** |
| 7 | +
|
| 8 | +It launches ``vllm-mlx serve --continuous-batching`` on the given model, fires |
| 9 | +``--sessions`` concurrent needle-in-a-haystack requests (each with its OWN unique |
| 10 | +needle, so a batching/cross-talk bug shows up as a recall drop), and reports: |
| 11 | +
|
| 12 | + * per-session recall (needle found in that session's answer), |
| 13 | + * aggregate decode tok/s at N concurrent vs an N=1 baseline (parallel speedup). |
| 14 | +
|
| 15 | +Stdlib only (urllib + threads + subprocess); vLLM-MLX is the served process. The |
| 16 | +script ALWAYS writes a verdict JSON (``status`` field) — even on install/load/ |
| 17 | +server failure — so the bridge round-trip returns a usable answer, not a crash. |
| 18 | +""" |
| 19 | + |
| 20 | +from __future__ import annotations |
| 21 | + |
| 22 | +import argparse |
| 23 | +import json |
| 24 | +import random |
| 25 | +import socket |
| 26 | +import subprocess |
| 27 | +import sys |
| 28 | +import tempfile |
| 29 | +import time |
| 30 | +import urllib.error |
| 31 | +import urllib.request |
| 32 | +from concurrent.futures import ThreadPoolExecutor |
| 33 | +from pathlib import Path |
| 34 | +from typing import Any, Dict, List, Optional, Tuple |
| 35 | + |
| 36 | + |
| 37 | +def _log(msg: str) -> None: |
| 38 | + print(f"[vllm-mlx-niah] {msg}", file=sys.stderr, flush=True) |
| 39 | + |
| 40 | + |
| 41 | +def _free_port() -> int: |
| 42 | + with socket.socket(socket.AF_INET, socket.SOCK_STREAM) as s: |
| 43 | + s.bind(("127.0.0.1", 0)) |
| 44 | + return int(s.getsockname()[1]) |
| 45 | + |
| 46 | + |
| 47 | +def _vllm_mlx_version() -> Optional[str]: |
| 48 | + try: |
| 49 | + import importlib.metadata as m |
| 50 | + |
| 51 | + return m.version("vllm-mlx") |
| 52 | + except Exception: |
| 53 | + return None |
| 54 | + |
| 55 | + |
| 56 | +def _build_niah_items(sessions: int, haystack_lines: int) -> List[Dict[str, str]]: |
| 57 | + """One independent NIAH item per session, each with a UNIQUE access code.""" |
| 58 | + rng = random.Random(1234) |
| 59 | + cities = [ |
| 60 | + "Lima", "Oslo", "Cairo", "Tokyo", "Quito", "Accra", "Riga", "Bern", |
| 61 | + "Doha", "Suva", "Male", "Kyiv", "Vienna", "Hanoi", "Sofia", "Dakar", |
| 62 | + ] |
| 63 | + items: List[Dict[str, str]] = [] |
| 64 | + for i in range(sessions): |
| 65 | + code = f"{rng.randrange(16**6):06X}" # unique 6-hex code per session |
| 66 | + filler = [ |
| 67 | + f"On day {j}, the courier from {rng.choice(cities)} logged a " |
| 68 | + f"routine delivery of crate {rng.randrange(1000)}." |
| 69 | + for j in range(max(1, haystack_lines)) |
| 70 | + ] |
| 71 | + needle = f"IMPORTANT: the access code for vault {i} is {code}." |
| 72 | + pos = rng.randrange(len(filler) + 1) |
| 73 | + filler.insert(pos, needle) |
| 74 | + prompt = ( |
| 75 | + "Read the following log carefully.\n\n" |
| 76 | + + "\n".join(filler) |
| 77 | + + f"\n\nQuestion: What is the access code for vault {i}? " |
| 78 | + "Answer with ONLY the code." |
| 79 | + ) |
| 80 | + items.append({"prompt": prompt, "code": code, "session": i}) |
| 81 | + return items |
| 82 | + |
| 83 | + |
| 84 | +def _post_chat( |
| 85 | + base_url: str, prompt: str, max_new_tokens: int, timeout: float, |
| 86 | +) -> Tuple[bool, str, int, float, str]: |
| 87 | + """POST /v1/chat/completions. Returns (ok, text, completion_tokens, latency, err).""" |
| 88 | + body = json.dumps({ |
| 89 | + "model": "default", |
| 90 | + "messages": [{"role": "user", "content": prompt}], |
| 91 | + "max_tokens": int(max_new_tokens), |
| 92 | + "temperature": 0.0, |
| 93 | + }).encode("utf-8") |
| 94 | + req = urllib.request.Request( |
| 95 | + f"{base_url}/v1/chat/completions", data=body, |
| 96 | + headers={"Content-Type": "application/json"}, method="POST", |
| 97 | + ) |
| 98 | + t0 = time.time() |
| 99 | + try: |
| 100 | + with urllib.request.urlopen(req, timeout=timeout) as resp: |
| 101 | + payload = json.loads(resp.read().decode("utf-8")) |
| 102 | + except urllib.error.HTTPError as exc: |
| 103 | + detail = exc.read().decode("utf-8", "replace")[:300] |
| 104 | + return False, "", 0, time.time() - t0, f"HTTP {exc.code}: {detail}" |
| 105 | + except Exception as exc: # noqa: BLE001 - report any transport error |
| 106 | + return False, "", 0, time.time() - t0, f"{type(exc).__name__}: {exc}" |
| 107 | + latency = time.time() - t0 |
| 108 | + try: |
| 109 | + text = payload["choices"][0]["message"]["content"] or "" |
| 110 | + except Exception: |
| 111 | + text = "" |
| 112 | + ctoks = 0 |
| 113 | + usage = payload.get("usage") or {} |
| 114 | + if isinstance(usage, dict) and isinstance(usage.get("completion_tokens"), int): |
| 115 | + ctoks = usage["completion_tokens"] |
| 116 | + if ctoks <= 0: # fallback estimate if server omits usage |
| 117 | + ctoks = max(1, len(text.split())) |
| 118 | + return True, text, ctoks, latency, "" |
| 119 | + |
| 120 | + |
| 121 | +def _wait_for_server( |
| 122 | + base_url: str, proc: subprocess.Popen, timeout: float, |
| 123 | +) -> Tuple[bool, str]: |
| 124 | + """Poll until the server answers, or it exits, or we time out.""" |
| 125 | + deadline = time.time() + timeout |
| 126 | + last = "" |
| 127 | + while time.time() < deadline: |
| 128 | + if proc.poll() is not None: |
| 129 | + return False, f"server process exited early (rc={proc.returncode})" |
| 130 | + for path in ("/version", "/v1/models", "/health"): |
| 131 | + try: |
| 132 | + with urllib.request.urlopen(base_url + path, timeout=5) as r: |
| 133 | + if r.status == 200: |
| 134 | + return True, path |
| 135 | + except Exception as exc: # noqa: BLE001 |
| 136 | + last = f"{type(exc).__name__}: {exc}" |
| 137 | + time.sleep(3) |
| 138 | + return False, f"timeout after {timeout:.0f}s (last: {last})" |
| 139 | + |
| 140 | + |
| 141 | +def _tail(path: Path, n: int = 40) -> str: |
| 142 | + try: |
| 143 | + return "\n".join(path.read_text("utf-8", "replace").splitlines()[-n:]) |
| 144 | + except Exception: |
| 145 | + return "" |
| 146 | + |
| 147 | + |
| 148 | +def main() -> int: |
| 149 | + ap = argparse.ArgumentParser(description="vLLM-MLX parallel NIAH probe") |
| 150 | + ap.add_argument("--model-path", required=True, |
| 151 | + help="Local MLX model dir (the same gemma verifier as the bug repro).") |
| 152 | + ap.add_argument("--sessions", type=int, default=8) |
| 153 | + ap.add_argument("--haystack-lines", type=int, default=60) |
| 154 | + ap.add_argument("--max-new-tokens", type=int, default=24) |
| 155 | + ap.add_argument("--server-timeout", type=float, default=900.0, |
| 156 | + help="Seconds to wait for model load + server readiness.") |
| 157 | + ap.add_argument("--req-timeout", type=float, default=300.0) |
| 158 | + ap.add_argument("--output", required=True) |
| 159 | + args = ap.parse_args() |
| 160 | + |
| 161 | + out = Path(args.output) |
| 162 | + out.parent.mkdir(parents=True, exist_ok=True) |
| 163 | + report: Dict[str, Any] = { |
| 164 | + "kind": "vllm_mlx_niah_parallel", |
| 165 | + "schema_version": 1, |
| 166 | + "status": "init", |
| 167 | + "config": { |
| 168 | + "model_path": args.model_path, |
| 169 | + "sessions": args.sessions, |
| 170 | + "haystack_lines": args.haystack_lines, |
| 171 | + "max_new_tokens": args.max_new_tokens, |
| 172 | + "engine": "vllm-mlx serve --continuous-batching --use-paged-cache", |
| 173 | + }, |
| 174 | + "vllm_mlx_version": _vllm_mlx_version(), |
| 175 | + } |
| 176 | + |
| 177 | + def _flush(status: str, **extra: Any) -> None: |
| 178 | + report["status"] = status |
| 179 | + report.update(extra) |
| 180 | + out.write_text(json.dumps(report, indent=2), encoding="utf-8") |
| 181 | + _log(f"status={status}; wrote {out}") |
| 182 | + |
| 183 | + if report["vllm_mlx_version"] is None: |
| 184 | + _flush("vllm_mlx_not_installed", |
| 185 | + error="`import importlib.metadata; version('vllm-mlx')` failed — " |
| 186 | + "the pip-install step must run before this script.") |
| 187 | + return 0 |
| 188 | + _log(f"vllm-mlx version: {report['vllm_mlx_version']}") |
| 189 | + |
| 190 | + port = _free_port() |
| 191 | + base_url = f"http://127.0.0.1:{port}" |
| 192 | + log_path = Path(tempfile.gettempdir()) / f"vllm_mlx_serve_{port}.log" |
| 193 | + serve_argv = [ |
| 194 | + "vllm-mlx", "serve", args.model_path, |
| 195 | + "--host", "127.0.0.1", "--port", str(port), |
| 196 | + "--continuous-batching", "--use-paged-cache", |
| 197 | + "--max-request-tokens", "32768", |
| 198 | + ] |
| 199 | + _log("launching: " + " ".join(serve_argv)) |
| 200 | + proc: Optional[subprocess.Popen] = None |
| 201 | + try: |
| 202 | + with open(log_path, "wb") as logf: |
| 203 | + proc = subprocess.Popen(serve_argv, stdout=logf, stderr=subprocess.STDOUT) |
| 204 | + |
| 205 | + ready, detail = _wait_for_server(base_url, proc, args.server_timeout) |
| 206 | + if not ready: |
| 207 | + _flush("server_failed", |
| 208 | + error=f"server not ready: {detail}", |
| 209 | + server_log_tail=_tail(log_path)) |
| 210 | + return 0 |
| 211 | + _log(f"server ready ({detail})") |
| 212 | + |
| 213 | + items = _build_niah_items(args.sessions, args.haystack_lines) |
| 214 | + |
| 215 | + # Warmup (lazy MLX graph compile) — not measured. |
| 216 | + _post_chat(base_url, "Reply with the word ready.", 8, args.req_timeout) |
| 217 | + |
| 218 | + # N=1 baseline (single request decode tok/s). |
| 219 | + ok0, text0, ct0, lat0, err0 = _post_chat( |
| 220 | + base_url, items[0]["prompt"], args.max_new_tokens, args.req_timeout) |
| 221 | + n1_tps = (ct0 / lat0) if (ok0 and lat0 > 0) else 0.0 |
| 222 | + |
| 223 | + # N concurrent (the parallel path — continuous batching). |
| 224 | + results: List[Optional[Tuple[bool, str, int, float, str]]] = [None] * len(items) |
| 225 | + t0 = time.time() |
| 226 | + with ThreadPoolExecutor(max_workers=len(items)) as ex: |
| 227 | + futs = { |
| 228 | + ex.submit(_post_chat, base_url, it["prompt"], |
| 229 | + args.max_new_tokens, args.req_timeout): k |
| 230 | + for k, it in enumerate(items) |
| 231 | + } |
| 232 | + for fut in futs: |
| 233 | + k = futs[fut] |
| 234 | + try: |
| 235 | + results[k] = fut.result() |
| 236 | + except Exception as exc: # noqa: BLE001 |
| 237 | + results[k] = (False, "", 0, 0.0, f"{type(exc).__name__}: {exc}") |
| 238 | + wall = max(time.time() - t0, 1e-6) |
| 239 | + |
| 240 | + per_session: List[Dict[str, Any]] = [] |
| 241 | + hits = 0 |
| 242 | + total_ctoks = 0 |
| 243 | + n_ok = 0 |
| 244 | + for k, (it, res) in enumerate(zip(items, results)): |
| 245 | + ok, text, ctoks, lat, err = res # type: ignore[misc] |
| 246 | + found = ok and (it["code"] in (text or "")) |
| 247 | + hits += 1 if found else 0 |
| 248 | + total_ctoks += ctoks if ok else 0 |
| 249 | + n_ok += 1 if ok else 0 |
| 250 | + per_session.append({ |
| 251 | + "session": it["session"], "ok": ok, "needle_found": found, |
| 252 | + "expected_code": it["code"], |
| 253 | + "answer_excerpt": (text or "")[:80], "completion_tokens": ctoks, |
| 254 | + "latency_s": round(lat, 3), "error": err, |
| 255 | + }) |
| 256 | + |
| 257 | + recall = hits / len(items) if items else 0.0 |
| 258 | + agg_tps = total_ctoks / wall |
| 259 | + _flush( |
| 260 | + "ok", |
| 261 | + recall=round(recall, 4), |
| 262 | + sessions_ok=n_ok, |
| 263 | + n1_decode_tps=round(n1_tps, 2), |
| 264 | + aggregate_decode_tps=round(agg_tps, 2), |
| 265 | + parallel_speedup_vs_n1=round(agg_tps / n1_tps, 3) if n1_tps > 0 else None, |
| 266 | + concurrent_wall_s=round(wall, 3), |
| 267 | + total_completion_tokens=total_ctoks, |
| 268 | + per_session=per_session, |
| 269 | + server_log_tail=_tail(log_path, 20), |
| 270 | + ) |
| 271 | + verdict = ( |
| 272 | + f"recall={recall:.3f} ({hits}/{len(items)}), " |
| 273 | + f"agg_decode={agg_tps:.1f} tok/s, N=1={n1_tps:.1f} tok/s, " |
| 274 | + f"parallel={'YES' if agg_tps > n1_tps else 'no-gain'}" |
| 275 | + ) |
| 276 | + _log("VERDICT: " + verdict) |
| 277 | + return 0 |
| 278 | + except Exception as exc: # noqa: BLE001 |
| 279 | + _flush("error", error=f"{type(exc).__name__}: {exc}", |
| 280 | + server_log_tail=_tail(log_path)) |
| 281 | + return 0 |
| 282 | + finally: |
| 283 | + if proc is not None and proc.poll() is None: |
| 284 | + proc.terminate() |
| 285 | + try: |
| 286 | + proc.wait(timeout=20) |
| 287 | + except Exception: |
| 288 | + proc.kill() |
| 289 | + |
| 290 | + |
| 291 | +if __name__ == "__main__": |
| 292 | + raise SystemExit(main()) |
0 commit comments