diff --git a/.gitignore b/.gitignore index 60df8bc7e..aeea20569 100644 --- a/.gitignore +++ b/.gitignore @@ -44,3 +44,7 @@ webpage/site/node_modules/ # Host-specific and reactive to local memory conditions, so it never belongs # in version control alongside the tracked benchmarks/*.csv result files. /benchmarks/.oom-record + +# Raw qmv-wide-pin measurement runs written by scripts/bench_qmv_wide_pin.sh +# (issue #1261). Curated results belong in docs/benchmark_results/. +/bench-results/ diff --git a/TECHNICAL_REPORTS/1278-qmv-wide-pin-tax-measurement-20260822.en.md b/TECHNICAL_REPORTS/1278-qmv-wide-pin-tax-measurement-20260822.en.md new file mode 100644 index 000000000..fca75e42a --- /dev/null +++ b/TECHNICAL_REPORTS/1278-qmv-wide-pin-tax-measurement-20260822.en.md @@ -0,0 +1,92 @@ +# Technical Report: PR #1278 - Pricing the qmv_wide narrow pin's collateral + +## Executive Summary + +Issue #1261 asked what the rest of a server process pays when the MTP exactness gate disables `qmv_wide` for the whole process to buy back temperature-0 byte-identity. The issue was deliberately measurement-gated ("nothing below is worth building until the collateral cost is a number") and carried an explicit exit condition: if the tax is small on production shapes, document it and stop. + +This PR takes that exit. It changes no Rust source. It adds two benchmark harnesses, records the measurement on the required Apple GPU generation 15 host, and corrects three documents whose `MLXCEL_MTP_ALLOW_INEXACT` recipe went stale when #1199 changed the gate's ordering. + +The measured answer is that the batched-decode tax is at most 1%, and the reason is structural rather than numerical: neither MTP family dispatches the `M = B` projection the issue assumed. The real collateral cost is one prompt-cache-adopted suffix prefill per request, +15.4 ms per forward on the Gemma target and +12.6 ms on the Qwen target. + +## 1. Problem Statement + +PR #1199 gave the exactness gate a retry: when the multi-token verify block diverges from the single-token decode chain under `qmv_wide`, the gate turns `qmv_wide` off and re-probes, and keeps it off for the rest of the process when that restores byte-identity. The switch is deliberately never restored, because re-enabling it would break the very block the gate just approved. + +But the switch is process-wide. It sits on the dispatch path of every quantized matmul in `dispatch_qmv`, so a server sharing the process pays it on work that never asked for byte-identity. #1199 said so explicitly and filed the scoping work as follow-up. #1261 is that follow-up, and its first step was to find out whether the collateral cost is large enough to justify the surgery. + +The verify-side cost was already priced (17 to 20% on the Qwen verify forward, about 23% on the Gemma 4 verify forward). What the bystanders pay had never been measured. + +## 2. What Was Measured + +Two arms on a Mac Studio M3 Ultra (`applegpu_g15d`, generation 15, macOS 26.6.1), under `scripts/with_indexers_paused.sh` with Time Machine off. + +**Arm 1, batched-decode B-sweep with no drafter.** Throughput at B = 1, 2, 4, 8 with `MLXCEL_QMV_WIDE=1` pinned against `MLXCEL_QMV_WIDE=0` pinned, on `models/gemma-4-31b-it-4bit`, confirmed on `models/qwen3.8-27b-4bit`. Eight boots in two balanced ABBA blocks, one discarded warm-up pass and two measured passes per boot, giving 8 samples per arm per cell (4 on the Qwen confirmation). Result: 0.0 to 0.9% on Gemma, 0.0 to 0.2% on Qwen, every spread at or under 1% against the harness's 4% trust limit. + +**Arm 2, mixed workload.** One MTP stream holding the tick-slice speculative slot plus four classic streams on the Qwen MTP pairing, arm A being the default env where the gate's retry pins the process narrow and arm B being `MLXCEL_QMV_WIDE=1 MLXCEL_MTP_ALLOW_INEXACT=1`. Only the classic streams' decode rates are read. Result: the classic streams lose 0.1% to 2.6%, and the loss tracks the MTP stream's own verify slowdown occupying the shared worker rather than the classic streams' own kernels. + +## 3. Technical Decisions + +### 3.1 Take the issue's exit rather than build Step 2 + +The issue's Step 2 offered three shapes for scoping the exact kernel to the verify forward, from bracketing with explicit synchronization to a dispatch-side stream predicate. None was built, which is the sanctioned outcome when the B-sweep delta is small. + +What makes the exit defensible is not the smallness of the number but the mechanism behind it. `M = 1` always dispatches `qmv`; the pin only selects between `qmv` and `qmv_wide` at `M >= 2`. Both MTP families decode batches one row per forward, so batched decode in a pinned process never reaches the kernel the pin disables. Gemma 3 and Llama 4 do stack decode rows into one `M = B` forward, but they are not MTP families, so no process they run in is ever pinned by the gate. + +The record names the boundary that would reopen the question: a real joint batched decode for an MTP family. The moment Gemma 4 or Qwen 3.5 stacks decode rows the way Gemma 3 already does, batched decode lands in the qmv window and the pin starts taxing it. + +### 3.2 Pin both arms explicitly rather than let the gate choose one + +`qmv_wide_pinned_by_operator()` reads `std::env::var("MLXCEL_QMV_WIDE").is_ok()`, so setting the variable to any value, including `0`, counts as an operator pin and skips the gate's retry in both directions. Setting it on both arms is what makes the B-sweep a clean A/B: the gate cannot flip an arm mid-run. With no drafter loaded there is no probe to run in the first place, and `mlxcel_core::set_qmv_wide` has exactly one caller, the gate, so nothing else can move the flag either. + +### 3.3 Report the contaminated cell rather than average it in + +The long-context B = 4 cell reads higher throughput on the narrow arm, stably across all 16 samples. That is not a kernel effect. At temperature 0 the two kernels legitimately generate different text, and on that prompt the divergence changes the generation length itself (130 tokens wide against 182 narrow), so the two columns compare different workloads. The cell is reported as text-divergence-contaminated and excluded from the tax, with its TTFT columns retained because prefill precedes generation and they serve as the chunked-prefill control. + +The ladder cells avoid this by construction: every generation ran 59 tokens in both arms, verified from per-stream `usage` counts, so the rate comparison is length-matched even though the bytes differ mid-stream. + +### 3.4 Correct the stale `MLXCEL_MTP_ALLOW_INEXACT` recipe + +`mtp_exactness_gate` runs `retry_without_qmv_wide` before `allow_inexact()` is consulted (`let decision = exact || allow_inexact();`). On a host where the narrow retry passes, which is every generation 15+ host measured so far, the override alone is therefore inert: the retry pins the process narrow first and the flag never becomes load-bearing. Documents written before #1199 merged say the override alone reaches the fast kernel, which it no longer does. + +The correction is verified three independent ways rather than asserted: the log lines (the override-alone run logs the retry's INFO line and never the loud warning), the bytes (the default run and the override-alone run produce byte-identical text, while the pinned-wide run diverges six words in), and the throughput (117 against 139 tok/s, reproducing the byte-identical and fast-kernel figures `docs/benchmarks.md` already carries). The working recipe is `MLXCEL_QMV_WIDE=1` together with `MLXCEL_MTP_ALLOW_INEXACT=1`. + +### 3.5 Count `reasoning_content` deltas in the concurrency harness + +Qwen 3.8 streams its reasoning channel as `reasoning_content` deltas. `bench_serving_concurrency.py` counted only `content`, so a request that spent its whole budget thinking reported no TTFT and no decode rate at all. Both channels are decoded tokens, so both now count. Previously recorded measurements on non-reasoning models are unaffected, since `reasoning_content` is simply absent there. + +## 4. Review Findings and Corrections + +The implementation review verified the two load-bearing code claims directly against the source, and one of them cited a route the measurement did not take. + +**The Gemma 4 mechanism citation (corrected).** The record said Gemma 4 "does not override `forward_batched`, so it inherits the trait default". That is true of `src/models/gemma4.rs`, but `models/gemma-4-31b-it-4bit` carries `embed_vision.*` weights, so `gemma4_has_vision_weights` routes it to `LoadedModel::Gemma4VLM`. The scheduler's `execute_batched_decode` calls `forward_batched_with_context_and_ids` with the batch's sequence ids, and `Gemma4VLModel` overrides that entry point (`src/vision/gemma4_vl.rs:687`) in favour of `forward_batched_with_seq_ids_dispatch`. The trait default is never reached on the measured configuration. + +The conclusion survives and in fact rests on firmer ground, because that dispatch helper is itself an explicit per-row loop over `forward_with_sequence_id`. But the record's whole value is that a future reader can re-verify it, and a reader who followed the citation would have found the override and concluded the claim was false. The record now describes both routes and names the one the measurement took. + +The Qwen claim needed no correction. `src/models/qwen3_5.rs:3388` branches to a per-row loop whenever `shape[1] <= 1`, which is every decode step, and the `Qwen35VLModel` wrapper delegates straight through to the same function, so the citation is correct for both variants. + +**Quantity naming (corrected).** `docs/benchmarks.md` carries two different 23% figures: a verify-forward cost for the Gemma 4 family and an end-to-end decode cost for the M5 Max code row, and it explicitly warns not to conflate them. The record quoted "~23% on Gemma 4" without saying which, and quoted a composite "17 to 23%" range in a section measuring the Qwen pairing alone. Both now name the quantity and the family. + +**Fit tolerance (corrected).** The suffix-forward fit claimed agreement "to within 0.1 ms on every row"; the B = 8 row is 0.2 ms off (4.5 times 15.4 is 69.3 against a measured 69.5). + +Verified and found accurate: the `MLXCEL_QMV_WIDE` documentation row against the C++ flag parsing and `qmv_wide_pinned_by_operator`, all four gate-recipe log lines against the `tracing` calls they quote, the claim that `set_qmv_wide` has exactly one caller, the qmv batch limit of 12 for every projection of the 31B target on an `applegpu_g15d` part, the `mtp_capable_target` family list, and the Gemma 3 and Llama 4 joint-decode counterexamples. + +## 5. Change Summary + +| File | Change | +| --- | --- | +| `scripts/bench_qmv_wide_pin.sh` | New. ABBA boot driver for both arms. `sweep` alternates pinned-wide and pinned-narrow boots without a drafter; `mixed` alternates gate recipes and greps each boot's exactness-gate line so arm identity is evidenced. | +| `scripts/bench_qmv_pin_mixed.py` | New. Mixed-workload client. Classic decode rates are the reported quantity, and a window is invalid unless the MTP stream decoded through at least 95% of it. | +| `scripts/bench_serving_concurrency.py` | Count `reasoning_content` deltas alongside `content`. | +| `docs/benchmark_results/qmv-wide-pin-tax-m3ultra-2026-08-22.md` | New. The measurement record, including the excluded contaminated cell and the gate-recipe verification. | +| `docs/benchmarks.md` | Link the record; correct the fast-row reproduction recipe and the declining-probe sentence for the post-#1199 retry ordering. | +| `docs/environment-variables.md` | Correct the `MLXCEL_MTP_ALLOW_INEXACT` row; add the missing `MLXCEL_QMV_WIDE` row. | +| `docs/benchmark_results/mtp-drafter-step-profile-m5max-2026-08-17.md` | Dated note that its reproduction recipe predates the #1199 retry. | +| `.gitignore` | Ignore the raw `bench-results/` run directories the driver writes. | + +No Rust source changed, so there is no runtime behaviour change to regress. Validation was `python3 -m py_compile` on both Python harnesses and `bash -n` on the driver, plus the measurement runs themselves. + +## 6. Follow-up + +Found on the way and recorded rather than resolved: on current `main` the 31B plus bf16 assistant pairing probes non-identical under both kernels on this host, so the default-env gate declines the batch-capable burst that #1217 enabled. #1217's 1.95x to 2.65x rows were measured at `9e2c6675`, which predates #1258's Gemma probe. Anyone rerunning those rows on current `main` will hit this, and deciding what to do about that default belongs to its own issue. + +The scoping work itself stays unbuilt until an MTP family gains a real joint batched decode. At that point the B-sweep in this record should be rerun, a material number should be expected, and only then are the issue's Step 2 candidates worth weighing. diff --git a/TECHNICAL_REPORTS/1278-qmv-wide-pin-tax-measurement-20260822.ko.md b/TECHNICAL_REPORTS/1278-qmv-wide-pin-tax-measurement-20260822.ko.md new file mode 100644 index 000000000..1f2318ce8 --- /dev/null +++ b/TECHNICAL_REPORTS/1278-qmv-wide-pin-tax-measurement-20260822.ko.md @@ -0,0 +1,92 @@ +# 기술 보고서: PR #1278 - qmv_wide narrow pin이 나머지 프로세스에 물리는 비용 측정 + +## 요약 + +이슈 #1261은 MTP exactness gate가 temperature-0 byte-identity를 되사려고 `qmv_wide`를 프로세스 전체에서 꺼버릴 때, 그 프로세스의 나머지 작업이 무엇을 지불하는지 물었다. 이슈는 의도적으로 측정을 선행 조건으로 걸었고("숫자가 나오기 전에는 아래 어떤 것도 만들 가치가 없다"), 명시적인 종료 조건을 함께 달았다. 프로덕션 shape에서 비용이 작으면 숫자를 기록하고 거기서 멈추라는 것. + +이 PR은 그 종료 조건을 택한다. Rust 소스는 한 줄도 바뀌지 않는다. 벤치마크 하네스 두 개를 추가하고, 이슈가 요구한 Apple GPU generation 15 호스트에서 측정을 기록하며, #1199가 gate의 순서를 바꾸면서 낡아버린 `MLXCEL_MTP_ALLOW_INEXACT` 레시피를 문서 세 곳에서 바로잡는다. + +측정된 답은 batched decode 비용이 최대 1%라는 것인데, 이유가 수치적이라기보다 구조적이다. 이슈가 가정한 `M = B` projection을 두 MTP 계열 모두 dispatch하지 않는다. 실제로 존재하는 비용은 요청당 prompt cache에 붙는 suffix prefill 한 번이고, Gemma 타깃에서 forward당 +15.4 ms, Qwen 타깃에서 +12.6 ms다. + +## 1. 문제 + +PR #1199는 exactness gate에 retry를 붙였다. multi-token verify block이 `qmv_wide` 아래에서 single-token decode chain과 갈라지면 gate가 `qmv_wide`를 끄고 다시 probe하며, 그렇게 해서 byte-identity가 돌아오면 프로세스가 끝날 때까지 꺼둔다. 스위치를 되돌리지 않는 것은 의도적이다. 다시 켜면 gate가 방금 승인한 바로 그 block이 깨지기 때문이다. + +문제는 이 스위치가 프로세스 전역이라는 점이다. `dispatch_qmv`에서 모든 quantized matmul의 dispatch 경로에 놓여 있어서, 프로세스를 공유하는 서버는 byte-identity를 요구한 적 없는 작업에도 이 비용을 문다. #1199는 이 점을 명시하고 scoping 작업을 후속으로 넘겼다. #1261이 그 후속이고, 첫 단계는 수술을 정당화할 만큼 부수 비용이 큰지 확인하는 일이었다. + +verify 쪽 비용은 이미 가격표가 붙어 있었다(Qwen verify forward 17~20%, Gemma 4 verify forward 약 23%). 옆에 있던 작업이 무엇을 물었는지는 한 번도 측정된 적이 없었다. + +## 2. 무엇을 측정했나 + +Mac Studio M3 Ultra(`applegpu_g15d`, generation 15, macOS 26.6.1)에서 `scripts/with_indexers_paused.sh` 아래, Time Machine을 끈 상태로 두 arm을 돌렸다. + +**arm 1, drafter 없는 batched-decode B-sweep.** `MLXCEL_QMV_WIDE=1` 고정과 `MLXCEL_QMV_WIDE=0` 고정을 B = 1, 2, 4, 8에서 비교했고, 타깃은 `models/gemma-4-31b-it-4bit`, 확인은 `models/qwen3.8-27b-4bit`로 했다. 균형 잡힌 ABBA 블록 두 개로 8 boot, boot마다 warm-up 한 pass를 버리고 측정 pass를 두 번 돌려 cell당 arm당 8 샘플을 얻었다(Qwen 확인은 4). 결과는 Gemma 0.0~0.9%, Qwen 0.0~0.2%였고 모든 spread가 1% 이하로, 하네스의 4% 신뢰 한계 안에 넉넉히 들어온다. + +**arm 2, 혼합 워크로드.** Qwen MTP 페어링에서 tick-slice speculative slot을 붙잡은 MTP 스트림 하나에 classic 스트림 넷을 붙였고, arm A는 gate의 retry가 프로세스를 narrow로 고정하는 기본 env, arm B는 `MLXCEL_QMV_WIDE=1 MLXCEL_MTP_ALLOW_INEXACT=1`이다. 읽는 값은 classic 스트림의 decode rate뿐이다. classic 스트림은 0.1~2.6%를 잃었는데, 그 손실은 classic 스트림 자신의 kernel이 아니라 narrow verify forward가 공유 worker를 더 오래 점유하는 데서 온다. + +## 3. 기술적 판단 + +### 3.1 Step 2를 만들지 않고 이슈의 종료 조건을 택한다 + +이슈의 Step 2는 exact kernel을 verify forward로 좁히는 방법을 세 가지 제시했다. 명시적 동기화로 구간을 감싸는 방식부터 dispatch 쪽 stream predicate까지. 아무것도 만들지 않았고, B-sweep 차이가 작을 때는 그쪽이 이슈가 승인한 결말이다. + +이 결말을 방어하는 것은 숫자가 작다는 사실이 아니라 그 뒤의 메커니즘이다. `M = 1`은 항상 `qmv`로 가고, pin은 `M >= 2`에서만 `qmv`와 `qmv_wide` 사이를 고른다. 두 MTP 계열 모두 decode batch를 forward당 한 row씩 처리하므로, 고정된 프로세스의 batched decode는 pin이 끄는 kernel에 애초에 닿지 않는다. Gemma 3와 Llama 4는 decode row를 하나의 `M = B` forward로 쌓지만 MTP 계열이 아니어서, 그들이 도는 프로세스는 gate에 고정될 일이 없다. + +기록은 이 답이 뒤집히는 경계도 함께 지목한다. MTP 계열이 진짜 joint batched decode를 갖는 순간이다. Gemma 4나 Qwen 3.5가 Gemma 3처럼 decode row를 쌓기 시작하면 batched decode가 qmv window로 들어가고 pin이 거기에 세금을 물리기 시작한다. + +### 3.2 gate에 맡기지 않고 두 arm을 모두 명시적으로 고정한다 + +`qmv_wide_pinned_by_operator()`는 `std::env::var("MLXCEL_QMV_WIDE").is_ok()`를 읽는다. 값이 `0`이든 무엇이든 변수를 설정한 것 자체가 operator pin이고, gate의 retry는 양방향 모두 건너뛴다. 두 arm에 모두 걸어야 B-sweep이 깨끗한 A/B가 되는데, 그래야 gate가 run 도중에 arm을 뒤집을 수 없기 때문이다. drafter를 안 띄우면 돌릴 probe 자체가 없고, `mlxcel_core::set_qmv_wide`의 호출자는 gate 하나뿐이라 다른 무엇도 이 flag를 움직이지 못한다. + +### 3.3 오염된 cell은 평균에 섞지 않고 그대로 보고한다 + +long-context B = 4 cell은 narrow arm 쪽 throughput이 오히려 높게 나왔고, 16 샘플 전체에서 안정적으로 그랬다. kernel 효과가 아니다. temperature 0에서도 두 kernel은 정당하게 다른 텍스트를 만들고, 이 프롬프트에서는 그 분기가 생성 길이 자체를 바꿨다(wide 130 토큰, narrow 182 토큰). 두 컬럼이 서로 다른 워크로드를 비교하고 있는 셈이다. 그래서 이 cell은 text-divergence로 오염됐다고 적고 비용 집계에서 뺐다. TTFT 컬럼은 prefill이 생성보다 앞서므로 영향을 받지 않고, chunked-prefill 대조군으로 그대로 쓴다. + +ladder cell들은 애초에 이 문제를 피하도록 구성됐다. 스트림별 `usage` 카운트로 확인한 결과 두 arm 모두 생성이 59 토큰에서 끝났고, 중간 바이트는 갈라져도 rate 비교는 길이가 맞춰져 있다. + +### 3.4 낡은 `MLXCEL_MTP_ALLOW_INEXACT` 레시피를 바로잡는다 + +`mtp_exactness_gate`는 `allow_inexact()`를 보기 전에 `retry_without_qmv_wide`를 먼저 돌린다(`let decision = exact || allow_inexact();`). narrow retry가 통과하는 호스트, 즉 지금까지 측정된 모든 generation 15+ 호스트에서는 override 단독이 무력하다. retry가 프로세스를 먼저 narrow로 고정해버려서 flag가 결정에 관여할 자리가 없다. #1199가 머지되기 전에 쓰인 문서들은 override만으로 fast kernel에 닿는다고 적어두었는데, 이제는 그렇지 않다. + +이 정정은 주장이 아니라 서로 독립적인 세 갈래로 검증됐다. 로그 줄(override만 건 실행은 retry의 INFO 줄을 남기고 큰 경고는 끝내 뜨지 않는다), 바이트(기본 실행과 override 단독 실행의 생성 텍스트가 byte-identical이고, wide로 고정한 실행은 여섯 단어째에서 갈라진다), 그리고 throughput(117 대 139 tok/s로, `docs/benchmarks.md`가 이미 싣고 있는 byte-identical 수치와 fast kernel 수치를 재현한다). 동작하는 레시피는 `MLXCEL_QMV_WIDE=1`과 `MLXCEL_MTP_ALLOW_INEXACT=1`을 함께 거는 것이다. + +### 3.5 concurrency 하네스가 `reasoning_content` delta를 센다 + +Qwen 3.8은 reasoning 채널을 `reasoning_content` delta로 흘린다. `bench_serving_concurrency.py`는 `content`만 세고 있었고, 예산 전부를 생각에 쓰는 요청은 TTFT도 decode rate도 아예 보고되지 않았다. 두 채널 모두 디코드된 토큰이므로 이제 둘 다 센다. reasoning이 없는 모델에는 `reasoning_content` 자체가 오지 않으니 기존에 기록된 측정값의 의미는 달라지지 않는다. + +## 4. 리뷰에서 나온 지적과 수정 + +구현 리뷰는 결론을 떠받치는 코드 주장 두 개를 소스에 직접 대조했고, 그중 하나가 측정이 지나가지 않은 경로를 인용하고 있었다. + +**Gemma 4 메커니즘 인용(수정됨).** 기록은 Gemma 4가 "`forward_batched`를 override하지 않으므로 trait default를 상속한다"고 적었다. `src/models/gemma4.rs`에 대해서는 맞는 말이지만, `models/gemma-4-31b-it-4bit`는 `embed_vision.*` 가중치를 들고 있어서 `gemma4_has_vision_weights`가 이를 `LoadedModel::Gemma4VLM`으로 보낸다. 스케줄러의 `execute_batched_decode`는 batch의 sequence id를 실어 `forward_batched_with_context_and_ids`를 호출하고, `Gemma4VLModel`은 바로 그 진입점을 override해서(`src/vision/gemma4_vl.rs:687`) `forward_batched_with_seq_ids_dispatch`로 넘긴다. 측정한 구성에서 trait default에는 닿지 않는다. + +결론은 살아남고 오히려 더 단단한 근거 위에 선다. 그 dispatch helper 자체가 `forward_with_sequence_id`를 도는 명시적 per-row 루프이기 때문이다. 다만 이 기록의 가치는 나중에 읽는 사람이 다시 검증할 수 있다는 데 있고, 인용을 따라간 독자는 override를 발견하고 주장이 틀렸다고 판단했을 것이다. 기록은 이제 두 경로를 모두 서술하고 측정이 탄 쪽을 지목한다. + +Qwen 쪽 주장은 손댈 데가 없었다. `src/models/qwen3_5.rs:3388`은 `shape[1] <= 1`이면, 즉 모든 decode step에서 per-row 루프로 분기하고, `Qwen35VLModel` 래퍼는 같은 함수로 그대로 위임하므로 인용이 두 variant 모두에 대해 정확하다. + +**수치의 이름(수정됨).** `docs/benchmarks.md`에는 23%가 둘 있다. Gemma 4 계열의 verify forward 비용과 M5 Max code row의 end-to-end decode 비용인데, 문서 스스로 둘을 섞지 말라고 경고한다. 기록은 어느 쪽인지 밝히지 않은 채 "Gemma 4에서 ~23%"라고 적었고, Qwen 페어링만 측정한 절에서 "17~23%"라는 합성 범위를 인용했다. 이제 둘 다 수치의 정체와 계열을 명시한다. + +**피팅 오차(수정됨).** suffix forward 피팅이 "모든 row에서 0.1 ms 이내"로 일치한다고 적었으나 B = 8 row는 0.2 ms 벗어난다(4.5 곱하기 15.4는 69.3, 측정값은 69.5). + +검증해서 정확한 것으로 확인된 항목은 다음과 같다. C++ flag 파싱과 `qmv_wide_pinned_by_operator`에 대조한 `MLXCEL_QMV_WIDE` 문서 행, 인용된 네 가지 gate 레시피 로그 줄과 실제 `tracing` 호출, `set_qmv_wide`의 호출자가 하나뿐이라는 주장, `applegpu_g15d` 파트에서 31B 타깃의 모든 projection에 대해 qmv batch limit이 12라는 계산, `mtp_capable_target`의 계열 목록, 그리고 Gemma 3와 Llama 4의 joint decode 반례. + +## 5. 변경 요약 + +| 파일 | 변경 | +| --- | --- | +| `scripts/bench_qmv_wide_pin.sh` | 신규. 두 arm을 모두 구동하는 ABBA boot 드라이버. `sweep`은 drafter 없이 wide 고정과 narrow 고정 boot를 번갈아 띄우고, `mixed`는 gate 레시피를 번갈아 쓰면서 boot마다 exactness-gate 로그 줄을 grep해 arm 정체를 증거로 남긴다. | +| `scripts/bench_qmv_pin_mixed.py` | 신규. 혼합 워크로드 클라이언트. 보고 대상은 classic decode rate이고, MTP 스트림이 window의 95% 이상을 디코드하며 지나가지 않은 window는 무효 처리한다. | +| `scripts/bench_serving_concurrency.py` | `content`와 나란히 `reasoning_content` delta를 센다. | +| `docs/benchmark_results/qmv-wide-pin-tax-m3ultra-2026-08-22.md` | 신규. 제외된 오염 cell과 gate 레시피 검증을 포함한 측정 기록. | +| `docs/benchmarks.md` | 기록을 링크하고, fast row 재현 레시피와 declining probe 문장을 #1199 이후 retry 순서에 맞게 고친다. | +| `docs/environment-variables.md` | `MLXCEL_MTP_ALLOW_INEXACT` 행을 정정하고 빠져 있던 `MLXCEL_QMV_WIDE` 행을 추가한다. | +| `docs/benchmark_results/mtp-drafter-step-profile-m5max-2026-08-17.md` | 재현 레시피가 #1199 retry보다 앞선다는 날짜 표기 주석. | +| `.gitignore` | 드라이버가 쓰는 원시 `bench-results/` 실행 디렉터리를 무시한다. | + +Rust 소스가 바뀌지 않았으므로 되돌아갈 런타임 동작 변화도 없다. 검증은 두 Python 하네스에 대한 `python3 -m py_compile`, 드라이버에 대한 `bash -n`, 그리고 측정 실행 자체였다. + +## 6. 후속 + +작업 도중 발견해 해결하지 않고 기록만 한 것이 하나 있다. 현재 `main`에서 31B + bf16 assistant 페어링은 이 호스트에서 두 kernel 모두에 대해 non-identical로 probe되고, 그래서 기본 env의 gate가 #1217이 켜놓은 batch-capable burst를 거절한다. #1217의 1.95x~2.65x 행은 `9e2c6675`에서 측정됐는데 이는 #1258의 Gemma probe보다 앞선다. 현재 `main`에서 그 행들을 다시 돌리는 사람은 이 상황을 만나게 되고, 그 기본값을 어떻게 할지는 별도 이슈의 몫이다. + +scoping 작업 자체는 MTP 계열이 진짜 joint batched decode를 갖기 전까지 만들지 않는다. 그 시점이 오면 이 기록의 B-sweep을 다시 돌려 유의미한 숫자를 기대해야 하고, 이슈의 Step 2 후보들을 저울질할 가치는 그때 생긴다. diff --git a/docs/benchmark_results/mtp-drafter-step-profile-m5max-2026-08-17.md b/docs/benchmark_results/mtp-drafter-step-profile-m5max-2026-08-17.md index 0df672c10..8f32f4014 100644 --- a/docs/benchmark_results/mtp-drafter-step-profile-m5max-2026-08-17.md +++ b/docs/benchmark_results/mtp-drafter-step-profile-m5max-2026-08-17.md @@ -171,3 +171,13 @@ done `MLXCEL_MTP_ALLOW_INEXACT=1` is required on generation 15 and later. Without it the gate refuses to engage MTP and the run falls back to classic decode, which produces no round-loop diagnostics at all. + +Update 2026-08-22: the paragraph above describes the pre-#1199 gate this +profile was measured under, and the recipe no longer reproduces these +kernels. Since #1199 the gate retries a failing probe with `qmv_wide` +disabled before the override is consulted, so on generation 15+ the same +command now engages MTP on the narrow kernel with byte-identity kept, and +the override is inert. Reproducing this profile's fast-kernel arm needs +`MLXCEL_QMV_WIDE=1` alongside `MLXCEL_MTP_ALLOW_INEXACT=1`; see +`qmv-wide-pin-tax-m3ultra-2026-08-22.md` for the live verification of all +four recipes. diff --git a/docs/benchmark_results/qmv-wide-pin-tax-m3ultra-2026-08-22.md b/docs/benchmark_results/qmv-wide-pin-tax-m3ultra-2026-08-22.md new file mode 100644 index 000000000..a4075acf3 --- /dev/null +++ b/docs/benchmark_results/qmv-wide-pin-tax-m3ultra-2026-08-22.md @@ -0,0 +1,417 @@ +# The qmv_wide narrow pin priced on batched serving, M3 Ultra, 2026-08-22 + +Issue #1261 asked for a number: when the MTP exactness gate buys back +temperature-0 byte-identity by disabling `qmv_wide` for the whole process +(#1199, #1258), what does everything else in that process pay? The issue's +framing assumed the main victim is batched decode at `B >= 2`, "whose +per-step projections are exactly the `M >= 2` shape `qmv_wide` exists for", +and gated any scoping work (its Step 2) on that tax being material. + +Headline: **the batched-decode tax is at most 1% and indistinguishable from +zero at B = 8, and not because the two kernels are close: the `M = B` +projection shape the issue assumed does not exist in the shipped decode path +of any family the pin can fire on.** Both MTP families run batched decode as +per-sequence `M = 1` forwards, which dispatch `qmv` under either pin. The +collateral tax that does exist today is on **prompt-cache-hit TTFT**: an +adopted-prefix request prefills only its short suffix, whose `M` lands in +the qmv window, and that one forward costs 15.4 ms more under the narrow +pin (12.6 ms on the Qwen target), which reads as +33% on this harness's +cache-hit TTFT. The mixed-workload arm (one MTP stream plus four classic +streams, the shape the pin actually arises in) agrees end to end: the +classic streams lose 0.1 to 2.6% beside a narrow-pinned MTP stream, and +the loss tracks the MTP stream's own verify slowdown occupying the shared +worker, not the classic streams' kernels. + +Per the issue's own exit condition ("if the B-sweep delta is small on +production shapes, the right fix may be documenting the tax and stopping +there"), the scoping work is not built. The numbers, the mechanism, and the +boundary where this answer would change are recorded below. + +## Environment + +| Field | Value | +|---|---| +| Host | Mac Studio, Apple M3 Ultra, 512 GB unified memory, macOS 26.6.1 (25G76) | +| Apple GPU generation | 15 (`applegpu_g15d`; `use_qmv_wide` holds for affine, the exactness probe fails wide, and where the narrow retry passes the gate pins the process narrow by default) | +| Build | `cargo build --release --features metal,accelerate` | +| Branch | `update/issue-1261-qmv-wide-pin-tax` from `main` at `dd21ada4` (harness scripts added, no runtime change) | +| Harness | `scripts/bench_qmv_wide_pin.sh sweep` / `mixed` (added by this work), driving `scripts/bench_serving_concurrency.py` and `scripts/bench_qmv_pin_mixed.py` | +| Wrapper | `scripts/with_indexers_paused.sh` (17 indexers suspended; `INDEXER_RESUME_DEADLINE` raised to cover the runs) | +| Time Machine | not running (`tmutil status` Running = 0) | +| Sweep target | `models/gemma-4-31b-it-4bit` (batch-capable, no drafter loaded), server `--parallel 8 --metrics` | +| Confirmation target | `models/qwen3.8-27b-4bit`, same protocol at half the boot count | +| Mixed pairing | `models/qwen3.8-27b-4bit` + `models/qwen3.8-27b-mtp-4bit`, `--draft-block-size 3` (the 31B + bf16 pairing was attempted first and cannot be pinned narrow on this host; see below) | +| Sampling | temperature 0 everywhere | + +Both arms of the B-sweep pin the kernel explicitly: `MLXCEL_QMV_WIDE=1` +(wide) versus `MLXCEL_QMV_WIDE=0` (narrow). Any value of `MLXCEL_QMV_WIDE` +counts as an operator pin (`qmv_wide_pinned_by_operator` in +`src/models/speculative_exactness.rs`), so the gate's retry can never flip +an arm mid-run, and with no drafter loaded the gate has no probe to run in +the first place. Boots alternate in two balanced ABBA blocks (wide, narrow, +narrow, wide, then narrow, wide, wide, narrow); each boot runs one +discarded warm-up pass and two measured passes, giving 8 samples per arm +per cell. A pass is the B = 1, 2, 4, 8 ladder (512-token prompt, 256-token +budget) plus a long-context B = 4 cell (4096-token prompt). + +## Where `M >= 2` quantized matmuls actually occur in serving + +The issue's premise was that batched decode at `B >= 2` runs its per-step +projections at `M = B`. The scheduler does run batched decode as one +`forward_batched()` call per step (`execute_batched_decode` in +`src/server/batch/scheduler.rs`, input shape `[B, 1]`), but what the model +does with that input decides the dispatch, and neither MTP family stacks it: + +- **Gemma 4** decodes per row on both of its routes. The measured + checkpoint carries `embed_vision.*` weights, so detection routes it to + `LoadedModel::Gemma4VLM` (`gemma4_has_vision_weights` in + `src/models/detection.rs`), and `execute_batched_decode` + (`src/server/batch/scheduler.rs:7300`) calls + `forward_batched_with_context_and_ids` with the batch's sequence ids. + `Gemma4VLModel` overrides that entry point + (`src/vision/gemma4_vl.rs:687`) and delegates to + `forward_batched_with_seq_ids_dispatch` + (`src/multimodal/batched_dispatch.rs:60`), which slices `input_ids` row + by row and calls `forward_with_sequence_id` once per sequence. The + text-only route (`LoadedModel::Gemma4`, `models::Gemma4Wrapper`) + overrides nothing and inherits the trait default + (`src/lib/mlxcel-core/src/generate.rs:736`), which is the same per-row + loop over `forward()`. Either way `M = 1` per forward, results + concatenated. +- **Qwen 3.5** (`src/models/qwen3_5.rs:3388`) overrides it but branches to + the same per-row loop whenever the input is single-token, which is every + decode step. Its joint path only serves multi-token batched prefill. + +`M = 1` always dispatches `qmv`; the pin selects between `qmv` and +`qmv_wide` only at `M >= 2` (`dispatch_qmv` in the +`src/lib/mlx-cpp/patches/mlx/backend/metal/quantized.cpp` overlay). So +batched decode in a pinned process never reaches the kernel the pin turns +off. The families that do stack decode rows into one `M = B` forward, +Gemma 3 (`src/models/gemma3.rs:1302`) and Llama 4 +(`src/models/llama4.rs:1801`), are not MTP families (`mtp_capable_target` +covers Gemma 4 and Qwen 3.5 only), so no process they run in is ever pinned +by the gate. + +Two server-side surfaces do put an `M` inside the qmv window +(`2 <= M < get_qmv_batch_limit`, and the limit is 12 for every projection +of this target on this host: hidden 5376 and intermediate 21504 put q, k, +v, o, gate, up, down and the 262k LM head all above the table's 4096 +branch): + +1. **Prompt-cache-adopted prefill.** A request whose prompt is cached up to + the last few tokens prefills only the suffix. The harness's repeated + identical prompts produce exactly this, and the server log shows it: + `cached=441/445 prompt tokens`, a 4-token suffix, one `M = 4` forward + per request. This is the one real tax the sweep caught, and it shows in + TTFT, not in decode throughput. +2. **The speculative verify forward itself** (`M = K`), which is the work + the pin exists for and was already priced: 17 to 20% on the Qwen verify + forward, ~23% on the Gemma 4 verify forward (`docs/benchmarks.md`). + Neither is the "23% of throughput" the same file quotes for the M5 Max + code row, which is end-to-end decode; the two 23s are different + quantities. + +Fresh full prefill and chunked-prefill chunks run at `M >= 473` in these +configurations, far above every batch limit, and take the matrix-matrix +kernel regardless of the pin. The long-context cell below confirms that +control directly. + +The per-row structure also shows in the absolute numbers, which is worth +recording so nobody reads this B-sweep as a healthy-scaling baseline: +aggregate decode throughput rises from 29.5 tok/s at B = 1 to only 43.3 at +B = 4 and falls back to 33.7 at B = 8, because each batched step pays B +row-forwards (partially overlapped by MLX's async pipeline) rather than one +amortized pass. `/metrics` confirms the steps are batched at the scheduler +level (`batch_decode_tokens_total / batch_decode_steps_total` tracked the +batch size at 3.83 tokens per step with 4 streams active) while the model +executes rows serially. Diagnosing that scaling is outside this issue's +scope; what matters here is that it is identical in both arms. + +## B-sweep: Gemma 4 31B, wide pin vs narrow pin + +Per-request decode rate (tokens after the first divided by the span from +first to last token), medians over 8 measured passes per arm. Every +generation in the ladder ran 59 tokens in both arms (the model answers the +synthetic prompt briefly and stops; verified with per-stream `usage` +counts), so the two arms decode the same number of tokens per stream and +the rate comparison is length-matched. The generated bytes differ between +arms mid-stream, which is the kernel non-identity the exactness gate +exists for; both arms end on the same 59th token. + +| B | wide, tok/s | spread | narrow, tok/s | spread | narrow / wide | +|---:|---:|---:|---:|---:|---:| +| 1 | 29.95 | 0.3% | 29.90 | 0.7% | 0.998 | +| 2 | 20.95 | 0.5% | 20.90 | 0.0% | 0.998 | +| 4 | 10.90 | 0.0% | 10.80 | 0.9% | 0.991 | +| 8 | 4.20 | 0.0% | 4.20 | 0.0% | 1.000 | + +The per-stream decode delta is 0.0 to 0.9% with every spread at or under +0.9%, against the harness's 4% trust limit. Aggregate throughput (all +completion tokens over the level's wall span, which includes prefill) reads +0.6 to 1.2% lower on the narrow arm; the next section shows that deficit is +the TTFT tax, not decode. + +**This is the number issue #1261 Step 1 asked for: the B = 2/4/8 +batched-decode tax of the narrow pin on this pairing is at most 1%, inside +or touching the run spread.** It is zero for the structural reason above: +these decode steps never dispatch the kernel the pin disables. + +## The tax that is real: cache-hit TTFT + +Mean time to first token per level, same passes. After the discarded +warm-up, every ladder request adopts its prompt from the cache and +prefills a 4-token suffix, one `M = 4` quantized-matmul forward, which is +inside the qmv window and therefore does change kernels under the pin: + +| B | wide TTFT, ms | spread | narrow TTFT, ms | spread | delta | +|---:|---:|---:|---:|---:|---:| +| 1 | 64.3 | 9.0% | 79.8 | 5.1% | +15.5 ms | +| 2 | 70.0 | 1.0% | 93.1 | 0.4% | +23.0 ms (+33%) | +| 4 | 116.2 | 0.4% | 154.6 | 0.5% | +38.4 ms (+33%) | +| 8 | 208.8 | 0.7% | 278.3 | 0.7% | +69.5 ms (+33%) | + +The B = 1 row's spreads (9.0% and 5.1%) are above the 4% trust limit, one +request per pass being too few to average TTFT jitter out, so that row is +indicative only; the B = 2, 4, 8 rows are all at or under 1.0%. + +The four deltas are one number in disguise. Concurrent identical requests +prefill their suffixes serially, so the i-th request's TTFT carries i +suffix forwards and the level mean carries `(B + 1) / 2` of them. One +suffix forward costing `d` more narrow predicts mean deltas of `1d, 1.5d, +2.5d, 4.5d`; the measured `15.5, 23.0, 38.4, 69.5` fit `d = 15.4 ms` to +within 0.2 ms on every row, the B = 1 row included. So the entire TTFT +effect is a single `M = 4` suffix forward costing **+15.4 ms** under the +narrow pin, repeated once per queued cache-hit request. + +Two controls pin the mechanism: + +- **Uncached prefill is untaxed.** The discarded warm-up passes, whose + first requests prefill the full 445 tokens through the matrix-matrix + kernel, show no arm difference beyond cold-boot noise (B = 1 warm-up + TTFT 1479.8 ms wide vs 1369.3 ms narrow, the narrow boot the faster + one). +- **Chunked long prefill is untaxed.** The long-context cell (4096-token + prompt, chunked at 512, every chunk `M >= 473`) measures TTFT 23848.5 ms + wide vs 23885.3 ms narrow (+0.2%, spreads 0.1%). + +## The long-context cell is a text-divergence casualty, not a kernel cost + +The long-context B = 4 cell's throughput columns read *higher* for the +narrow arm (6.4 vs 5.8 tok/s per stream), stable across all 16 samples. +That is not a kernel effect: at temperature 0 the two arms legitimately +generate different text (the same last-ulp kernel difference the exactness +gate polices), and on this prompt the divergence changes the generation +length itself: 130 tokens under the wide pin, 182 under the narrow, every +stream, verified with per-stream `usage` counts. Different token counts +mean different effective batch occupancy over the window, so the +throughput columns compare different workloads and are reported as +contaminated rather than averaged into the tax. `docs/benchmarks.md` +carries the same warning for the offline arms: turning the flag changes +the text, so cross-flag throughput is only comparable when the lengths +happen to match, as they do (at 59 tokens) in the ladder above. The cell's +TTFT columns are unaffected (prefill precedes generation) and serve as the +chunked-prefill control above. + +## Confirmation on Qwen 3.8 27B + +Same protocol at half the boot count (one ABBA block, 4 samples per arm per +cell), `models/qwen3.8-27b-4bit`, no drafter. Qwen 3.8 streams its +reasoning channel, which `bench_serving_concurrency.py` did not count as +decoded tokens; the script now counts `reasoning_content` deltas alongside +`content` (without that fix a reasoning model reports no TTFT and no +decode rate at all). Every ladder stream decodes its full 256-token budget +in both arms, so this table is length-matched by construction. + +| B | wide, tok/s | spread | narrow, tok/s | spread | narrow / wide | +|---:|---:|---:|---:|---:|---:| +| 1 | 36.35 | 0.3% | 36.30 | 0.3% | 0.999 | +| 2 | 25.80 | 0.0% | 25.75 | 0.4% | 0.998 | +| 4 | 10.70 | 0.0% | 10.70 | 0.0% | 1.000 | +| 8 | 4.90 | 0.0% | 4.90 | 0.0% | 1.000 | + +Decode tax 0.0 to 0.2%, spreads at or under 0.4%: the second pinned family +confirms the first. The single-stream 36.3 tok/s agrees with the 35.7 the +offline harness records for this checkpoint on this host in +`docs/benchmarks.md`. + +The TTFT columns repeat the suffix mechanism with this family's own +numbers. Qwen's cache-hit suffix is 5 tokens (`cached=479/484`), and the +cache-hit levels read +18.8 ms at B = 2, +31.6 ms at B = 4, +56.8 ms at +B = 8 (all +27 to +28%, spreads at or under 2.3%), fitting one `M = 5` +suffix forward at **d = 12.6 ms** across all three levels. Qwen's B = 1 +level happened to run uncached every pass (its 1210 ms TTFT is a full +485-token prefill, not a suffix), which turns that row into another +control: matrix-kernel prefill, TTFT 1210.2 vs 1223.8 ms, +1.1%. The +long-context cell agrees: chunked prefill TTFT +0.4%, decode delta 0.0%. + +## Found on the way: the 31B pairing now declines MTP outright on this host + +The mixed arm was first attempted on the 31B + bf16 assistant pairing, +`--draft-block-size 4`, and could not be: **on current `main` the exactness +probe for that pairing fails under `qmv_wide` and fails again without it** +("verify block position 0 differs from the single-token chain in 231782 of +524288 logit bytes ... Disabling qmv_wide did not make it exact either"), +so the default-env gate declines MTP, restores the wide kernel, and no +narrow pin ever arises for it. Both server boots reproduced it, block 4, +same byte counts. + +This is new information and it collides with a fresh default: #1217 +measured this pairing at 1.95x to 2.65x on this host and turned the +batch-capable B = 1 burst on for generation 15+, but that measurement ran +at `9e2c6675`, which predates #1258's Gemma probe. With the probe in +place, the burst #1217 enabled is vetoed at serve time by the exactness +gate on this same host, and the speedup is reachable only by forfeiting +byte-identity (`MLXCEL_MTP_ALLOW_INEXACT=1`, with or without the pin: a +retry that fails restores the wide kernel, so for this pairing the +override alone does reach the fast kernel). The plausible mechanism is the +one #1258 names for the M1 Ultra prose divergence: a narrow-kernel +divergence in the 262144-wide LM head, which the 12B pairing (whose retry +passes, see the recipes below) shares in shape but not in hidden width. +Deciding what to do about that default belongs to a follow-up, not to this +measurement; it is recorded here because anyone rerunning #1217's rows on +current `main` will hit it. + +For this document's purpose the consequence is narrower: the pairing the +mixed arm can price is the one whose retry actually pins the process +narrow on this host, and that is the Qwen pairing +(`qwen3.8-27b-4bit` + `qwen3.8-27b-mtp-4bit`, block 3), the same +combination `docs/benchmarks.md` records as "passes after dropping +`qmv_wide`" here. + +## Mixed workload: one MTP stream plus four classic streams + +The shape the pin actually arises in: `qwen3.8-27b-4bit` + +`qwen3.8-27b-mtp-4bit`, block 3, `--parallel 8`, with +`MLXCEL_ENABLE_MTP_B1=1 MLXCEL_MTP_ADAPTIVE=0` pinning the burst decision +and `MLXCEL_MTP_SLICE_GRANT_ROUNDS=0` disabling slice-slot rotation, so +the first stream holds the tick-cooperative MTP slot for its whole +generation and every concurrent eligible request falls back to classic +decode (the pre-#746 behaviour; the scheduler's "speculative slice slot +busy; seq ... falls back to classic decode" line is in both arms' logs). +Each boot runs three windows (`scripts/bench_qmv_pin_mixed.py`): one long +MTP stream is started, and once it is decoding, four identical classic +streams (512-token prompts, 256-token budgets) run beside it; only the +classic streams' decode rates are read, and a window is valid only if the +MTP stream decoded through at least 95% of it (all windows here: 99.7 to +100%). Window 0 of each boot is the discarded warm-up. Boots alternate +A B B A. + +Arm identities, evidenced from each boot's gate line: + +- **Arm A**, default env: INFO "probe failed under qmv_wide ... and passed + without it. Disabling qmv_wide for this process". The MTP stream runs + the exact narrow verify and the whole process is pinned narrow. +- **Arm B**, `MLXCEL_QMV_WIDE=1 MLXCEL_MTP_ALLOW_INEXACT=1`: WARN "probe + FAILED but MLXCEL_MTP_ALLOW_INEXACT is set". The process stays wide and + the MTP stream forfeits byte-identity. (The issue text's recipe for this + arm, the override alone, does not produce it; see the recipes section.) + +The MTP stream's own numbers are not compared across arms (its text +differs by construction). Per-stream classic decode rate, mean of the four +streams, both boots of each arm: + +| window | arm A (narrow pin) | arm B (wide) | A / B | +|---|---:|---:|---:| +| 1 | 7.89, 7.94 | 7.92, 7.92 | 0.999 | +| 2 | 7.11, 7.11 | 7.30, 7.29 | 0.974 | + +The two windows are genuinely different workloads, deterministically so: +at temperature 0 the MTP stream replays the same text in every boot, so +window 1 (where it emitted 325 tokens in both arms) and window 2 (593 +narrow, 612 wide) repeat their own numbers to 0.6% across boots but do not +match each other. Pooling them into one median would manufacture an 8 to +11% spread out of window heterogeneity, so the comparison is per +like-window: **the classic streams lose 0.1% (window 1) to 2.6% (window +2) beside a narrow-pinned MTP stream.** + +The mechanism is not the classic streams' own kernels, which are per-row +`M = 1` in both arms; it is worker-occupancy: the narrow verify forward +runs 17 to 20% longer, each MTP slice holds the worker that much longer +per round, and the classic batch gets correspondingly fewer ticks. The +MTP stream's window 2 emission (593 vs 612 tokens, 3% fewer narrow) is +the same effect seen from the other side. So even in the mixed shape, the +pin's cost to bystander streams on current code is bounded by the MTP +stream's own slowdown diluted across the batch, single figures of a +percent, not the kernel-sized 17 to 20% this pairing's verify forward +pays. + +## Gate recipes: which env reaches which kernel + +Issue #1261's description of its mixed-workload arm reads +"`MLXCEL_MTP_ALLOW_INEXACT=1` with the switch left wide", and +`docs/benchmarks.md` said reproducing the pre-gate fast rows "needs +`MLXCEL_MTP_ALLOW_INEXACT=1`". Both descriptions predate what #1199's +merged ordering actually does: `mtp_exactness_gate` runs +`retry_without_qmv_wide` **before** `allow_inexact()` is ever consulted, +and the override feeds only the engage/decline decision, never the kernel +switch. So on a host where the narrow retry passes, which is every +generation 15+ host measured so far, the override alone is inert: the +retry pins the process narrow first and the flag is never load-bearing. + +Verified live with all four recipes on the pairing #1258 measured +(`gemma-4-12b-it-4bit` + 4-bit assistant, block 5, the +`bench_speculative.sh` code prompt, 300 tokens, offline CLI, two +interleaved samples per recipe): + +| recipe | gate log line | kernel served | tok/s | +|---|---|---|---:| +| default env | INFO "probe failed under qmv_wide ... Disabling qmv_wide for this process" | narrow, byte-identity kept | 117.29, 116.98 | +| `MLXCEL_MTP_ALLOW_INEXACT=1` | the same INFO retry line; the ALLOW_INEXACT warning never fires | narrow, byte-identity kept | 117.14, 116.85 | +| `MLXCEL_QMV_WIDE=1 MLXCEL_MTP_ALLOW_INEXACT=1` | WARN "probe FAILED but MLXCEL_MTP_ALLOW_INEXACT is set" | wide, inexact | 139.18, 139.12 | +| `MLXCEL_QMV_WIDE=1` | WARN "retry was skipped because MLXCEL_QMV_WIDE is pinned"; the CLI declines MTP | none (classic decode only) | declined | + +Three independent lines of evidence agree: + +- **The log lines.** The override-alone run logs the retry's INFO line and + never the loud warning, which is the gate saying the flag did nothing. +- **The bytes.** The default run and the override-alone run produce + **byte-identical generated text**, both samples; the pinned-wide run + diverges from them six words in ("write this function" versus + "implement this"), which is the same divergence + `docs/benchmarks.md` records for this host's fast kernel. +- **The throughput.** 117 versus 139 tok/s reproduces the byte-identical + and fast-kernel figures (117.5 / 138.5) that `docs/benchmarks.md` + carries for this pairing on this host. + +So the working recipes on generation 15+ are: default env for exact MTP on +the narrow kernel; `MLXCEL_QMV_WIDE=1` alone to keep the wide kernel and +give up MTP; both together to research the fast kernel with MTP and give +up byte-identity. `MLXCEL_MTP_ALLOW_INEXACT` alone remains meaningful only +where both kernels diverge, so no exact configuration exists (the +pre-#1199 state of generation 15+, and any future hardware whose narrow +arm also fails the probe). `docs/environment-variables.md` and +`docs/benchmarks.md` now say this; the throughput tables in #1199 and +#1258 whose `MLXCEL_MTP_ALLOW_INEXACT=1` rows say "fast kernel" describe +the pre-merge gate and carry a correction note. The measured mixed arm B +above uses the corrected recipe. + +## What this settles, and what would reopen it + +Issue #1261's acceptance criteria, against this record: + +1. **The B = 2/4/8 batched-decode tax is measured on a generation 15+ + host**: at most 1%, spreads at or under 1%, two families, structural + mechanism identified. The real collateral tax is +15.4 ms per cache-hit + suffix prefill forward, +33% on this harness's cache-hit TTFT. +2. **The tax is documented as accepted, with the number**: this document. + Scoping the exact kernel to the verify forward (the issue's Step 2) is + not built, per the issue's own exit condition. The per-request cost is + tens of milliseconds of TTFT on cache-hit requests and nothing + measurable anywhere else in serving today. +3. **The probe measures the same kernel configuration the verify forward + serves with**: unchanged and true by construction. The pin is + process-wide and never restored, so probe-time selection and serve-time + selection cannot differ; under `MLXCEL_QMV_WIDE=1 + MLXCEL_MTP_ALLOW_INEXACT=1` the probe measures wide and the process + serves wide. Step 2 designs were what could have broken this, and none + shipped. + +What would reopen Step 2: **a real joint batched decode for an MTP +family.** The moment Gemma 4 or Qwen 3.5 stacks decode rows into one +`M = B` forward the way Gemma 3 and Llama 4 already do, batched decode +lands in the qmv window and the pin starts taxing it at whatever the +kernel gap is at that `M` (the op-level data in `docs/benchmarks.md` +measures 1.7 to 1.9x on verify forwards at `M` = 10 to 13). Whoever builds +that should rerun this sweep, expect a material number, and only then +weigh the issue's Step 2 candidates. Until then the narrow pin's collateral +is priced: 15.4 ms per cache-hit prefill, zero on decode. diff --git a/docs/benchmarks.md b/docs/benchmarks.md index d50ddba80..3da17a7f5 100644 --- a/docs/benchmarks.md +++ b/docs/benchmarks.md @@ -639,7 +639,10 @@ width 2 because MLX routes `M >= 2` quantized projections to a different reduction. The 12 is the `d` entry for this target's largest projections rather than a generation constant: the same table reads 6 for those shapes on a non-`d` generation 13 part, and 18 for this target's attention projections -on either. A declining probe falls back to classic decode unless +on either. A probe that diverges under `qmv_wide` retries with it disabled +and keeps the narrow kernel when that restores exactness (#1199), which is +what happens on every generation 15+ host measured so far; only a probe +that diverges both ways falls back to classic decode, unless `MLXCEL_MTP_ALLOW_INEXACT=1` is set. B=1 (single-request) MTP runs by default for every MTP target; the Gemma 4 Unified target cannot batch at all, so B=1 is also its only decode path. The batch-capable 31B + bf16 @@ -651,10 +654,17 @@ does not pay for itself. The Gemma 4 rows above were measured before the #1188 gate landed, so they are the fast kernel rather than the byte-identical one; with the gate in place the default on generation 15+ is the byte-identical kernel, and reproducing the -fast rows needs `MLXCEL_MTP_ALLOW_INEXACT=1`. Keeping byte-identity on the -code row, by dropping -`qmv_wide`, measures 93.2 tok/s instead of 121.0 on M5 Max, or 2.14x instead of -2.79x, and 117.5 tok/s instead of 138.5 on M3 Ultra, 1.83x instead of 2.16x. +fast rows needs `MLXCEL_QMV_WIDE=1` together with `MLXCEL_MTP_ALLOW_INEXACT=1` +(the pin keeps the gate's retry from dropping `qmv_wide`, and the override +engages MTP anyway). `MLXCEL_MTP_ALLOW_INEXACT=1` alone does not reach them: +the retry runs before the override is consulted, pins the process narrow, and +produces output byte-identical to the default env, measured at the +byte-identical rows' own throughput (verified live on M3 Ultra 2026-08-22, +117 vs 139 tok/s on the 12B pairing; see +[qmv-wide-pin-tax-m3ultra-2026-08-22](benchmark_results/qmv-wide-pin-tax-m3ultra-2026-08-22.md)). +Keeping byte-identity on the code row, by dropping `qmv_wide`, measures 93.2 +tok/s instead of 121.0 on M5 Max, or 2.14x instead of 2.79x, and 117.5 tok/s +instead of 138.5 on M3 Ultra, 1.83x instead of 2.16x. That is 23% of throughput on one host and 15% on the other, which is not the same quantity as the 17 to 20% the probe quotes for the Qwen pairing: the probe is costing the verify forward, while these figures are end-to-end decode, @@ -770,6 +780,13 @@ by failing under `qmv_wide` and disabling it for the process. One generation per arm reproduces any of this, and the M3 Ultra source-code row parts 22 bytes in. +What the rest of a process pinned narrow pays is measured in +[qmv-wide-pin-tax-m3ultra-2026-08-22](benchmark_results/qmv-wide-pin-tax-m3ultra-2026-08-22.md) +(issue #1261): batched decode loses at most 1% at B = 2 to 8, because both +MTP families decode batches as per-row `M = 1` forwards that never reach +`qmv_wide`; the one real collateral cost is about 15 ms per prompt-cache-hit +request, whose short adopted-suffix prefill lands in the qmv window. + Two things will make that diff lie if they are not handled. The MTP arm prints its drafter loader lines *after* `Generating...` and immediately after the echoed prompt, so a naive diff reports a divergence at byte 1 that is only the diff --git a/docs/environment-variables.md b/docs/environment-variables.md index 36a485e45..1ba409e1e 100644 --- a/docs/environment-variables.md +++ b/docs/environment-variables.md @@ -186,7 +186,8 @@ The OpenAI audio endpoints (`/v1/audio/speech`, `/v1/audio/transcriptions`, `/v1 | `MLXCEL_ENABLE_MTP_DEFERRED` | `1` | off | **Advanced.** Enables the deferred greedy verifier path for Gemma 4 MTP when sampling settings allow it. | | `MLXCEL_METAL4_ATTENTION` | `0`/`false`/`no`/`off` to disable; unset or any other value to enable | on (where the hardware has it) | **Advanced, diagnostic kill switch.** Forces the M5 neural-accelerator fused attention route off on hardware that has it, so `layers::metal4_causal_attention` is skipped and the ordinary SDPA path runs instead. Off-switch only: it cannot turn the route on where `has_neural_accelerator && macos_supports_na` is false, so setting it on an M1 is inert. This route is the first suspect whenever an M5 disagrees numerically with an earlier Apple GPU generation (issue #1065), and before this switch the only way to A/B the hypothesis was to patch `should_use_metal4_attention` and rebuild, which is what the #1182 M5 investigation had to do. Read once per process, so set it before starting `mlxcel` or `mlxcel-server`. Inert on non-Metal builds. | | `MLXCEL_GDN_CHAIN_PARITY` | `0` to disable, any other value (or unset) to enable | on | **Advanced, diagnostic escape hatch.** Gates the chain-parity gated-delta Metal kernel used by Qwen 3.5 MTP's speculative verify and rollback-replay paths (issue #1165). The standard gated-delta kernel carries float32 recurrent state across a `T = K` verify block and rounds it to the storage dtype only once at the end, while the classic single-token decode chain rounds after every token; a `T = K` verify block is therefore NOT bit-identical to `K` consecutive single-token decode steps unless the state is rounded per in-block step. The chain-parity kernel (`gated_delta_step_seqpar`) does that rounding, which is what makes Qwen 3.5 MTP's temperature-0 output byte-identical to classic decode. **Setting this to `0` forfeits that exactness contract**, restoring the pre-#1165 block numerics for A/B attribution of the parity kernel's own cost and acceptance effect; do not set it to `0` in a deployment that needs byte-identical speculative output. Metal-only: the non-Metal ops fallback ignores the flag (the parity guarantee does not exist off Metal today). **The kernel is necessary but not sufficient**: byte-identity also requires every quantized projection to dispatch to the same MLX kernel at `M = block_size` as at `M = 1`, which is not true on every GPU generation or at every block width, so the runtime probe behind `MLXCEL_MTP_ALLOW_INEXACT` is what actually decides whether MTP engages. See `docs/benchmark_results/qwen38-mtp-m1ultra-2026-08-16.md` for the measured kernel cost (inside the dispatch-noise band). | -| `MLXCEL_MTP_ALLOW_INEXACT` | `1`/`true`/`yes`/`on` to enable; unset or anything else to disable | **off** | Engage Qwen 3.5 MTP speculative decoding even when the startup exactness probe reports that the multi-token verify block is **not** byte-identical to the single-token decode chain. Before enabling MTP the runtime now measures the property instead of predicting it: one synthetic verify block and the equivalent single-token chain are run from the same state on the loaded checkpoint at the configured `--draft-block-size`, and their logits are compared byte for byte (three independent synthetic inputs, each two short prefills plus `K + 1` forwards; measured 4.9 s for the first call and 1.3 s for a later one per input on a Qwen3.8-27B 4-bit target on an M1 Ultra, the difference being MLX's one-time kernel compilation; more than one input because a kernel pair can disagree by only a byte or two out of ten thousand, at which amplitude a single draw can read as equal; memoized per (model, block width) and warmed at worker startup so it never lands on the request path). A divergence means temperature-0 speculative output would silently differ from `mlxcel generate` without `--draft-model`, so the default is to decline and run classic decode. The static conditions (Metal backend, `supports_metal_gated_delta_kernel` geometry) still apply and are checked first; this probe covers what they cannot, namely which MLX kernel each **quantized projection** dispatches to at `M = K` versus `M = 1`. That choice depends on the GPU generation, the quantization mode, the operand sizes and the block width: `use_qmv_wide` in [`mlx/backend/metal/quantized.cpp`](https://github.com/ml-explore/mlx/blob/main/mlx/backend/metal/quantized.cpp) sends `M >= 2` to a different reduction whenever `mode != "affine" || arch_gen >= 15`, and `get_qmv_batch_limit` sends `M` above 10, 12, 18 or 32 (by architecture size and generation) to the matrix-matrix kernel. Measured: an affine 4-bit Qwen3.8-27B target on an M1 Ultra is byte-identical at block widths 1 through 11 and diverges at 12 (the `arch_size == 'd'` branch); the same checkpoint on an M5 Max diverges from block width 2, where the `M >= 2` split fires before any batch limit can be observed. Within one checkpoint the limit is per projection, not per model: Gemma 4 12B's attention shapes hold to 17 on an M1 Ultra while its MLP shapes break at 12, so a model's own cliff is the minimum over its shapes, which is why this is measured rather than tabulated. Set this to `1` when researching MTP throughput on hardware where the probe declines, accepting that the byte-identity contract no longer holds; the decline and the override are both logged at WARN with the differing-byte count. Read once per process. | +| `MLXCEL_MTP_ALLOW_INEXACT` | `1`/`true`/`yes`/`on` to enable; unset or anything else to disable | **off** | Engage Qwen 3.5 MTP speculative decoding even when the startup exactness probe reports that the multi-token verify block is **not** byte-identical to the single-token decode chain. Before enabling MTP the runtime now measures the property instead of predicting it: one synthetic verify block and the equivalent single-token chain are run from the same state on the loaded checkpoint at the configured `--draft-block-size`, and their logits are compared byte for byte (three independent synthetic inputs, each two short prefills plus `K + 1` forwards; measured 4.9 s for the first call and 1.3 s for a later one per input on a Qwen3.8-27B 4-bit target on an M1 Ultra, the difference being MLX's one-time kernel compilation; more than one input because a kernel pair can disagree by only a byte or two out of ten thousand, at which amplitude a single draw can read as equal; memoized per (model, block width) and warmed at worker startup so it never lands on the request path). A divergence means temperature-0 speculative output would silently differ from `mlxcel generate` without `--draft-model`, so the default is to decline and run classic decode. The static conditions (Metal backend, `supports_metal_gated_delta_kernel` geometry) still apply and are checked first; this probe covers what they cannot, namely which MLX kernel each **quantized projection** dispatches to at `M = K` versus `M = 1`. That choice depends on the GPU generation, the quantization mode, the operand sizes and the block width: `use_qmv_wide` in [`mlx/backend/metal/quantized.cpp`](https://github.com/ml-explore/mlx/blob/main/mlx/backend/metal/quantized.cpp) sends `M >= 2` to a different reduction whenever `mode != "affine" || arch_gen >= 15`, and `get_qmv_batch_limit` sends `M` above 10, 12, 18 or 32 (by architecture size and generation) to the matrix-matrix kernel. Measured: an affine 4-bit Qwen3.8-27B target on an M1 Ultra is byte-identical at block widths 1 through 11 and diverges at 12 (the `arch_size == 'd'` branch); the same checkpoint on an M5 Max diverges from block width 2, where the `M >= 2` split fires before any batch limit can be observed. Within one checkpoint the limit is per projection, not per model: Gemma 4 12B's attention shapes hold to 17 on an M1 Ultra while its MLP shapes break at 12, so a model's own cliff is the minimum over its shapes, which is why this is measured rather than tabulated. Note the ordering that #1199 introduced: on a failing probe the gate first retries with `qmv_wide` disabled and keeps the narrow kernel when that restores exactness, and only a probe that fails **both** ways consults this flag. On Apple GPU generation 15+ the narrow retry passes, so this flag alone is inert there: the process is pinned narrow, output stays byte-identical, and the log shows the retry's INFO line rather than the override warning (verified live on M3 Ultra, 2026-08-22, byte-identical output with and without the flag; see `benchmark_results/qmv-wide-pin-tax-m3ultra-2026-08-22.md`). To research the fast kernel there, set `MLXCEL_QMV_WIDE=1` together with this flag: the pin skips the retry and this flag then engages MTP on the wide kernel, forfeiting byte-identity with the loud WARN. This flag alone is load-bearing only where no exact kernel selection exists at the configured block width. Read once per process. | +| `MLXCEL_QMV_WIDE` | `0`/`false`/`no`/`off` to disable; `1` (or any other value) to pin wide | unset (wide, until the MTP gate's retry turns it off) | Operator pin for MLX's `qmv_wide` kernel, the faster reduction for `M >= 2` quantized matmuls on Apple GPU generation 15+ (overlay in `src/lib/mlx-cpp/patches/mlx/backend/metal/quantized.cpp`, added by #1199). **Setting the variable at all, to any value, counts as an operator pin**: the MTP exactness gate's retry (`retry_without_qmv_wide`) is skipped in both directions, so `MLXCEL_QMV_WIDE=1` keeps the wide kernel and makes a failing probe decline MTP instead of buying exactness back, and `MLXCEL_QMV_WIDE=0` runs the whole process narrow from the start. Unset, the kernel is wide until a failing MTP probe's retry finds the narrow kernel exact and pins the process narrow for good. The pin is process-wide and sits on the dispatch path of every quantized matmul; what non-MTP work pays for the narrow state is measured in `benchmark_results/qmv-wide-pin-tax-m3ultra-2026-08-22.md` (nothing measurable on batched decode, about 15 ms per prompt-cache-hit request's suffix prefill). Read once per process at first dispatch; `mlxcel_core::set_qmv_wide` can move it at runtime and the gate is its only caller. | | `MLXCEL_MTP_TICK_SLICE` | `0`/`false`/`no`/`off` to disable, any other value (or unset) to enable | on | Tick-cooperative B=1 MTP serving (issue #734). When on (the default), a B=1 MTP request on the Gemma 4 family is served one speculative round per scheduler tick, alternating with the classic decode/prefill actions, so concurrent classic-decode rows advance between rounds and the head-of-line stall a speculative request imposes drops from the whole burst to about one round (`burst_wall_ms` in the finalize log reports the max single-tick wall). Tokens stream per round instead of in one end-of-burst lump. Set to an off value to restore the legacy run-to-completion burst (the whole request served inside one tick). The interleaving trades roughly 27% of the speculative request's own aggregate decode throughput (cross-tick round gaps) for that bounded stall, so a deployment serving speculative requests without concurrent classic traffic can turn it off to keep the full-throughput burst. Greedy output, acceptance accounting, and every other env gate are unchanged in both modes; DFlash and the batched B>1 paths always run to completion regardless of this flag. | | `MLXCEL_MTP_SLICE_GRANT_ROUNDS` | non-negative integer | `8` | Grant budget for one hold of the tick-slice speculative slot (issue #746), counted in executed slices (slice 0, the prefill + seed, counts as the first slice of a grant). While a slice is in flight, up to 2 further tick-slice-eligible requests park in a grant backlog instead of permanently falling back to classic decode; once the active request has run this many slices with the backlog non-empty, it parks at the next round boundary and the slot is granted to the next request (priority lane first, FIFO within a lane, with an anti-starvation floor: an entry passed over by 2 grant decisions is granted next regardless of lane), so concurrent long streams share speculative acceleration in bounded turns. The budget is read once per grant and per admission decision (cached for the per-round expiry check), so changes apply from the next grant. The budget binds only under contention: a single speculative request never rotates and behaves exactly as under #734. Rotation preserves per-request token streams byte-identically (the drafter is re-armed from the session's own stored verify output at every round). `0` disables rotation and restores the pre-#746 behavior: the active request holds the slot for its whole generation and every concurrent speculative request falls back to classic decode. Unparseable values fall back to the default. | | `MLXCEL_SPECULATIVE_STOCHASTIC_ACCEPT` | `1`/`true`/`yes`/`on` to enable; unset or anything else to disable | **off** | Acceptance-optimal speculative acceptance for the classic `SpeculativeGenerator` path (offline `mlxcel generate --draft-model`), issue #902. When on, `temperature > 0` verification uses modified rejection sampling (accept the drafted token `t` iff `u * q(t) <= p(t)` for a fresh `u ~ U[0,1)`, and on the first rejection emit a draw from the normalized residual `relu(p - q)`) instead of the default sampler-match rule (accept iff the draft equals an independent draw from the target sampler). **Both rules are distribution-preserving**: the emitted stream is a target-only sample either way, which is the central correction to the issue's premise. What changes is the acceptance probability, which rises from `sum_x p(x) q(x)` to `sum_x min(p(x), q(x))`, the maximal-coupling ceiling for any correct rule. **Opt-in rather than default** because the gain is the ratio between those two quantities and it collapses toward 1 whenever the drafter is confident (`q(t*) ~ 1` makes `min(p, q)` and `p * q` coincide); measured at about 1.02 on a Llama-3.1-8B / Llama-3.2-1B pair at temperature 0.7, which does not pay for two extra full-vocabulary passes and a host sync per verified position. Check the available gain with `MLXCEL_SPECULATIVE_ACCEPT_DIAG=1` before enabling. Enabling changes the RNG stream, so at an equal seed the emitted tokens differ from a default run even though the distribution is identical. Greedy (`temperature == 0` or `top_k == 1`) never reaches either rule and is byte-identical. The Gemma 4 MTP and DFlash round loops are unaffected: they select the target token by argmax regardless of temperature, so this switch is inert there. `SpeculativeGenerator::with_stochastic_acceptance(bool)` overrides it programmatically. Read once per process. See [`speculative-acceptance.md`](speculative-acceptance.md). | diff --git a/scripts/bench_qmv_pin_mixed.py b/scripts/bench_qmv_pin_mixed.py new file mode 100755 index 000000000..0e3cb6159 --- /dev/null +++ b/scripts/bench_qmv_pin_mixed.py @@ -0,0 +1,464 @@ +#!/usr/bin/env python3 +"""Mixed-workload client for the qmv_wide narrow-pin tax (issue #1261). + +One MTP stream plus N classic streams against a running ``mlxcel-server``, +reading the classic streams' decode throughput only. This is the second arm +of the issue #1261 measurement: the B-sweep (``bench_qmv_wide_pin.sh sweep``) +prices the narrow pin on batched decode in isolation, and this harness prices +it in the mixed shape the pin actually arises in, where an MTP stream bought +byte-identity for itself and everything admitted beside it pays the kernel. + +How the two request classes are kept distinct, since with a drafter loaded +every eligible request wants speculative service: the server must run with +``MLXCEL_MTP_SLICE_GRANT_ROUNDS=0``, which disables slice-slot rotation +(issue #746). The first stream then holds the tick-cooperative MTP slice +slot for its whole generation, and every eligible request arriving while the +slot is busy falls back to classic decode, exactly the pre-#746 behaviour. +That gives one MTP stream and N classic rows deterministically, with the +same env in both kernel arms so the comparison isolates the kernel. + +Phases: + +1. Wait for the server to answer ``/v1/models``. +2. Start ONE long streaming request (the MTP stream) and wait for its first + token. On the first window of a server process this includes the + exactness probe. Then wait ``--settle-s`` so the slice loop is steady. +3. Fire ``--classic-streams`` identical streaming requests concurrently + (the classic streams) and record each one's TTFT and decode rate. +4. When the last classic stream finishes, close the MTP stream's connection + and report. A window is only valid on two counts: the MTP stream was + still decoding when the last classic stream finished, and that stream + then actually drained. The overlap fraction is printed and checked so a + window that quietly lost its MTP stream cannot pass as a mixed + measurement, and a stream still running after the close is failed too, + because it may still hold the slice slot the next window needs, which + would make the next window's "MTP stream" a classic one. + +The classic streams' decode tok/s is the reported quantity. The MTP +stream's own throughput is deliberately not compared across kernel arms: +its generated text differs between them by construction. + +Only the Python standard library is used, matching the sibling harnesses +(``bench_serving_concurrency.py``, ``bench_mixed_step_admission.py``). + +The pairing must be one whose narrow retry actually passes on the host, or +arm A has no pin to price; on M3 Ultra that is the Qwen pairing (the Gemma +31B + bf16 pairing probes non-identical under both kernels there and +declines MTP). + +Example (arm A, the default-env narrow pin): + MLXCEL_MTP_SLICE_GRANT_ROUNDS=0 MLXCEL_ENABLE_MTP_B1=1 MLXCEL_MTP_ADAPTIVE=0 \ + target/release/mlxcel-server -m models/qwen3.8-27b-4bit \ + --model-draft models/qwen3.8-27b-mtp-4bit \ + --draft-block-size 3 --parallel 8 --metrics --port 8114 & + python3 scripts/bench_qmv_pin_mixed.py --port 8114 --classic-streams 4 +""" + +from __future__ import annotations + +import argparse +import http.client +import json +import sys +import threading +import time +from dataclasses import dataclass + + +@dataclass +class StreamResult: + """Timing of one streaming request.""" + + ok: bool + ttft_s: float | None = None + decode_tok_s: float | None = None + completion_tokens: int = 0 + start_s: float = 0.0 + first_token_s: float = 0.0 + end_s: float = 0.0 + error: str | None = None + + +_BASE_SENTENCE = ( + "The quick brown fox jumps over the lazy dog while the benchmark harness " + "measures prefill and decode throughput under concurrent streaming load. " +) +_TOKENS_PER_WORD = 1.3 + +_MTP_PROMPT = ( + "Write a long, detailed essay about the history of numerical computing, " + "covering mechanical calculators, the stored-program concept, floating " + "point arithmetic, vector supercomputers, and modern accelerators. Use " + "flowing prose with no lists." +) + + +def build_prompt(prompt_tokens: int) -> str: + words_per_copy = len(_BASE_SENTENCE.split()) + target_words = max(words_per_copy, int(prompt_tokens / _TOKENS_PER_WORD)) + copies = max(1, target_words // words_per_copy + 1) + return (_BASE_SENTENCE * copies).strip() + + +def wait_ready(host: str, port: int, timeout_s: float) -> str: + """Poll ``/v1/models`` until it answers, returning the model id.""" + deadline = time.monotonic() + timeout_s + while time.monotonic() < deadline: + try: + conn = http.client.HTTPConnection(host, port, timeout=5) + conn.request("GET", "/v1/models") + resp = conn.getresponse() + body = resp.read() + conn.close() + if resp.status == 200: + data = json.loads(body) + models = data.get("data") or [] + if models and models[0].get("id"): + return str(models[0]["id"]) + return "default" + except (OSError, ValueError): + pass + time.sleep(1.0) + raise SystemExit(f"server on {host}:{port} not ready after {timeout_s:.0f}s") + + +class StreamRunner(threading.Thread): + """One streaming chat completion on its own thread. + + ``stop()`` closes the connection from the client side, which is how the + MTP stream is ended once the classic window has been measured. + """ + + def __init__( + self, + host: str, + port: int, + model: str, + prompt: str, + max_tokens: int, + timeout: float, + ) -> None: + super().__init__(daemon=True) + self._host = host + self._port = port + self._model = model + self._prompt = prompt + self._max_tokens = max_tokens + self._timeout = timeout + self._conn: http.client.HTTPConnection | None = None + self._stop_event = threading.Event() + self.result = StreamResult(ok=False, error="not started") + self.first_token = threading.Event() + self.last_token_s = 0.0 + + def stop(self) -> None: + self._stop_event.set() + conn = self._conn + if conn is not None: + try: + conn.close() + except OSError: + pass + + def run(self) -> None: # noqa: C901 - one linear protocol loop + payload = json.dumps( + { + "model": self._model, + "messages": [{"role": "user", "content": self._prompt}], + "max_tokens": self._max_tokens, + "temperature": 0.0, + "stream": True, + "stream_options": {"include_usage": True}, + } + ) + headers = {"Content-Type": "application/json", "Accept": "text/event-stream"} + start = time.perf_counter() + ttft: float | None = None + delta_tokens = 0 + usage_tokens: int | None = None + stopped_by: str | None = None + try: + self._conn = http.client.HTTPConnection( + self._host, self._port, timeout=self._timeout + ) + self._conn.request( + "POST", "/v1/chat/completions", body=payload, headers=headers + ) + resp = self._conn.getresponse() + if resp.status != 200: + body = resp.read().decode("utf-8", "replace")[:200] + self.result = StreamResult(ok=False, error=f"HTTP {resp.status}: {body}") + return + buf = b"" + while not self._stop_event.is_set(): + chunk = resp.read(1) + if not chunk: + break + buf += chunk + if not buf.endswith(b"\n"): + continue + line = buf.strip() + buf = b"" + if not line.startswith(b"data:"): + continue + data = line[len(b"data:") :].strip() + if data == b"[DONE]": + break + try: + event = json.loads(data) + except ValueError: + continue + usage = event.get("usage") + if isinstance(usage, dict) and usage.get("completion_tokens") is not None: + try: + usage_tokens = int(usage["completion_tokens"]) + except (TypeError, ValueError): + # A malformed usage block should not discard a window + # that otherwise measured fine, and TypeError is not in + # the except tuple below, so it would kill this thread + # and leave the initial "not started" result standing. + # delta_tokens is the fallback count. + pass + for choice in event.get("choices", []) or []: + delta = choice.get("delta") or {} + # Reasoning models stream their thinking channel as + # `reasoning_content`; both channels are decoded tokens + # (same fix as bench_serving_concurrency.py). + content = delta.get("content") or delta.get("reasoning_content") + if content: + now = time.perf_counter() + if ttft is None: + ttft = now - start + self.first_token.set() + self.last_token_s = now + delta_tokens += 1 + except (OSError, http.client.HTTPException, AttributeError, ValueError) as exc: + # AttributeError / ValueError cover the race where stop() + # closes the connection while the read loop is inside + # http.client (its file object becomes None mid-read); a + # stop-induced close is expected for the MTP stream and its + # partial stats below are still the measurement. What ended the + # stream is recorded rather than discarded, because the same tuple + # also catches a genuine bug in the parsing above (an AttributeError + # from a typo, say), which would otherwise be indistinguishable + # from a clean stop. + if not self._stop_event.is_set(): + self.result = StreamResult(ok=False, error=str(exc)) + return + stopped_by = str(exc) + finally: + if self._conn is not None: + try: + self._conn.close() + except OSError: + pass + + end = time.perf_counter() + completion_tokens = usage_tokens if usage_tokens is not None else delta_tokens + decode_tok_s: float | None = None + if ttft is not None and completion_tokens > 1: + span = (self.last_token_s or end) - (start + ttft) + if span > 0: + decode_tok_s = (completion_tokens - 1) / span + self.result = StreamResult( + ok=True, + ttft_s=ttft, + decode_tok_s=decode_tok_s, + completion_tokens=completion_tokens, + start_s=start, + first_token_s=start + (ttft or 0.0), + end_s=end, + error=stopped_by, + ) + + +def run_window(args: argparse.Namespace, model: str, window: int) -> dict: + """One mixed window: MTP stream up, then N classic streams measured.""" + mtp = StreamRunner( + args.host, args.port, model, _MTP_PROMPT, args.mtp_max_tokens, args.timeout + ) + mtp_started = time.perf_counter() + mtp.start() + if not mtp.first_token.wait(timeout=args.mtp_first_token_timeout): + mtp.stop() + mtp.join(timeout=10) + raise SystemExit( + f"window {window}: MTP stream produced no token within " + f"{args.mtp_first_token_timeout:.0f}s ({mtp.result.error})" + ) + mtp_ttft = time.perf_counter() - mtp_started + time.sleep(args.settle_s) + + prompt = build_prompt(args.classic_prompt_tokens) + classics = [ + StreamRunner( + args.host, args.port, model, prompt, args.classic_max_tokens, args.timeout + ) + for _ in range(args.classic_streams) + ] + classic_start = time.perf_counter() + for c in classics: + c.start() + for c in classics: + c.join() + classic_end = time.perf_counter() + + # The MTP stream must have outlived the classic window for the window to + # count as mixed. last_token_s is the wall-clock of its latest token. + mtp_alive_until = mtp.last_token_s + mtp.stop() + mtp.join(timeout=15) + # The stream must also have ended before the next window starts. A thread + # still alive here means the request may still hold the tick-cooperative + # slice slot, so the next window's "MTP stream" would arrive to a busy slot + # and fall back to classic decode: a different shape, measured under the + # same label. That is exactly the silent change the overlap check exists to + # catch, so leakage fails the window too. + mtp_drained = not mtp.is_alive() + if not mtp_drained: + print( + f"window {window}: MTP stream did not end within 15s of being " + "closed; it may still hold the slice slot, so the next window's " + "shape is not trustworthy", + file=sys.stderr, + flush=True, + ) + + window_span = classic_end - classic_start + overlap = 0.0 + if window_span > 0: + overlap = max(0.0, min(mtp_alive_until, classic_end) - classic_start) + overlap /= window_span + valid = overlap >= args.min_overlap and mtp_drained + + rows = [] + for i, c in enumerate(classics): + r = c.result + rows.append( + { + "stream": i, + "ok": r.ok, + "ttft_s": round(r.ttft_s, 3) if r.ttft_s is not None else None, + "decode_tok_s": round(r.decode_tok_s, 2) + if r.decode_tok_s is not None + else None, + "completion_tokens": r.completion_tokens, + # Carried even when ok, because a successful stream now records + # whatever exception ended its read loop. + "error": r.error, + } + ) + ok_rates = [ + r["decode_tok_s"] + for r in rows + if r["ok"] and r["decode_tok_s"] is not None + ] + summary = { + "window": window, + "valid": valid, + "overlap": round(overlap, 3), + "mtp_drained": mtp_drained, + "mtp_ttft_s": round(mtp_ttft, 3), + "mtp_tokens_in_window": mtp.result.completion_tokens, + "classic_streams": args.classic_streams, + "classic_mean_decode_tok_s": round(sum(ok_rates) / len(ok_rates), 2) + if ok_rates + else None, + "classic_aggregate_tok_s": round( + sum( + (r["completion_tokens"] - 1) + for r in rows + if r["ok"] and r["completion_tokens"] > 1 + ) + / window_span, + 2, + ) + if window_span > 0 + else None, + "window_span_s": round(window_span, 2), + "streams": rows, + } + return summary + + +def main() -> int: + parser = argparse.ArgumentParser( + description="One MTP stream plus N classic streams (issue #1261 arm 2)." + ) + parser.add_argument("--host", default="127.0.0.1") + parser.add_argument("--port", type=int, default=8080) + parser.add_argument("--model", default=None) + parser.add_argument( + "--windows", + type=int, + default=1, + help="Mixed windows to run back to back (default: 1)", + ) + parser.add_argument( + "--classic-streams", + type=int, + default=4, + help="Concurrent classic streams per window (default: 4)", + ) + parser.add_argument("--classic-prompt-tokens", type=int, default=512) + parser.add_argument("--classic-max-tokens", type=int, default=256) + parser.add_argument( + "--mtp-max-tokens", + type=int, + default=3000, + help="Token budget for the MTP stream; it is closed once the classic " + "window ends, so this only needs to outlast the window (default: 3000)", + ) + parser.add_argument( + "--mtp-first-token-timeout", + type=float, + default=420.0, + help="The first window's MTP TTFT includes the one-time exactness " + "probe (and, in the default-env arm, its retry), which on a 31B " + "target takes tens of seconds (default: 420)", + ) + parser.add_argument( + "--settle-s", + type=float, + default=2.0, + help="Delay between the MTP stream's first token and the classic " + "window, so the slice loop is steady (default: 2)", + ) + parser.add_argument( + "--min-overlap", + type=float, + default=0.95, + help="Minimum fraction of the classic window the MTP stream must have " + "been decoding for; below it the window is reported invalid " + "(default: 0.95)", + ) + parser.add_argument("--timeout", type=float, default=600.0) + parser.add_argument("--ready-timeout", type=float, default=600.0) + args = parser.parse_args() + + model = args.model or wait_ready(args.host, args.port, args.ready_timeout) + print(f"Server: http://{args.host}:{args.port}") + print(f"Model: {model}") + print( + f"Windows: {args.windows}, classic streams per window: " + f"{args.classic_streams} x {args.classic_max_tokens} tokens" + ) + + any_valid = False + for w in range(args.windows): + summary = run_window(args, model, w) + any_valid = any_valid or summary["valid"] + print(f"RESULT {json.dumps(summary)}", flush=True) + mean = summary["classic_mean_decode_tok_s"] + print( + f"window {w}: valid={summary['valid']} overlap={summary['overlap']} " + f"classic mean decode {mean} tok/s over " + f"{summary['window_span_s']}s, MTP emitted " + f"{summary['mtp_tokens_in_window']} tokens", + flush=True, + ) + return 0 if any_valid else 1 + + +if __name__ == "__main__": + sys.exit(main()) diff --git a/scripts/bench_qmv_wide_pin.sh b/scripts/bench_qmv_wide_pin.sh new file mode 100755 index 000000000..e5be2334a --- /dev/null +++ b/scripts/bench_qmv_wide_pin.sh @@ -0,0 +1,313 @@ +#!/usr/bin/env bash +# Measure the collateral cost of the process-wide qmv_wide narrow pin +# (issue #1261) on a generation 15+ host. +# +# Two modes, one per arm of the issue's Step 1: +# +# ./scripts/bench_qmv_wide_pin.sh sweep # batched-decode B-sweep, no drafter +# ./scripts/bench_qmv_wide_pin.sh mixed # one MTP stream + N classic streams +# +# sweep: boots mlxcel-server on the batch-capable target WITHOUT a drafter, +# alternating MLXCEL_QMV_WIDE=1 (wide) and =0 (narrow) boots in ABBA order. +# Pinning the env in BOTH arms is what keeps them on different kernels: any +# value of MLXCEL_QMV_WIDE counts as an operator pin +# (`qmv_wide_pinned_by_operator` in src/models/speculative_exactness.rs), so +# the exactness gate's retry can never flip an arm mid-run, and with no +# drafter loaded the gate has no probe to run in the first place. Each boot +# runs one discarded warm-up pass and MEASURE_PASSES measured passes; a pass +# is the B = 1,2,4,8 ladder plus a long-context B=4 cell. +# +# mixed: boots a target WITH its drafter, alternating the default env +# (arm A: the gate's retry pins the process narrow) and +# MLXCEL_QMV_WIDE=1 MLXCEL_MTP_ALLOW_INEXACT=1 (arm B: the operator pin skips +# the retry and the override engages MTP on the wide kernel). Note the arm B +# recipe needs BOTH variables: MLXCEL_MTP_ALLOW_INEXACT=1 alone does not +# leave the switch wide, because the gate's retry runs before the override is +# consulted and pins the process narrow itself. The pairing must be one whose +# narrow retry actually passes on the host, or arm A has no pin to price; on +# M3 Ultra that is the Qwen pairing, and the 2026-08-22 run used +# +# TARGET=models/qwen3.8-27b-4bit DRAFTER=models/qwen3.8-27b-mtp-4bit \ +# DRAFT_BLOCK=3 ./scripts/bench_qmv_wide_pin.sh mixed +# +# (the default Gemma 31B + bf16 pairing probes non-identical under BOTH +# kernels there and declines MTP; see +# docs/benchmark_results/qmv-wide-pin-tax-m3ultra-2026-08-22.md). +# Every boot also runs with +# MLXCEL_MTP_SLICE_GRANT_ROUNDS=0 so the first stream holds the speculative +# slot for its whole generation and the N concurrent streams fall back to +# classic decode (the pre-#746 behaviour), which is what makes "one MTP +# stream plus N classic streams" a deterministic shape. After each boot the +# server log is grepped for the exactness-gate lines so the arm identity is +# evidenced, not assumed. +# +# Protocol (docs/benchmarks.md): ABBA boot order against thermal drift, +# warm-up passes discarded, spreads reported by the analysis step, and the +# whole invocation belongs under scripts/with_indexers_paused.sh: +# +# INDEXER_RESUME_DEADLINE=7200 ./scripts/with_indexers_paused.sh \ +# ./scripts/bench_qmv_wide_pin.sh sweep +# +# Output: one directory per invocation under bench-results/qmv-wide-pin/, +# holding the raw per-pass tables, the server logs, the gate-line evidence +# and an environment record. Nothing is aggregated here; aggregation belongs +# to the write-up so that discarded samples stay visible. + +set -uo pipefail + +REPO="$(cd "$(dirname "$0")/.." && pwd)" +BIN="$REPO/target/release/mlxcel-server" +MODE="${1:-}" +if [ "$MODE" != "sweep" ] && [ "$MODE" != "mixed" ]; then + echo "usage: $0 sweep|mixed" >&2 + exit 2 +fi + +TARGET="${TARGET:-$REPO/models/gemma-4-31b-it-4bit}" +DRAFTER="${DRAFTER:-$REPO/models/gemma-4-31b-it-assistant-bf16}" +DRAFT_BLOCK="${DRAFT_BLOCK:-4}" +PORT="${PORT:-8113}" +PARALLEL="${PARALLEL:-8}" +MEASURE_PASSES="${MEASURE_PASSES:-2}" +# ABBA blocks; sweep arms are qmv_wide pins, mixed arms are gate recipes. +SWEEP_ARMS="${SWEEP_ARMS:-1 0 0 1 0 1 1 0}" +MIXED_ARMS="${MIXED_ARMS:-A B B A}" +CLASSIC_STREAMS="${CLASSIC_STREAMS:-4}" +# Seconds a server gets to honour SIGTERM before the harness escalates to SIGKILL. +SHUTDOWN_GRACE_S="${SHUTDOWN_GRACE_S:-60}" + +# Preflight the binary. Without it the first symptom is record_env's stat +# failing, then every boot failing in turn, and the operator has to read a +# server log to find out that nothing was ever built. +if [ ! -x "$BIN" ]; then + echo "server binary not found at $BIN; build with:" >&2 + echo " cargo build --release --features metal,accelerate" >&2 + exit 2 +fi + +# The arms are defined by the environment, so an inherited value silently +# redefines them: run_mixed's arm A is "the default env" and run_sweep assumes +# these two are the only things that differ between boots. Testing a gate +# recipe by hand is exactly how this measurement's own recipes were checked +# (see the results record), and an export left behind by that would make both +# arms the same arm while the run still reports success. +if [ -n "${MLXCEL_QMV_WIDE+set}" ] || [ -n "${MLXCEL_MTP_ALLOW_INEXACT+set}" ]; then + echo "the arms are defined by MLXCEL_QMV_WIDE and MLXCEL_MTP_ALLOW_INEXACT, but this shell already exports:" >&2 + echo " MLXCEL_QMV_WIDE=${MLXCEL_QMV_WIDE-} MLXCEL_MTP_ALLOW_INEXACT=${MLXCEL_MTP_ALLOW_INEXACT-}" >&2 + echo "an inherited value collapses both arms onto one kernel; unset them and rerun" >&2 + exit 2 +fi + +# Refuse to run against a server this script did not boot. If something already +# holds $PORT (typically a server leaked by an aborted run) every launch below +# dies on EADDRINUSE while wait_ready happily probes the survivor, so both arms +# measure the same kernel and the run still reports success. That silently +# destroys the only thing the ABBA design establishes, so abort instead. +if curl -sf -m 5 "http://127.0.0.1:$PORT/v1/models" >/dev/null 2>&1; then + echo "something is already serving on port $PORT; stop it or run with PORT=" >&2 + exit 2 +fi + +STAMP="$(date +%Y%m%d-%H%M%S)" +OUT="${OUT:-$REPO/bench-results/qmv-wide-pin/$MODE-$STAMP}" +# This script does not use `set -e`, so a failed mkdir would leave every +# redirect below failing silently while the servers still boot: hours of +# measurement discarded as it is produced. +mkdir -p "$OUT" || exit 1 + +SERVER_PID="" +# Counts python3 harness invocations that exited non-zero, so an unbalanced +# design cannot be mistaken for a complete one at aggregation time. +HARNESS_FAILURES=0 + +# Stop the current server and make sure it is really gone. SIGTERM first so +# the server can release the model cleanly; escalate to SIGKILL if it is +# wedged, because an unbounded wait here would hang the harness with tens of +# GB of unified memory still held. SERVER_PID is cleared before returning so +# a second call (signal handler, then the EXIT trap) can never signal a PID +# the OS has recycled. +kill_server() { + local pid="$SERVER_PID" + SERVER_PID="" + [ -n "$pid" ] || return 0 + kill -0 "$pid" 2>/dev/null || { wait "$pid" 2>/dev/null; return 0; } + kill -TERM "$pid" 2>/dev/null + local waited=0 + while [ "$waited" -lt "$SHUTDOWN_GRACE_S" ] && kill -0 "$pid" 2>/dev/null; do + sleep 1 + waited=$((waited + 1)) + done + if kill -0 "$pid" 2>/dev/null; then + echo "server $pid ignored SIGTERM after ${SHUTDOWN_GRACE_S}s; sending SIGKILL" >&2 + kill -KILL "$pid" 2>/dev/null + fi + wait "$pid" 2>/dev/null +} + +cleanup() { + kill_server +} +# The signal handlers exit rather than fall through. A bash handler that just +# returns resumes the script where the signal interrupted it, so a Ctrl-C part +# way through an ABBA run would kill the current server and then boot the next +# arm instead of aborting. HUP is trapped for the same reason an SSH drop or a +# closed terminal must not leave a 31B server holding tens of GB of unified +# memory. +trap cleanup EXIT +trap 'cleanup; echo "Interrupted (signal received)" >&2; exit 130' INT TERM HUP + +record_env() { + { + echo "mode: $MODE" + echo "date: $(date -u +%Y-%m-%dT%H:%M:%SZ)" + echo "host: $(sysctl -n machdep.cpu.brand_string), $(sysctl -n hw.memsize | awk '{print $1/1073741824 " GB"}')" + echo "macos: $(sw_vers -productVersion) ($(sw_vers -buildVersion))" + echo "branch: $(git -C "$REPO" rev-parse --abbrev-ref HEAD) at $(git -C "$REPO" rev-parse --short HEAD)" + echo "binary: $BIN ($(stat -f %Sm "$BIN"))" + echo "target: $TARGET" + [ "$MODE" = "mixed" ] && echo "drafter: $DRAFTER" + echo "parallel: $PARALLEL, port: $PORT, measured passes per boot: $MEASURE_PASSES" + echo "arms: $([ "$MODE" = "sweep" ] && echo "$SWEEP_ARMS" || echo "$MIXED_ARMS")" + echo "time machine running: $(tmutil status 2>/dev/null | grep Running | tr -cd '0-9')" + # Recorded rather than assumed: any of these inherited from the operator's + # shell reaches every boot, so the record has to show what the arms + # actually ran under. + echo "inherited env: $(env | grep -E '^(MLXCEL_|MLX_|LLAMA_ARG_)' | sort | tr '\n' ' ')" + } > "$OUT/env.txt" +} + +wait_ready() { + local deadline=$((SECONDS + 600)) + while [ $SECONDS -lt $deadline ]; do + # Liveness before readiness. A curl success proves only that something is + # answering on $PORT, not that it is the boot we just launched, so a boot + # that died on EADDRINUSE against a stale server must be reported dead + # here rather than silently measured as this arm. + if [ -n "$SERVER_PID" ] && ! kill -0 "$SERVER_PID" 2>/dev/null; then + echo "server died during startup; see the *-server.log files in $OUT" >&2 + return 1 + fi + if curl -sf -m 5 "http://127.0.0.1:$PORT/v1/models" >/dev/null 2>&1; then + return 0 + fi + sleep 2 + done + echo "server not ready after 600s" >&2 + return 1 +} + +stop_server() { + kill_server + # Let the port close and the GPU settle between boots. + sleep 5 +} + +run_sweep() { + local boot=0 arm rc + for arm in $SWEEP_ARMS; do + # SWEEP_ARMS is deliberately word-split, which also glob-expands, and each + # token then lands in an output path below. Reject anything unexpected so a + # typo or a stray `/` cannot write outside $OUT. + case "$arm" in + 0|1) ;; + *) echo "invalid SWEEP_ARMS entry '$arm' (expected 0 or 1)" >&2; exit 2 ;; + esac + boot=$((boot + 1)) + local label="boot${boot}-wide${arm}" + echo "=== $label: MLXCEL_QMV_WIDE=$arm ===" + MLXCEL_QMV_WIDE="$arm" "$BIN" -m "$TARGET" --port "$PORT" \ + --parallel "$PARALLEL" --metrics \ + > "$OUT/$label-server.log" 2>&1 & + SERVER_PID=$! + wait_ready || exit 1 + + local pass + for pass in $(seq 0 "$MEASURE_PASSES"); do + local tag="$label-pass$pass" + [ "$pass" = 0 ] && tag="$label-warmup" + # A harness that errors out leaves a traceback in its output file while + # the ABBA loop marches on, which costs one arm a sample and is invisible + # at aggregation time. Record the failure both in the file and in the + # run-level counter so it cannot be missed. + python3 "$REPO/scripts/bench_serving_concurrency.py" --port "$PORT" \ + --concurrency 1,2,4,8 --prompt-tokens 512 --max-tokens 256 --metrics \ + > "$OUT/$tag.txt" 2>&1 + rc=$? + if [ "$rc" -ne 0 ]; then + echo " harness failed for $tag (rc=$rc)" >&2 + echo "HARNESS-FAILED rc=$rc" >> "$OUT/$tag.txt" + HARNESS_FAILURES=$((HARNESS_FAILURES + 1)) + fi + python3 "$REPO/scripts/bench_serving_concurrency.py" --port "$PORT" \ + --concurrency 4 --prompt-tokens 4096 --max-tokens 256 --metrics \ + > "$OUT/$tag-long.txt" 2>&1 + rc=$? + if [ "$rc" -ne 0 ]; then + echo " harness failed for $tag-long (rc=$rc)" >&2 + echo "HARNESS-FAILED rc=$rc" >> "$OUT/$tag-long.txt" + HARNESS_FAILURES=$((HARNESS_FAILURES + 1)) + fi + echo " pass $pass done" + done + stop_server + done +} + +run_mixed() { + local boot=0 arm rc + for arm in $MIXED_ARMS; do + # MIXED_ARMS is deliberately word-split, which also glob-expands, and each + # token then lands in an output path below. Reject anything unexpected so a + # typo or a stray `/` cannot write outside $OUT. + case "$arm" in + A|B) ;; + *) echo "invalid MIXED_ARMS entry '$arm' (expected A or B)" >&2; exit 2 ;; + esac + boot=$((boot + 1)) + local label="boot${boot}-arm${arm}" + echo "=== $label ===" + # Scheduler debug logging is on in BOTH arms (identical overhead) so the + # "falls back to classic decode" lines evidence the N classic rows. + local -a env_pairs=( + MLXCEL_ENABLE_MTP_B1=1 MLXCEL_MTP_ADAPTIVE=0 MLXCEL_MTP_SLICE_GRANT_ROUNDS=0 + "RUST_LOG=info,mlxcel::server::batch::scheduler=debug" + ) + if [ "$arm" = "B" ]; then + env_pairs+=(MLXCEL_QMV_WIDE=1 MLXCEL_MTP_ALLOW_INEXACT=1) + fi + env "${env_pairs[@]}" "$BIN" -m "$TARGET" --model-draft "$DRAFTER" \ + --draft-block-size "$DRAFT_BLOCK" --port "$PORT" --parallel "$PARALLEL" --metrics \ + > "$OUT/$label-server.log" 2>&1 & + SERVER_PID=$! + wait_ready || exit 1 + + # Window 0 is the warm-up (it also pays the one-time exactness probe); + # the rest are the measured windows. + python3 "$REPO/scripts/bench_qmv_pin_mixed.py" --port "$PORT" \ + --windows $((MEASURE_PASSES + 1)) --classic-streams "$CLASSIC_STREAMS" \ + > "$OUT/$label-windows.txt" 2>&1 + rc=$? + # A non-zero exit means the harness gave up (no MTP token in time, or no + # valid window), so this boot contributed nothing. Mark it in the file and + # in the counter rather than letting the loop hide the lost sample. + if [ "$rc" -ne 0 ]; then + echo " harness failed for $label (rc=$rc)" >&2 + echo "HARNESS-FAILED rc=$rc" >> "$OUT/$label-windows.txt" + HARNESS_FAILURES=$((HARNESS_FAILURES + 1)) + fi + stop_server + + # Arm identity is evidenced by which exactness-gate line the boot logged. + grep -E "exactness probe|qmv_wide|ALLOW_INEXACT|falls back to classic|falling back to classic|slot busy" \ + "$OUT/$label-server.log" > "$OUT/$label-gate.txt" || true + done +} + +record_env +if [ "$MODE" = "sweep" ]; then run_sweep; else run_mixed; fi +echo "results in $OUT" +# run_sweep and run_mixed run in the current shell, not a subshell, so the +# counter they incremented is the one read here. +if [ "$HARNESS_FAILURES" -ne 0 ]; then + echo "WARNING: $HARNESS_FAILURES harness invocation(s) failed; arms are not balanced, see the HARNESS-FAILED markers" >&2 +fi diff --git a/scripts/bench_serving_concurrency.py b/scripts/bench_serving_concurrency.py index 2be7afd61..7a704ebd6 100755 --- a/scripts/bench_serving_concurrency.py +++ b/scripts/bench_serving_concurrency.py @@ -195,9 +195,26 @@ def stream_request( continue usage = event.get("usage") if isinstance(usage, dict) and usage.get("completion_tokens") is not None: - usage_tokens = int(usage["completion_tokens"]) + try: + usage_tokens = int(usage["completion_tokens"]) + except (TypeError, ValueError): + # A malformed usage block must not end the sweep. Neither + # TypeError nor ValueError is in the except tuple below, so + # this would propagate out of the executor, through the + # gather in run_level, and abort every remaining + # concurrency level of the pass, discarding a measurement + # that had already run for minutes. delta_tokens is the + # fallback count. + pass for choice in event.get("choices", []) or []: - content = (choice.get("delta") or {}).get("content") + delta = choice.get("delta") or {} + # Reasoning models stream their thinking channel as + # `reasoning_content` deltas; counting only `content` would + # report no TTFT and no decode rate at all for a request + # that spends its whole budget thinking (issue #1261 hit + # exactly this on Qwen 3.8). Both channels are decoded + # tokens, so both count. + content = delta.get("content") or delta.get("reasoning_content") if content: if ttft is None: ttft = time.perf_counter() - start diff --git a/scripts/with_indexers_paused.sh b/scripts/with_indexers_paused.sh index 1aea42d10..7ac0e8bb9 100755 --- a/scripts/with_indexers_paused.sh +++ b/scripts/with_indexers_paused.sh @@ -29,23 +29,38 @@ # Three independent paths resume the daemons, because leaving one stopped is # worse than any measurement is worth: # -# 1. a trap on EXIT, INT, TERM and HUP, covering a normal end and a Ctrl-C; +# 1. a trap on EXIT, INT, TERM, HUP and QUIT, covering a normal end, a +# Ctrl-C and a Ctrl-\ quit; # 2. that same trap on a failed command, since the trap is on EXIT; # 3. a detached deadline resume, so even SIGKILL of this wrapper cannot -# leave anything stopped. +# leave anything stopped. It is retired by path 1 on any ending that +# reaches the trap, so a clean run does not leave it resident. # -# A daemon that was already suspended before this ran is left alone, so two -# nested invocations cannot resume each other's work early. +# A daemon that was already suspended before this ran is left alone, so this +# never takes over a suspension someone else owns. That guard is at suspend +# time only: a long-lived daemon that several sequential runs each stopped is +# on each of their resume lists, so a later run's resume does reach an earlier +# run's entry. That direction is harmless, since SIGCONT to a running process +# is a no-op, but it is not an isolation guarantee and should not be read as +# one. set -uo pipefail -DEADLINE=${INDEXER_RESUME_DEADLINE:-2700} # seconds; the backstop resume - if [ $# -eq 0 ]; then sed -n '2,8p' "$0" exit 1 fi +DEADLINE=${INDEXER_RESUME_DEADLINE:-2700} # seconds; the backstop resume +# Validated before it is used anywhere. The value reaches a detached `bash -c` +# below, so anything but a plain count of seconds is either a shell injection +# or a backstop that never fires. Zero is rejected too: it would resume the +# daemons the instant they were suspended. +case "$DEADLINE" in + ''|*[!0-9]*) echo "INDEXER_RESUME_DEADLINE must be a whole number of seconds, got '$DEADLINE'" >&2; exit 2 ;; +esac +[ "$DEADLINE" -gt 0 ] || { echo "INDEXER_RESUME_DEADLINE must be greater than 0" >&2; exit 2; } + # One process name per line, because a desktop app's name can contain a space. # # `corespotlightd` coordinates and `mdworker` does the indexing, so suspending @@ -82,7 +97,13 @@ if [ -n "${INDEXER_EXTRA_NAMES:-}" ]; then $INDEXER_EXTRA_NAMES" fi -PIDFILE=$(mktemp "${TMPDIR:-/tmp}/paused_indexers.XXXXXX") +# Without a resume list nothing can undo a suspension: the trap and the +# detached backstop both read this file. An unchecked mktemp leaves PIDFILE +# empty and the daemons stopped with their pids recorded nowhere, so refuse to +# suspend anything at all rather than risk that. +PIDFILE=$(mktemp "${TMPDIR:-/tmp}/paused_indexers.XXXXXX") || { echo "cannot create the resume list; refusing to suspend anything" >&2; exit 1; } + +BACKSTOP_PID="" resume() { local pid @@ -90,8 +111,21 @@ resume() { [ -n "$pid" ] && kill -CONT "$pid" 2>/dev/null && echo "resumed $pid" >&2 done < "$PIDFILE" command rm -f "$PIDFILE" + # The backstop exists only for an ending that never reaches this trap, and + # this trap just ran, so retire it instead of leaving a bash and a sleep + # resident for the rest of the deadline. Eight of them were found on the + # 2026-08-22 measurement host, one per run, the oldest 2h41m old. A stale one + # is not only litter: it wakes hours later and signals pids the OS may have + # recycled by then. The sleep goes first because it is a child of the + # backstop shell and would outlive it, and the pid list is already unlinked + # above, so whichever half wins the race has nothing left to act on. + if [ -n "$BACKSTOP_PID" ]; then + pkill -P "$BACKSTOP_PID" 2>/dev/null + kill "$BACKSTOP_PID" 2>/dev/null + BACKSTOP_PID="" + fi } -trap resume EXIT INT TERM HUP +trap resume EXIT INT TERM HUP QUIT while IFS= read -r n; do [ -n "$n" ] || continue @@ -100,8 +134,17 @@ while IFS= read -r n; do case "$(ps -o state= -p "$pid" 2>/dev/null)" in T*) echo "$n ($pid) was already suspended, leaving it alone" >&2; continue ;; esac + # Record first, suspend second. A write that failed after the STOP would + # leave a suspended daemon whose pid is on no list, and neither the trap + # nor the detached backstop could reach it. The reverse ordering is safe: + # a pid recorded for a STOP that then failed only earns a SIGCONT to a + # process that was already running, and daemons someone else suspended are + # skipped above, so this cannot resume another run's work. + if ! echo "$pid" >> "$PIDFILE"; then + echo "cannot record $n ($pid) in the resume list; aborting before suspending it" >&2 + exit 1 + fi if kill -STOP "$pid" 2>/dev/null; then - echo "$pid" >> "$PIDFILE" echo "suspended $n ($pid)" >&2 else echo "cannot signal $n ($pid), leaving it alone" >&2 @@ -112,9 +155,13 @@ $NAMES EOF # Backstop. Detached and holding only the file path, so a SIGKILL of this -# shell still leaves something that will resume the list. -nohup bash -c "sleep $DEADLINE -while read -r p; do kill -CONT \"\$p\" 2>/dev/null; done < '$PIDFILE' 2>/dev/null" \ - >/dev/null 2>&1 & +# shell still leaves something that will resume the list. The deadline and the +# path are passed as arguments rather than spliced into the program text, so +# neither an operator-supplied deadline nor a TMPDIR containing a quote can +# become code in a process that outlives this shell. +nohup bash -c 'sleep "$1" +while read -r p; do kill -CONT "$p" 2>/dev/null; done < "$2" 2>/dev/null' \ + _ "$DEADLINE" "$PIDFILE" >/dev/null 2>&1 & +BACKSTOP_PID=$! "$@"