diff --git a/server/CMakeLists.txt b/server/CMakeLists.txt index a07701382..e4aea666a 100644 --- a/server/CMakeLists.txt +++ b/server/CMakeLists.txt @@ -254,6 +254,7 @@ add_library(dflash_common STATIC # DeepSeek V4 Flash target arch src/deepseek4/deepseek4_loader.cpp src/deepseek4/deepseek4_graph.cpp + src/deepseek4/deepseek4_gpu_profiler.cpp src/deepseek4/deepseek4_backend.cpp src/deepseek4/deepseek4_daemon.cpp src/deepseek4/deepseek4_layer_split_adapter.cpp @@ -388,7 +389,7 @@ endif() if(DFLASH27B_GPU_BACKEND STREQUAL "cuda") target_link_libraries(dflash_common PUBLIC CUDA::cudart) elseif(DFLASH27B_GPU_BACKEND STREQUAL "hip") - target_link_libraries(dflash_common PUBLIC hip::host) + target_link_libraries(dflash_common PUBLIC hip::host ${CMAKE_DL_LIBS}) endif() # FlashPrefill custom kernels. diff --git a/server/docs/DS4.md b/server/docs/DS4.md index aae2b62b1..a4f2659c4 100644 --- a/server/docs/DS4.md +++ b/server/docs/DS4.md @@ -129,6 +129,7 @@ The runtime logs the chosen split with a `[deepseek4-split] auto-split:` banner. | Variable | Purpose | |----------|---------| | `DFLASH_DS4_CUDA_LAYERS` | Override the auto-split heuristic and pin the first `N` DeepSeek4 layers to CUDA. The remaining `43 - N` layers run on the Halo shard. | +| `DFLASH_DS4_GPU_PROFILE` | Enable HIP-event phase records and ROCTX ranges for DS4 forward and verification work. Default off; `0` is disabled. | | `DFLASH_DS4_TIMING` | Enable DS4 timing logs for the layer-split parent and target-shard daemon. Useful for profiling prefill/decode breakdowns; leave unset for normal runs. | `DFLASH_DS4_TIMING` enables the existing timing banners: @@ -136,6 +137,19 @@ The runtime logs the chosen split with a `[deepseek4-split] auto-split:` banner. - parent / local shard: `[deepseek4-split-timing]` - remote Halo shard: `[deepseek4-target-timing]` +`DFLASH_DS4_GPU_PROFILE=1` emits stable records with the prefix +`[ds4-gpu-profile]`, `clock=hip_event`, a scope and mode, a phase name, token +width and position, GPU elapsed milliseconds, and the number of timed calls. +Records from `deepseek4_step_layer_range` also carry the `layers=-` +range so shards are distinguishable in a layer-split run. +Core exact-verification phases are `hc_pre`, `attention`, `moe_ffn`, `hc_post`, +and `output_projection`; phases with no HIP work report zero calls. Exact +verification also emits `verification_step`. Fused decode and the explicit +approximate fused-verification research path emit whole-graph records because +their phase boundaries are inside one captured graph. When `libroctx64` is +available, the same phase names are pushed as ROCTX ranges; builds and runs do +not require the library. + DeepSeek4 no longer uses the old expert-split environment variables or expert-worker tuning knobs. Those retired knobs were removed from the codebase rather than left behind as unsupported debug switches. ## DSpark Speculative Decode @@ -183,13 +197,13 @@ export DFLASH_DS4_SPEC_Q=4 --ds4-expert-top-k 4 ``` -`DFLASH_DS4_FUSED_VERIFY=1` is the opt-in throughput profile. Its persistent -whole-model GPU graph uses stable padded reduction shapes, so near-tied greedy -logits can select a different token than the normal causal verifier even at -temperature 0. Leave it unset when comparing against the normal verifier, or -set `DFLASH_DS4_SEQ_VERIFY=1` for the slower token-at-a-time verification -diagnostic. Neither fused verification nor the separate -`--ds4-expert-top-k 4` approximation should be presented as byte-identical AR. +`DFLASH_DS4_FUSED_VERIFY=1` requests the fused throughput profile, but falls +back to the normal verifier because the persistent whole-model GPU graph can +select a different greedy token at near-tied logits. The approximate graph is +available only for explicit research runs by also setting +`DFLASH_DS4_ALLOW_APPROX_FUSED_VERIFY=1`; it must not be presented as +byte-identical. `DFLASH_DS4_SEQ_VERIFY=1` remains the slower token-at-a-time +diagnostic. The separate `--ds4-expert-top-k 4` policy is also approximate. DSpark currently requires monolithic target placement. On HIP, `--ds4-fused-decode` selects that placement; if the target falls back to hybrid @@ -216,6 +230,8 @@ confidence of the proposed prefix. It adds the projection to the same fused Markov graph and reads its scores in the existing token-id synchronization; no additional host round trip is introduced. Artifacts without a compatible confidence head transparently retain the existing acceptance-EWMA policy. +Set `DFLASH_DS4_ADAPTIVE_WIDTH=0` to hold the verify width fixed for parity +tests; the environment value takes precedence over the legacy `/tmp` control. On the gfx1151 validation host, confidence-adaptive width retained 10/10 GSM+Math accuracy and measured 31.94 tok/s weighted, within 0.6% of fixed q=4 diff --git a/server/docs/ENVIRONMENT.md b/server/docs/ENVIRONMENT.md index 77d9dc77b..cc6fa7e87 100644 --- a/server/docs/ENVIRONMENT.md +++ b/server/docs/ENVIRONMENT.md @@ -25,11 +25,15 @@ consolidation of this list into CLI flags is tracked as follow-up work. | `DFLASH_ADAPTIVE_K_DENSE` | per-model default | CSV of MoE layers kept dense under adaptive-K (DFlash capture layers). Warned-inert on families that do not thread layer indices yet. | | `DFLASH_MMID_GROUPED` | unset | Grouped MUL_MAT_ID kernel for small verify batches; candidate for CLI promotion. | | `DFLASH_MMID_TELEMETRY` | unset | DEBUG: report MUL_MAT_ID dispatch, MMVQ variant, and per-node graph compatibility. | +| `DFLASH_DS4_GPU_PROFILE` | unset | DEBUG: HIP-event DS4 phase timings and optional ROCTX ranges. `0` is disabled. | +| `DFLASH_DS4_PARITY_TRACE` | unset | DEBUG: generated IDs plus per-row top-two logits for verified tokens. Scans the full vocabulary per row and prints one stderr line per row, so keep it to short debug runs. | | `DFLASH_KVFLASH` | unset | Prefer the CLI: `--kvflash` (token count or `auto`). | ## Full inventory (generated) `grep -rE 'getenv\("[A-Z0-9_]+"\)' server/src` - regenerate when adding or removing variables. +Variables read through wrapper helpers (for example `ds4_env_flag`, `spec_env_flag`, +`env_flag_enabled`) do not match that grep; their inventory entries are curated manually. - `DFLASH27B_CHUNKED` - qwen35_target_graph.cpp - `DFLASH27B_DRAFT_FP16` - draft_safetensors_loader.cpp @@ -57,6 +61,8 @@ consolidation of this list into CLI flags is tracked as follow-up work. - `DFLASH_DRAFT_KV` - laguna_backend.cpp, qwen35_backend.cpp - `DFLASH_DRAFT_PERSIST` - laguna_backend.cpp - `DFLASH_DROP_COLD` - qwen35moe_backend.cpp, qwen35moe_pipelined_decode.cpp +- `DFLASH_DS4_GPU_PROFILE` - deepseek4_graph.cpp, deepseek4_dspark_spec.cpp +- `DFLASH_DS4_PARITY_TRACE` - deepseek4_backend.cpp, deepseek4_dspark_spec.cpp - `DFLASH_DS4_TIMING` - deepseek4_target_shard_ipc_daemon.cpp - `DFLASH_EXPERT_BUDGET_MB` - deepseek4_backend.cpp, laguna_backend.cpp, qwen35moe_backend.cpp - `DFLASH_EXPERT_BUDGET_PCT` - laguna_backend.cpp diff --git a/server/scripts/test_ds4_fused_verify_parity.py b/server/scripts/test_ds4_fused_verify_parity.py new file mode 100644 index 000000000..ccfc3c202 --- /dev/null +++ b/server/scripts/test_ds4_fused_verify_parity.py @@ -0,0 +1,137 @@ +#!/usr/bin/env python3 +"""Model-backed token parity regression for the public DS4 fused-verify flag.""" + +from __future__ import annotations + +import argparse +import json +import os +import re +import subprocess +import tempfile +import time +import urllib.request +from pathlib import Path + + +TOKEN_RE = re.compile(r"\[ds4-parity-tokens\] n=\d+ ids=\[([0-9 ]*)\]") + + +def wait_ready(port: int, proc: subprocess.Popen[bytes], timeout: float) -> None: + deadline = time.monotonic() + timeout + url = f"http://127.0.0.1:{port}/health" + while time.monotonic() < deadline: + if proc.poll() is not None: + raise RuntimeError(f"server exited before readiness: {proc.returncode}") + try: + with urllib.request.urlopen(url, timeout=2) as response: + if response.status == 200: + return + except OSError: + time.sleep(1) + raise TimeoutError(f"server did not become ready within {timeout:.0f}s") + + +def stop_server(proc: subprocess.Popen[bytes]) -> None: + if proc.poll() is not None: + return + proc.terminate() + try: + proc.wait(timeout=30) + except subprocess.TimeoutExpired: + proc.kill() + proc.wait(timeout=10) + + +def run_case(args: argparse.Namespace, fused_requested: bool, log_path: Path) -> list[int]: + env = os.environ.copy() + for name in ( + "DFLASH_DS4_FUSED_VERIFY", + "DFLASH_DS4_ALLOW_APPROX_FUSED_VERIFY", + "DFLASH_DS4_SEQ_VERIFY", + "DFLASH_DS4_DSPARK_DEBUG", + ): + env.pop(name, None) + env.update({ + "DFLASH_DS4_SPEC": "1", + "DFLASH_DS4_DRAFT": str(args.draft), + "DFLASH_DS4_SPEC_Q": "4", + "DFLASH_DS4_ADAPTIVE_WIDTH": "0", + "DFLASH_DS4_PARITY_TRACE": "1", + "LUCE_MMVQ_MAX_NCOLS": "4", + }) + if fused_requested: + env["DFLASH_DS4_FUSED_VERIFY"] = "1" + + cmd = [ + str(args.server_bin), str(args.target), + "--host", "127.0.0.1", "--port", str(args.port), + "--max-ctx", str(args.max_ctx), "--chunk", "512", + "--target-device", "hip:0", "--ds4-fused-decode", + ] + with log_path.open("wb") as log: + proc = subprocess.Popen(cmd, env=env, stdout=log, stderr=subprocess.STDOUT) + try: + wait_ready(args.port, proc, args.startup_timeout) + body = json.dumps({ + "model": "dflash", + "messages": [{"role": "user", "content": args.prompt}], + "temperature": 0, + "seed": 1234, + "max_tokens": args.max_tokens, + "stream": False, + }).encode() + request = urllib.request.Request( + f"http://127.0.0.1:{args.port}/v1/chat/completions", + data=body, + headers={"Content-Type": "application/json"}, + ) + with urllib.request.urlopen(request, timeout=args.request_timeout) as response: + if response.status != 200: + raise RuntimeError(f"generation returned HTTP {response.status}") + json.load(response) + finally: + stop_server(proc) + + matches = TOKEN_RE.findall(log_path.read_text(errors="replace")) + if not matches: + raise RuntimeError(f"token trace missing from {log_path}") + return [int(token) for token in matches[-1].split()] + + +def main() -> int: + parser = argparse.ArgumentParser() + parser.add_argument("--server-bin", required=True, type=Path) + parser.add_argument("--target", required=True, type=Path) + parser.add_argument("--draft", required=True, type=Path) + parser.add_argument("--port", type=int, default=18084) + parser.add_argument("--max-ctx", type=int, default=4096) + parser.add_argument("--max-tokens", type=int, default=32) + parser.add_argument("--startup-timeout", type=float, default=180) + parser.add_argument("--request-timeout", type=float, default=600) + parser.add_argument( + "--prompt", + default="Explain why a bicycle stays upright while moving.", + ) + args = parser.parse_args() + for path in (args.server_bin, args.target, args.draft): + if not path.is_file(): + parser.error(f"file not found: {path}") + + with tempfile.TemporaryDirectory(prefix="ds4-fused-parity-") as tmp: + tmp_path = Path(tmp) + normal = run_case(args, False, tmp_path / "normal.log") + fused_flag = run_case(args, True, tmp_path / "fused-flag.log") + + if normal != fused_flag: + limit = min(len(normal), len(fused_flag)) + first = next((i for i in range(limit) if normal[i] != fused_flag[i]), limit) + print(f"FAIL: first token mismatch at {first}: normal={normal[first:first+4]} " + f"fused_flag={fused_flag[first:first+4]}") + return 1 + print(f"PASS: {len(normal)} generated token IDs are identical") + return 0 + + +if __name__ == "__main__": + raise SystemExit(main()) diff --git a/server/src/deepseek4/deepseek4_backend.cpp b/server/src/deepseek4/deepseek4_backend.cpp index 90e8284fc..08b4d1b93 100644 --- a/server/src/deepseek4/deepseek4_backend.cpp +++ b/server/src/deepseek4/deepseek4_backend.cpp @@ -1040,6 +1040,13 @@ GenerateResult DeepSeek4Backend::generate_impl(const GenerateRequest & req, } result.succeed(); result.tokens = std::move(gen); + if (env_flag_enabled("DFLASH_DS4_PARITY_TRACE")) { + std::fprintf(stderr, "[ds4-parity-tokens] n=%zu ids=[", result.tokens.size()); + for (size_t i = 0; i < result.tokens.size(); ++i) { + std::fprintf(stderr, "%s%d", i == 0 ? "" : " ", result.tokens[i]); + } + std::fprintf(stderr, "]\n"); + } result.decode_s = elapsed_s(t1); result.accept_rate = accept_rate; result.spec_decode_ran = spec_ran; diff --git a/server/src/deepseek4/deepseek4_dspark_spec.cpp b/server/src/deepseek4/deepseek4_dspark_spec.cpp index ddd388a38..1a593f39f 100644 --- a/server/src/deepseek4/deepseek4_dspark_spec.cpp +++ b/server/src/deepseek4/deepseek4_dspark_spec.cpp @@ -22,6 +22,7 @@ // DFLASH_DS4_FULL_SNAP=1 for A/B validation. #include "deepseek4_dspark.h" +#include "deepseek4_gpu_profiler.h" #include "deepseek4_internal.h" #include "internal.h" #include "common/dspark_head.h" @@ -39,6 +40,10 @@ namespace dflash::common { +namespace { +bool spec_env_flag(const char * name); +} + // ── DFlashTarget adapter over the DS4 target ──────────────────────────── class DeepSeek4DFlashTarget : public DFlashTarget { public: @@ -71,7 +76,20 @@ class DeepSeek4DFlashTarget : public DFlashTarget { const char * v = std::getenv("DFLASH_DS4_SEQ_VERIFY"); return v && *v && *v != '0'; }(); + const bool approximate_fused = + spec_env_flag("DFLASH_DS4_FUSED_VERIFY") && + spec_env_flag("DFLASH_DS4_ALLOW_APPROX_FUSED_VERIFY"); + const char * profile_mode = seq_verify ? "exact_sequential" : + (approximate_fused ? "approx_fused" : "exact"); + Ds4GpuProfileOptions profile_opts; + profile_opts.scope = "verification"; + profile_opts.mode = profile_mode; + profile_opts.n_tokens = n; + profile_opts.kv_start = base_pos; + Ds4GpuProfiler verify_profiler( + spec_env_flag("DFLASH_DS4_GPU_PROFILE"), profile_opts); if (seq_verify) { + verify_profiler.begin(Ds4GpuPhase::VerificationStep); std::vector am_all; std::vector feat_all; std::vector logits_all; @@ -98,22 +116,27 @@ class DeepSeek4DFlashTarget : public DFlashTarget { last_tok = am_all.back(); verify_n_ = n; if (all_argmax) *all_argmax = std::move(am_all); + verify_profiler.end(Ds4GpuPhase::VerificationStep); + verify_profiler.emit(); return true; } std::vector am; // n==1 must take the dynamic (non-reuse) path: the reused decode graph // skips the capture/all-logits hooks (backend HC), which this needs. - if (!deepseek4_dspark_verify_forward(backend_, device_, w_, cache_, capture_ids_, - embed_buf_.data(), tokens.data(), n, base_pos, am, - keep_logits_ ? &verify_logits_ : nullptr, - verify_features_, telemetry_, - /*allow_graph_reuse=*/n > 1)) { + verify_profiler.begin(Ds4GpuPhase::VerificationStep); + const bool verify_ok = deepseek4_dspark_verify_forward( + backend_, device_, w_, cache_, capture_ids_, embed_buf_.data(), tokens.data(), + n, base_pos, am, keep_logits_ ? &verify_logits_ : nullptr, + verify_features_, telemetry_, /*allow_graph_reuse=*/n > 1); + verify_profiler.end(Ds4GpuPhase::VerificationStep); + if (!verify_ok) { return false; } if (am.empty()) return false; last_tok = am.back(); verify_n_ = n; if (all_argmax) *all_argmax = std::move(am); + verify_profiler.emit(); return true; } @@ -426,13 +449,17 @@ bool run_deepseek4_dspark_spec_decode( const bool debug = spec_env_flag("DFLASH_DS4_DSPARK_DEBUG"); const bool timing = spec_env_flag("DFLASH_DS4_TIMING"); + const bool parity_trace = spec_env_flag("DFLASH_DS4_PARITY_TRACE"); const bool full_snap = spec_env_flag("DFLASH_DS4_FULL_SNAP"); const bool seq_verify_mode = spec_env_flag("DFLASH_DS4_SEQ_VERIFY"); // Laguna-style adaptive verify width: EWMA of accepted candidates, width = // ewma + 2 (avg_commit << block means the wide tail is usually wasted). // /tmp/ds4_awidth: 1 = on, 0 = off (default on). bool adaptive_width = true; - if (std::FILE * f = std::fopen("/tmp/ds4_awidth", "r")) { + const char * adaptive_env = std::getenv("DFLASH_DS4_ADAPTIVE_WIDTH"); + if (adaptive_env && *adaptive_env) { + adaptive_width = *adaptive_env != '0'; + } else if (std::FILE * f = std::fopen("/tmp/ds4_awidth", "r")) { int v = 1; if (std::fscanf(f, "%d", &v) == 1) adaptive_width = (v != 0); std::fclose(f); @@ -480,6 +507,7 @@ bool run_deepseek4_dspark_spec_decode( DeepSeek4DFlashTarget target(target_w, target_cache, backend, device, snap_backend, drafter.capture_layer_ids, drafter.mask_token_id); + target.set_keep_logits(parity_trace); DraftWeights dw = make_dspark_shim(drafter); DeepSeek4SpecRollback rollback; DeepSeek4StepTelemetry tel{}; @@ -680,6 +708,31 @@ bool run_deepseek4_dspark_spec_decode( } tm_verify += spec_ms_since(t0); + if (parity_trace) { + std::vector trace_logits; + if (target.read_verify_logits(q, trace_logits)) { + for (int row = 0; row < q; ++row) { + const float * logits = trace_logits.data() + (size_t) row * target_w.n_vocab; + int best = 0; + int second = -1; + for (int tok = 1; tok < target_w.n_vocab; ++tok) { + if (logits[tok] > logits[best]) { + second = best; + best = tok; + } else if (second < 0 || logits[tok] > logits[second]) { + second = tok; + } + } + const float second_logit = second >= 0 ? logits[second] : logits[best]; + std::fprintf(stderr, + "[ds4-parity-logits] step=%ld pos=%d row=%d best=%d val=%.9g " + "second=%d val2=%.9g margin=%.9g\n", + steps, pos, row, best, logits[best], second, second_logit, + logits[best] - second_logit); + } + } + } + // Accept the longest matching prefix. accept counts the seed (slot 0) // plus each candidate the target agrees with. int accept = 1; diff --git a/server/src/deepseek4/deepseek4_fused_verify.inc b/server/src/deepseek4/deepseek4_fused_verify.inc index 82b790de7..654dc50bc 100644 --- a/server/src/deepseek4/deepseek4_fused_verify.inc +++ b/server/src/deepseek4/deepseek4_fused_verify.inc @@ -14,7 +14,15 @@ static void ds4_fv_set(ggml_tensor * t, const void * data, size_t nbytes) { static bool ds4_fused_verify_enabled() { static int enabled = -1; if (enabled < 0) { - enabled = ds4_env_flag("DFLASH_DS4_FUSED_VERIFY") ? 1 : 0; + const bool requested = ds4_env_flag("DFLASH_DS4_FUSED_VERIFY"); + const bool allow_approx = ds4_env_flag("DFLASH_DS4_ALLOW_APPROX_FUSED_VERIFY"); + enabled = requested && allow_approx ? 1 : 0; + if (requested && !allow_approx) { + std::fprintf(stderr, + "[ds4-fused-verify] exact token parity is not guaranteed; " + "using the normal verifier. Set DFLASH_DS4_ALLOW_APPROX_FUSED_VERIFY=1 " + "only for explicit approximate experiments.\n"); + } } return enabled == 1; } @@ -506,14 +514,26 @@ static int ds4_try_fused_verify_step( } // ── Compute + read back ── + Ds4GpuProfileOptions profile_opts; + profile_opts.scope = "forward"; + profile_opts.mode = "approx_fused_verify"; + profile_opts.n_tokens = q; + profile_opts.kv_start = kv_start; + Ds4GpuProfiler fused_profiler( + ds4_backend_is_hip(backend) && ds4_env_flag("DFLASH_DS4_GPU_PROFILE"), + profile_opts); + fused_profiler.begin(Ds4GpuPhase::ApproxFusedVerifyGraph); const auto compute_t0 = Ds4TimingClock::now(); - if (ggml_backend_graph_compute(backend, fg->sg.gf) != GGML_STATUS_SUCCESS) { + const ggml_status fused_status = ggml_backend_graph_compute(backend, fg->sg.gf); + if (fused_status != GGML_STATUS_SUCCESS) { std::fprintf(stderr, "[ds4-fused-verify] compute failed\n"); return -1; } if (telemetry) { telemetry->full_graph_compute_us += ds4_elapsed_us(compute_t0, Ds4TimingClock::now()); } + fused_profiler.end(Ds4GpuPhase::ApproxFusedVerifyGraph); + fused_profiler.emit(); const auto read_t0 = Ds4TimingClock::now(); const int ncap = (int) hooks->capture_layer_ids->size(); diff --git a/server/src/deepseek4/deepseek4_gpu_profiler.cpp b/server/src/deepseek4/deepseek4_gpu_profiler.cpp new file mode 100644 index 000000000..2cdd6bb83 --- /dev/null +++ b/server/src/deepseek4/deepseek4_gpu_profiler.cpp @@ -0,0 +1,202 @@ +#include "deepseek4_gpu_profiler.h" + +#include +#include +#include +#include + +#if defined(GGML_USE_HIP) +#include +#include +#endif + +namespace dflash::common { + +namespace { + +constexpr size_t kPhaseCount = static_cast(Ds4GpuPhase::Count); + +const char * phase_name(Ds4GpuPhase phase) { + switch (phase) { + case Ds4GpuPhase::HcPre: return "hc_pre"; + case Ds4GpuPhase::Attention: return "attention"; + case Ds4GpuPhase::MoeFfn: return "moe_ffn"; + case Ds4GpuPhase::HcPost: return "hc_post"; + case Ds4GpuPhase::OutputProjection: return "output_projection"; + case Ds4GpuPhase::FusedDecodeGraph: return "fused_decode_graph"; + case Ds4GpuPhase::ApproxFusedVerifyGraph: return "approx_fused_verify_graph"; + case Ds4GpuPhase::VerificationStep: return "verification_step"; + case Ds4GpuPhase::Count: break; + } + return "unknown"; +} + +#if defined(GGML_USE_HIP) +class RoctxApi { +public: + using PushFn = int (*)(const char *); + using PopFn = int (*)(); + + RoctxApi() { + handle_ = dlopen("libroctx64.so", RTLD_LAZY | RTLD_LOCAL); + if (!handle_) return; + push_ = reinterpret_cast(dlsym(handle_, "roctxRangePushA")); + pop_ = reinterpret_cast(dlsym(handle_, "roctxRangePop")); + if (!push_ || !pop_) { + dlclose(handle_); + handle_ = nullptr; + push_ = nullptr; + pop_ = nullptr; + } + } + + ~RoctxApi() { + if (handle_) dlclose(handle_); + } + + void push(const char * name) const { + if (push_) push_(name); + } + + void pop() const { + if (pop_) pop_(); + } + +private: + void * handle_ = nullptr; + PushFn push_ = nullptr; + PopFn pop_ = nullptr; +}; + +RoctxApi & roctx_api() { + static RoctxApi api; + return api; +} + +void destroy_event(hipEvent_t event) { + if (!event) return; + const hipError_t status = hipEventDestroy(event); + (void) status; +} +#endif + +} // namespace + +struct Ds4GpuProfiler::Impl { + const char * scope = nullptr; + const char * mode = nullptr; + int n_tokens = 0; + int kv_start = 0; + int layer_begin = -1; + int layer_end = -1; + bool emit_zero_core = false; + Ds4GpuPhase active = Ds4GpuPhase::Count; + std::array elapsed_ms{}; + std::array calls{}; + bool emitted = false; +#if defined(GGML_USE_HIP) + hipEvent_t start = nullptr; + hipEvent_t stop = nullptr; +#endif +}; + +Ds4GpuProfiler::Ds4GpuProfiler(bool enabled, const Ds4GpuProfileOptions & options) { +#if defined(GGML_USE_HIP) + if (!enabled) return; + Impl * impl = new (std::nothrow) Impl; + if (!impl) return; + impl->scope = options.scope; + impl->mode = options.mode; + impl->n_tokens = options.n_tokens; + impl->kv_start = options.kv_start; + impl->layer_begin = options.layer_begin; + impl->layer_end = options.layer_end; + impl->emit_zero_core = options.emit_zero_core; + if (hipEventCreate(&impl->start) != hipSuccess || + hipEventCreate(&impl->stop) != hipSuccess) { + destroy_event(impl->start); + destroy_event(impl->stop); + delete impl; + return; + } + impl_ = impl; +#else + (void) enabled; + (void) options; +#endif +} + +Ds4GpuProfiler::~Ds4GpuProfiler() { +#if defined(GGML_USE_HIP) + if (!impl_) return; + if (impl_->active != Ds4GpuPhase::Count) { + roctx_api().pop(); + } + destroy_event(impl_->start); + destroy_event(impl_->stop); + delete impl_; +#endif +} + +bool Ds4GpuProfiler::enabled() const { + return impl_ != nullptr; +} + +void Ds4GpuProfiler::begin(Ds4GpuPhase phase) { +#if defined(GGML_USE_HIP) + if (!impl_ || impl_->active != Ds4GpuPhase::Count || phase == Ds4GpuPhase::Count) return; + if (hipEventRecord(impl_->start, nullptr) != hipSuccess || + hipEventSynchronize(impl_->start) != hipSuccess) { + return; + } + impl_->active = phase; + roctx_api().push(phase_name(phase)); +#else + (void) phase; +#endif +} + +void Ds4GpuProfiler::end(Ds4GpuPhase phase) { +#if defined(GGML_USE_HIP) + if (!impl_ || phase == Ds4GpuPhase::Count || impl_->active != phase) return; + roctx_api().pop(); + impl_->active = Ds4GpuPhase::Count; + if (hipEventRecord(impl_->stop, nullptr) != hipSuccess || + hipEventSynchronize(impl_->stop) != hipSuccess) { + return; + } + float elapsed = 0.0f; + if (hipEventElapsedTime(&elapsed, impl_->start, impl_->stop) != hipSuccess) return; + const size_t index = static_cast(phase); + impl_->elapsed_ms[index] += elapsed; + impl_->calls[index]++; +#else + (void) phase; +#endif +} + +void Ds4GpuProfiler::emit() { + if (!impl_ || impl_->emitted) return; + impl_->emitted = true; + uint64_t total_calls = 0; + for (uint64_t calls : impl_->calls) total_calls += calls; + if (total_calls == 0) return; + char layers[24] = ""; + if (impl_->layer_begin >= 0) { + std::snprintf(layers, sizeof(layers), " layers=%d-%d", + impl_->layer_begin, impl_->layer_end); + } + for (size_t i = 0; i < kPhaseCount; ++i) { + const bool core_phase = i <= static_cast(Ds4GpuPhase::OutputProjection); + if (impl_->calls[i] == 0 && (!core_phase || !impl_->emit_zero_core)) continue; + const auto phase = static_cast(i); + std::fprintf(stderr, + "[ds4-gpu-profile] clock=hip_event scope=%s mode=%s phase=%s " + "tokens=%d kv_start=%d%s gpu_ms=%.3f calls=%llu\n", + impl_->scope, impl_->mode, phase_name(phase), impl_->n_tokens, + impl_->kv_start, layers, impl_->elapsed_ms[i], + static_cast(impl_->calls[i])); + } +} + +} // namespace dflash::common diff --git a/server/src/deepseek4/deepseek4_gpu_profiler.h b/server/src/deepseek4/deepseek4_gpu_profiler.h new file mode 100644 index 000000000..d780b0ce5 --- /dev/null +++ b/server/src/deepseek4/deepseek4_gpu_profiler.h @@ -0,0 +1,47 @@ +#pragma once + +#include + +namespace dflash::common { + +enum class Ds4GpuPhase : uint8_t { + HcPre, + Attention, + MoeFfn, + HcPost, + OutputProjection, + FusedDecodeGraph, + ApproxFusedVerifyGraph, + VerificationStep, + Count, +}; + +struct Ds4GpuProfileOptions { + const char * scope = nullptr; + const char * mode = nullptr; + int n_tokens = 0; + int kv_start = 0; + int layer_begin = -1; + int layer_end = -1; + bool emit_zero_core = false; +}; + +class Ds4GpuProfiler { +public: + Ds4GpuProfiler(bool enabled, const Ds4GpuProfileOptions & options); + ~Ds4GpuProfiler(); + + Ds4GpuProfiler(const Ds4GpuProfiler &) = delete; + Ds4GpuProfiler & operator=(const Ds4GpuProfiler &) = delete; + + bool enabled() const; + void begin(Ds4GpuPhase phase); + void end(Ds4GpuPhase phase); + void emit(); + +private: + struct Impl; + Impl * impl_ = nullptr; +}; + +} // namespace dflash::common diff --git a/server/src/deepseek4/deepseek4_graph.cpp b/server/src/deepseek4/deepseek4_graph.cpp index b14af4474..87338fbf6 100644 --- a/server/src/deepseek4/deepseek4_graph.cpp +++ b/server/src/deepseek4/deepseek4_graph.cpp @@ -9,6 +9,7 @@ // 6. MoE FFN (hash routing + top-k + shared expert + clamped SwiGLU) #include "deepseek4_internal.h" +#include "deepseek4_gpu_profiler.h" #include "deepseek4_hc_cuda.h" #include "internal.h" #include "../common/step_graph.h" @@ -4954,12 +4955,24 @@ static int ds4_try_fused_decode_step( if (telemetry) telemetry->full_graph_set_us += ds4_elapsed_us(set_t0, Ds4TimingClock::now()); // ── Compute ───────────────────────────────────────────────────── + Ds4GpuProfileOptions profile_opts; + profile_opts.scope = "forward"; + profile_opts.mode = "fused_decode"; + profile_opts.n_tokens = 1; + profile_opts.kv_start = kv_start; + Ds4GpuProfiler fused_profiler( + ds4_backend_is_hip(backend) && ds4_env_flag("DFLASH_DS4_GPU_PROFILE"), + profile_opts); + fused_profiler.begin(Ds4GpuPhase::FusedDecodeGraph); const auto compute_t0 = Ds4TimingClock::now(); - if (ggml_backend_graph_compute(backend, fg->sg.gf) != GGML_STATUS_SUCCESS) { + const ggml_status fused_status = ggml_backend_graph_compute(backend, fg->sg.gf); + if (fused_status != GGML_STATUS_SUCCESS) { std::fprintf(stderr, "[deepseek4] fused decode graph compute failed\n"); return -1; } if (telemetry) telemetry->full_graph_compute_us += ds4_elapsed_us(compute_t0, Ds4TimingClock::now()); + fused_profiler.end(Ds4GpuPhase::FusedDecodeGraph); + fused_profiler.emit(); // ── Read logits ───────────────────────────────────────────────── const auto read_t0 = Ds4TimingClock::now(); @@ -4986,7 +4999,8 @@ static bool ds4_run_exact_tokenwise_prefill_attention( DeepSeek4AttentionImpl attention_impl, std::vector & attn_out_host, DeepSeek4CachedLayerAlloc & attn_alloc, - DeepSeek4StepTelemetry * telemetry) { + DeepSeek4StepTelemetry * telemetry, + Ds4GpuProfiler * gpu_profiler) { if (!backend || !cur || n_tokens <= 1 || kv_start < 0) return false; const int n_embd = w.n_embd; @@ -5052,12 +5066,14 @@ static bool ds4_run_exact_tokenwise_prefill_attention( sizeof(float) * b.values.size()); } + if (gpu_profiler) gpu_profiler->begin(Ds4GpuPhase::Attention); const auto compute_t0 = Ds4TimingClock::now(); const ggml_status status = ggml_backend_graph_compute(backend, gf); if (telemetry) { telemetry->attn_compute_us += ds4_elapsed_us( compute_t0, Ds4TimingClock::now()); } + if (gpu_profiler) gpu_profiler->end(Ds4GpuPhase::Attention); if (status != GGML_STATUS_SUCCESS) { std::fprintf(stderr, "[deepseek4] exact prefill attn compute failed layer %d token %d\n", @@ -5846,6 +5862,19 @@ bool deepseek4_step_layer_range( const int n_hc = w.n_hc; const int hc_dim = n_hc * n_embd; const bool is_last_shard = (layer_end >= w.n_layer); + const bool gpu_profile_enabled = + ds4_backend_is_hip(backend) && ds4_env_flag("DFLASH_DS4_GPU_PROFILE"); + const char * gpu_profile_mode = verify_hooks ? "exact_verify" : + (n_tokens == 1 ? "decode" : "prefill"); + Ds4GpuProfileOptions gpu_profile_opts; + gpu_profile_opts.scope = "forward"; + gpu_profile_opts.mode = gpu_profile_mode; + gpu_profile_opts.n_tokens = n_tokens; + gpu_profile_opts.kv_start = kv_start; + gpu_profile_opts.layer_begin = layer_begin; + gpu_profile_opts.layer_end = layer_end; + gpu_profile_opts.emit_zero_core = verify_hooks != nullptr; + Ds4GpuProfiler gpu_profiler(gpu_profile_enabled, gpu_profile_opts); // A dynamic batch may be supplied by callers other than the DSpark // verifier. Split it whenever it spans a learned-compressor boundary: @@ -6137,8 +6166,9 @@ bool deepseek4_step_layer_range( } if (telemetry) telemetry->hc_pre_build_us += ds4_elapsed_us(hc_pre_attn_build_t0, Ds4TimingClock::now()); } + gpu_profiler.begin(Ds4GpuPhase::HcPre); const auto hc_pre_attn_compute_t0 = Ds4TimingClock::now(); - if (!ds4_try_gpu_hc_pre_device(cached.sg.hidden_states, + const bool hc_pre_ok = ds4_try_gpu_hc_pre_device(cached.sg.hidden_states, cached.post, cached.comb, backend, @@ -6154,11 +6184,13 @@ bool deepseek4_step_layer_range( n_embd, n_hc, w.n_hc_sinkhorn_iter, - w.hc_eps)) { + w.hc_eps); + if (!hc_pre_ok) { std::fprintf(stderr, "[deepseek4] direct hc-pre compute failed layer %d attn\n", il); return false; } if (telemetry) telemetry->hc_pre_compute_us += ds4_elapsed_us(hc_pre_attn_compute_t0, Ds4TimingClock::now()); + gpu_profiler.end(Ds4GpuPhase::HcPre); attn_in_backend = cached.sg.hidden_states; attn_post_backend = cached.post; attn_comb_backend = cached.comb; @@ -6179,12 +6211,15 @@ bool deepseek4_step_layer_range( const auto hc_pre_attn_input_t0 = Ds4TimingClock::now(); ggml_backend_tensor_copy(hc_state_backend, cached.sg.inp_embed); if (telemetry) telemetry->hc_pre_input_us += ds4_elapsed_us(hc_pre_attn_input_t0, Ds4TimingClock::now()); + gpu_profiler.begin(Ds4GpuPhase::HcPre); const auto hc_pre_attn_compute_t0 = Ds4TimingClock::now(); - if (ggml_backend_graph_compute(backend, cached.sg.gf) != GGML_STATUS_SUCCESS) { + const ggml_status hc_pre_status = ggml_backend_graph_compute(backend, cached.sg.gf); + if (hc_pre_status != GGML_STATUS_SUCCESS) { std::fprintf(stderr, "[deepseek4] cached hc-pre compute failed layer %d attn\n", il); return false; } if (telemetry) telemetry->hc_pre_compute_us += ds4_elapsed_us(hc_pre_attn_compute_t0, Ds4TimingClock::now()); + gpu_profiler.end(Ds4GpuPhase::HcPre); attn_in_backend = cached.sg.hidden_states; attn_post_backend = cached.post; attn_comb_backend = cached.comb; @@ -6214,7 +6249,8 @@ bool deepseek4_step_layer_range( if (!ds4_run_exact_tokenwise_prefill_attention( backend, w, L, lc, il, cur.data(), n_tokens, kv_start, attention_impl, attn_out_host, - cached_attn_allocs[(size_t) il], telemetry)) { + cached_attn_allocs[(size_t) il], telemetry, + &gpu_profiler)) { return false; } } else if (reuse_decode_attn) { @@ -6360,13 +6396,16 @@ bool deepseek4_step_layer_range( } if (!exact_tokenwise_prefill) { + gpu_profiler.begin(Ds4GpuPhase::Attention); const auto attn_compute_t0 = Ds4TimingClock::now(); - if (ggml_backend_graph_compute(backend, gf) != GGML_STATUS_SUCCESS) { + const ggml_status attn_status = ggml_backend_graph_compute(backend, gf); + if (attn_status != GGML_STATUS_SUCCESS) { std::fprintf(stderr, "[deepseek4] attn compute failed layer %d\n", il); if (ctx) ggml_free(ctx); return false; } if (telemetry) telemetry->attn_compute_us += ds4_elapsed_us(attn_compute_t0, Ds4TimingClock::now()); + gpu_profiler.end(Ds4GpuPhase::Attention); if (use_backend_decode_hc_graph || use_backend_decode_hc_direct) { if (hc_state_backend != cached_decode_hc_post_graph.residual_hc) { ggml_backend_tensor_copy(hc_state_backend, cached_decode_hc_post_graph.residual_hc); @@ -6374,14 +6413,18 @@ bool deepseek4_step_layer_range( ggml_backend_tensor_copy(attn_out, cached_decode_hc_post_graph.block_out); ggml_backend_tensor_copy(attn_post_backend, cached_decode_hc_post_graph.post); ggml_backend_tensor_copy(attn_comb_backend, cached_decode_hc_post_graph.comb); + gpu_profiler.begin(Ds4GpuPhase::HcPost); const auto hc_post_attn_t0 = Ds4TimingClock::now(); - if (ggml_backend_graph_compute(backend, cached_decode_hc_post_graph.sg.gf) != GGML_STATUS_SUCCESS) { + const ggml_status hc_post_status = ggml_backend_graph_compute( + backend, cached_decode_hc_post_graph.sg.gf); + if (hc_post_status != GGML_STATUS_SUCCESS) { std::fprintf(stderr, "[deepseek4] cached hc-post compute failed layer %d attn\n", il); if (ctx) ggml_free(ctx); return false; } hc_state_backend = cached_decode_hc_post_graph.sg.hidden_states; if (telemetry) telemetry->hc_post_attn_us += ds4_elapsed_us(hc_post_attn_t0, Ds4TimingClock::now()); + gpu_profiler.end(Ds4GpuPhase::HcPost); } else { const auto attn_read_t0 = Ds4TimingClock::now(); ggml_backend_tensor_get(attn_out, attn_out_host.data(), 0, sizeof(float) * attn_out_host.size()); @@ -6422,8 +6465,9 @@ bool deepseek4_step_layer_range( } if (telemetry) telemetry->hc_pre_build_us += ds4_elapsed_us(hc_pre_ffn_build_t0, Ds4TimingClock::now()); } + gpu_profiler.begin(Ds4GpuPhase::HcPre); const auto hc_pre_ffn_compute_t0 = Ds4TimingClock::now(); - if (!ds4_try_gpu_hc_pre_device(cached.sg.hidden_states, + const bool hc_pre_ok = ds4_try_gpu_hc_pre_device(cached.sg.hidden_states, cached.post, cached.comb, backend, @@ -6439,11 +6483,13 @@ bool deepseek4_step_layer_range( n_embd, n_hc, w.n_hc_sinkhorn_iter, - w.hc_eps)) { + w.hc_eps); + if (!hc_pre_ok) { std::fprintf(stderr, "[deepseek4] direct hc-pre compute failed layer %d ffn\n", il); return false; } if (telemetry) telemetry->hc_pre_compute_us += ds4_elapsed_us(hc_pre_ffn_compute_t0, Ds4TimingClock::now()); + gpu_profiler.end(Ds4GpuPhase::HcPre); ffn_in_backend = cached.sg.hidden_states; ffn_post_backend = cached.post; ffn_comb_backend = cached.comb; @@ -6464,12 +6510,15 @@ bool deepseek4_step_layer_range( const auto hc_pre_ffn_input_t0 = Ds4TimingClock::now(); ggml_backend_tensor_copy(hc_state_backend, cached.sg.inp_embed); if (telemetry) telemetry->hc_pre_input_us += ds4_elapsed_us(hc_pre_ffn_input_t0, Ds4TimingClock::now()); + gpu_profiler.begin(Ds4GpuPhase::HcPre); const auto hc_pre_ffn_compute_t0 = Ds4TimingClock::now(); - if (ggml_backend_graph_compute(backend, cached.sg.gf) != GGML_STATUS_SUCCESS) { + const ggml_status hc_pre_status = ggml_backend_graph_compute(backend, cached.sg.gf); + if (hc_pre_status != GGML_STATUS_SUCCESS) { std::fprintf(stderr, "[deepseek4] cached hc-pre compute failed layer %d ffn\n", il); return false; } if (telemetry) telemetry->hc_pre_compute_us += ds4_elapsed_us(hc_pre_ffn_compute_t0, Ds4TimingClock::now()); + gpu_profiler.end(Ds4GpuPhase::HcPre); ffn_in_backend = cached.sg.hidden_states; ffn_post_backend = cached.post; ffn_comb_backend = cached.comb; @@ -6533,9 +6582,11 @@ bool deepseek4_step_layer_range( sizeof(int32_t) * hash_expert_ids_host.size()); } + gpu_profiler.begin(Ds4GpuPhase::MoeFfn); const auto ffn_compute_t0 = Ds4TimingClock::now(); auto status = ggml_backend_graph_compute(backend, cached.sg.gf); if (telemetry) telemetry->ffn_compute_us += ds4_elapsed_us(ffn_compute_t0, Ds4TimingClock::now()); + gpu_profiler.end(Ds4GpuPhase::MoeFfn); if (status != GGML_STATUS_SUCCESS) { std::fprintf(stderr, "[deepseek4] cached ffn compute failed layer %d\n", il); return false; @@ -6548,13 +6599,17 @@ bool deepseek4_step_layer_range( ggml_backend_tensor_copy(ffn_out, cached_decode_hc_post_graph.block_out); ggml_backend_tensor_copy(ffn_post_backend, cached_decode_hc_post_graph.post); ggml_backend_tensor_copy(ffn_comb_backend, cached_decode_hc_post_graph.comb); + gpu_profiler.begin(Ds4GpuPhase::HcPost); const auto hc_post_ffn_t0 = Ds4TimingClock::now(); - if (ggml_backend_graph_compute(backend, cached_decode_hc_post_graph.sg.gf) != GGML_STATUS_SUCCESS) { + const ggml_status hc_post_status = ggml_backend_graph_compute( + backend, cached_decode_hc_post_graph.sg.gf); + if (hc_post_status != GGML_STATUS_SUCCESS) { std::fprintf(stderr, "[deepseek4] cached hc-post compute failed layer %d ffn\n", il); return false; } hc_state_backend = cached_decode_hc_post_graph.sg.hidden_states; if (telemetry) telemetry->hc_post_ffn_us += ds4_elapsed_us(hc_post_ffn_t0, Ds4TimingClock::now()); + gpu_profiler.end(Ds4GpuPhase::HcPost); } else { const auto ffn_read_t0 = Ds4TimingClock::now(); ggml_backend_tensor_get(ffn_out, ffn_out_host.data(), 0, sizeof(float) * ffn_out_host.size()); @@ -6625,7 +6680,11 @@ bool deepseek4_step_layer_range( } ggml_backend_tensor_set(cached_decode_output_graph.sg.hidden_input, final_embd.data(), 0, sizeof(float) * final_embd.size()); - if (ggml_backend_graph_compute(backend, cached_decode_output_graph.sg.gf) != GGML_STATUS_SUCCESS) { + gpu_profiler.begin(Ds4GpuPhase::OutputProjection); + const ggml_status output_status = ggml_backend_graph_compute( + backend, cached_decode_output_graph.sg.gf); + gpu_profiler.end(Ds4GpuPhase::OutputProjection); + if (output_status != GGML_STATUS_SUCCESS) { return false; } out_logits->resize((size_t)w.n_vocab); @@ -6640,7 +6699,8 @@ bool deepseek4_step_layer_range( ggml_context * ctx = ggml_init(params); if (!ctx) return false; - const bool last_only = n_tokens > 1; + const bool need_all_logits = verify_hooks && verify_hooks->all_logits_out; + const bool last_only = n_tokens > 1 && !need_all_logits; const int output_tokens = last_only ? 1 : n_tokens; ggml_tensor * inp = ggml_new_tensor_2d( ctx, GGML_TYPE_F32, n_embd, output_tokens); @@ -6669,7 +6729,10 @@ bool deepseek4_step_layer_range( : final_embd.data(); ggml_backend_tensor_set(inp, output_input, 0, sizeof(float) * (size_t)n_embd * output_tokens); - if (ggml_backend_graph_compute(backend, gf) != GGML_STATUS_SUCCESS) { + gpu_profiler.begin(Ds4GpuPhase::OutputProjection); + const ggml_status output_status = ggml_backend_graph_compute(backend, gf); + gpu_profiler.end(Ds4GpuPhase::OutputProjection); + if (output_status != GGML_STATUS_SUCCESS) { ggml_free(ctx); return false; } @@ -6708,6 +6771,7 @@ bool deepseek4_step_layer_range( cache.cur_pos = next_pos; if (telemetry) telemetry->total_us += ds4_elapsed_us(step_t0, Ds4TimingClock::now()); + gpu_profiler.emit(); return true; }