Pull requests / #1864
#1864 Report pending swap and adaptive join times in serial decode timing
open · @SanghunYun · 0 comments · View on GitHub
BenchmarksServer & APIMulti-GPUAMD / HIPNVIDIA / CUDADocumentationWindows
Description
## Title Issue: Resolves #1863 ## Summary The serial `--serve` breakdown printed by `STRATA_DECODE_TIMING=1` omits pending expert swap application before verify and the synchronous adaptive-worker join after draft, although both are included in total decode time. On v0.1.42 (`61b3fb5d`), release → patched build → release runs of the same public request reported about 54ms/window in total, while the existing three sections explained about 42ms/window. This change records the two intervals in execution order on the same line. ## What changed - `src/program/generate.cpp`: time the pending-swap branch and the actual `adapt_thr.join()` call in the serial serve loop. Keep each serial/pipeline timing line in one `fprintf` call. - `docs/DETAILS.md`: explain the new fields, averaging, scope and parser compatibility. - `bench/decode_timing_probe.py`: send the public document-based request and print its response hash. - Routing, expert swap behavior and defaults are unchanged. Additional clock reads only run when the existing timing option is enabled. ### Time missing from the existing breakdown Each difference below is the release run's total minus its three printed sections. Verify's parenthesized values are its internal details and are not added again. | Run | Total decode | Existing sections | Time outside the breakdown | |---|---:|---:|---:| | v0.1.42 before | 53.54 ms/window | verify 38.69 + commit/emit 0.05 + draft 2.88 = 41.62 | **11.92 ms/window** | | v0.1.42 after | 54.03 ms/window | verify 38.97 + commit/emit 0.05 + draft 2.85 = 41.87 | **12.16 ms/window** | ### Sections in execution order | Order | Section | What it covers | Release before (ms/window) | Patched (ms/window) | |---:|---|---|---:|---:| | 1 | `swap apply` | Apply previously prepared swaps: GPU completion synchronization, RAM exchange commit and residency updates | **Not listed** | **5.37** | | 2 | `verify` | Verify the current window's tokens | 38.69 | 38.56 | | 3 | `commit/emit` | Commit and emit accepted tokens | 0.05 | 0.05 | | 4 | `draft` | Generate candidates for the next window | 2.88 | 2.87 | | 5 | `adapt join` | Wait for the synchronous worker, which overlaps commit/draft | **Not listed** | **6.91** | | — | `other` | Total minus the measured sections | Not included in breakdown | 0.00 | | | **Total** | Elapsed time within the existing decode timer's scope | **53.54** | **53.76** | | New timer | Start → end | Meaning | |---|---|---| | `swap apply` | Enter the pending-swap branch before verify → leave the branch, including any `apply_pending()` call | Host elapsed time in the swap-application path | | `adapt join` | Immediately before an actual `adapt_thr.join()` → immediately after it returns | The caller's wait, excluding the worker's earlier parallel runtime | Both use `steady_clock` and are averaged over all decode windows. `joins` counts actual joins. These are host elapsed times, not pure GPU DMA durations. Output excerpt, with verify's internal details omitted: ```text 53.76 ms/window = swap apply 5.37 + verify 38.56 (...) + commit/emit 0.05 + draft 2.87 + adapt join 6.91 + other 0.00; 28 joins ``` In this run, the five measured sections sum to 53.76ms/window without adding `other`. Rounding can produce differences in general. `other` is a residual, not an independent timer; separate work such as PCIe auto adjustment and async ticks remains there. The release differences and patched measurements come from separate runs, so they need not match exactly. ## Extra Notes The three timing-on runs each processed 4,489 input tokens, 256 output tokens and 115 windows. I also ran release → patched build → release with timing off and checked identical response-content SHA-256 hashes and absence of timing lines. Request bodies and response-content hashes matched across all six runs. This checks response content, not the complete JSON, token IDs or logits. | Backend | Build validation | Runtime validation | |---|---|---| | CUDA (sm_86) | v0.1.42-based Release build and default host test passed | Timing-on output and timing-off response identity checked | | HIP (ROCm 7.10.0a20251120, gfx1100) | v0.1.42-based Release compilation/linking and default host test passed | AMD GPU inference not run | Test conditions: RTX 3060 12GB, 32GB system RAM, Ubuntu 26.04, Qwen3.8 Flash-Next IQ2_XS; 3,196 actual VRAM expert slots (4,200 requested), 20.5GiB resident RAM, KV `k8v4`, `--spec 3 --mtp-max-t 3 --spec-min-p 0.5`. Synchronous adaptation (`--adapt-async` unset), the same static expert profile, profile saving and `STRATA_RAM_ADAPT` off, `STRATA_PREFILL_CPU_SHARE=0`, `STRATA_IQ_MT_MIN=1`, GPU verify profiling off. Each run used a fresh process and reused zero prompt tokens; OS page cache was not flushed. Vision was configured but no images were sent. The public helper was run directly against the upstream v0.1.42 Python server. Start a fresh server with the same settings and `STRATA_DECODE_TIMING=1` for the timing-on check, then send: ```bash python bench/decode_timing_probe.py --url http://127.0.0.1:8080/v1/chat/completions ``` The helper reads the first 12,000 characters of the checkout's `docs/DETAILS.md`, so use the same document input for comparisons. This portion matched between the tested release and patch. Zero reused tokens were verified in the engine log rather than relying on `cache_prompt=false` alone. SYCL uses its separate generate source and is not changed. Multi-GPU/pipeline/batch runtime was not tested. Pipeline retains its existing timing format. Serial parsers that require `ms/window = verify` must accept `ms/window = swap apply`.
Related on strata.com
Editorial links to help you install, pick models, or read release notes — not part of the upstream thread.