diff --git a/worklogs/decode_analysis_report_2026-07-14.md b/worklogs/decode_analysis_report_2026-07-14.md index 8387a94..43dd89b 100644 --- a/worklogs/decode_analysis_report_2026-07-14.md +++ b/worklogs/decode_analysis_report_2026-07-14.md @@ -1146,3 +1146,51 @@ _PROF_TRACE = os.environ.get("PROF_TRACE", "0") == "1" ### 结论 32768 可以启动，但没有带来总体收益；Output TPS P10 略升，TTFT 继续变差，综合吞吐仍低于原 100K 基线。单纯扩大 chunk 不是主优化方向。下一步尝试 8192，验证更小 chunk 是否能改善 TTFT。 + +## 2026-07-15：max_num_batched_tokens=8192 实验 + +### 流程改进 + +新增可复用远端实验脚本： + +- `worklogs/remote_scripts/run_batched_tokens_experiment.sh` + +脚本负责： + +- 停止旧 `api_server`； +- 检查启动前 GPU 显存； +- 按指定 `max_num_batched_tokens` 启动 100K/no-prof 服务； +- 等待 `/health`； +- 运行 8 请求官方相似压测； +- 写入 `driver.log`、`server.log` 和结果 JSON。 + +这能减少超长 SSH 命令导致的本地 PowerShell/SSH 子进程异常，也让后续实验日志格式统一。 + +### 结果 + +本地归档： + +- `worklogs/remote_results/2026-07-15-official-like-baseline/eager_100k_b8192_c1_r8_t256_cap40k.json` +- `worklogs/remote_results/2026-07-15-official-like-baseline/driver_b8192.log` + +| 指标 | 100K 基线 | no-prof 8192 | no-prof 16384 | no-prof 32768 | 目标 | +| --- | ---: | ---: | ---: | ---: | ---: | +| Success Rate | 100.00% | 100.00% | 100.00% | 100.00% | >= 99% | +| Cache Hit Rate | 74.17% | 74.17% | 74.17% | 74.17% | >= 50% | +| TTFT P90 | 9.803s | 13.996s | 12.739s | 13.005s | <= 5s | +| Output TPS P10 | 5.825 | 5.840 | 5.851 | 5.895 | >= 20 | +| Aggregate Output TPS | 5.789 | 5.513 | 5.674 | 5.556 | - | +| Uncached Input TPS | 178.330 | 168.408 | 169.148 | 173.430 | - | +| Cache TPS | 512.015 | 483.527 | 485.652 | 497.947 | - | +| Weighted Throughput | 883.109 | 834.751 | 840.712 | 857.595 | >= 8000 | + +### 结论 + +8192 没有改善 TTFT，反而是本轮 chunk 参数中最弱。8192/16384/32768 三组的 Output TPS P10 都约 5.8-5.9，差别很小，说明当前目标瓶颈不是 chunk 大小，而是 decode 每 token 的层内计算/通信周期，以及长上下文 prefill/cache 路径的底层吞吐。 + +下一轮方向： + +1. 对 decode 稳态做低开销 profiling，只记录少量聚合计时，避免 `PROF_TRACE` 每层每 token 打日志。 +2. 拆分 `MLP` 时间中 routed expert、shared expert、TP all-reduce 的占比。 +3. 若 all-reduce 占比高，测试 `--disable-custom-all-reduce` 保持关闭/打开的差异和 TP 通信路径。 +4. 若 routed expert 占比高，继续优化 `_native_experts_sorted` 中逐 expert 循环和 `index_add_`。 diff --git a/worklogs/remote_results/2026-07-15-official-like-baseline/driver_b8192.log b/worklogs/remote_results/2026-07-15-official-like-baseline/driver_b8192.log new file mode 100644 index 0000000..a416abd --- /dev/null +++ b/worklogs/remote_results/2026-07-15-official-like-baseline/driver_b8192.log @@ -0,0 +1,230 @@ +[exp] label=batched_tokens_8192_20260715 +[exp] max_num_batched_tokens=8192 +[exp] out_dir=/root/work/logs/batched_tokens_8192_20260715 +Wed Jul 15 02:34:25 UTC 2026 +[exp] stopping existing api_server +[exp] gpu before start +Timestamp Wed Jul 15 02:34:25 2026 ++-----------------------------------------------------------------------------+ +| IX-ML: 3.2.3 Driver Version: 3.2.1 CUDA Version: 10.2 | +|-------------------------------+----------------------+----------------------| +| GPU Name | Bus-Id | Clock-SM Clock-Mem | +| Fan Temp Perf Pwr:Usage/Cap| Memory-Usage | GPU-Util Compute M. | +|===============================+======================+======================| +| 0 Iluvatar BI-V100 | 00000000:4B:00.0 | 1500MHz 1200MHz | +| 0% 29C P0 47W / 250W | 257MiB / 32768MiB | 0% Default | ++-------------------------------+----------------------+----------------------+ +| 1 Iluvatar BI-V100 | 00000000:4C:00.0 | 1500MHz 1200MHz | +| 0% 32C P0 47W / 250W | 257MiB / 32768MiB | 0% Default | ++-------------------------------+----------------------+----------------------+ +| 2 Iluvatar BI-V100 | 00000000:4D:00.0 | 1500MHz 1200MHz | +| 0% 31C P0 47W / 250W | 257MiB / 32768MiB | 0% Default | ++-------------------------------+----------------------+----------------------+ +| 3 Iluvatar BI-V100 | 00000000:4E:00.0 | 1500MHz 1200MHz | +| 0% 30C P0 47W / 250W | 257MiB / 32768MiB | 0% Default | ++-------------------------------+----------------------+----------------------+ + ++-----------------------------------------------------------------------------+ +| Processes: GPU Memory | +| GPU PID Process name Usage(MiB) | +|=============================================================================| +| No running processes found | ++-----------------------------------------------------------------------------+ +[exp] starting server +[exp] server_pid=32482 +[exp] waiting for health +[exp] health ok after 17 checks +[exp] running benchmark +done 1/8 ok=True +done 2/8 ok=True +done 3/8 ok=True +done 4/8 ok=True +done 5/8 ok=True +done 6/8 ok=True +done 7/8 ok=True +done 8/8 ok=True +{ + "created_at": "2026-07-15T02:41:32", + "url": "http://127.0.0.1:1111", + "model": "llm", + "dataset": "/root/work/logs/synthetic_cumulative_8_s3_cap40k.jsonl", + "concurrency": 1, + "max_requests": 8, + "max_tokens": 256, + "wall_sec": 345.89166797697544, + "success_rate": 1.0, + "ttft_p90_sec": 13.995924570597705, + "output_tps_p10_per_request": 5.840174878063855, + "aggregate_output_tps": 5.513286894574578, + "aggregate_input_tps_uncached": 168.40821966222535, + "aggregate_cache_tps": 483.5271140764599, + "cache_hit_rate": 0.7416795639891973, + "weighted_token_throughput": 834.7509573986608, + "totals": { + "requests": 8, + "success": 8, + "prompt_tokens": 225499, + "input_tokens_uncached": 58251, + "cached_tokens": 167248, + "completion_tokens": 1907, + "reasoning_tokens": 1758 + }, + "targets": { + "output_tps_p10_per_request_gte_20": false, + "ttft_p90_lte_5": false, + "cache_hit_rate_gte_50pct": true, + "success_rate_gte_99pct": true, + "weighted_token_throughput_gte_8000": false + } +} +RESULT_FILE /root/work/logs/batched_tokens_8192_20260715/eager_100k_b8192_c1_r8_t256_cap40k.json +[exp] benchmark rc=0 +{ + "created_at": "2026-07-15T02:41:32", + "url": "http://127.0.0.1:1111", + "model": "llm", + "dataset": "/root/work/logs/synthetic_cumulative_8_s3_cap40k.jsonl", + "concurrency": 1, + "max_requests": 8, + "max_tokens": 256, + "wall_sec": 345.89166797697544, + "success_rate": 1.0, + "ttft_p90_sec": 13.995924570597705, + "output_tps_p10_per_request": 5.840174878063855, + "aggregate_output_tps": 5.513286894574578, + "aggregate_input_tps_uncached": 168.40821966222535, + "aggregate_cache_tps": 483.5271140764599, + "cache_hit_rate": 0.7416795639891973, + "weighted_token_throughput": 834.7509573986608, + "totals": { + "requests": 8, + "success": 8, + "prompt_tokens": 225499, + "input_tokens_uncached": 58251, + "cached_tokens": 167248, + "completion_tokens": 1907, + "reasoning_tokens": 1758 + }, + "targets": { + "output_tps_p10_per_request_gte_20": false, + "ttft_p90_lte_5": false, + "cache_hit_rate_gte_50pct": true, + "success_rate_gte_99pct": true, + "weighted_token_throughput_gte_8000": false + }, + "results": [ + { + "ok": true, + "elapsed_sec": 36.67137165553868, + "ttft_sec": 7.283070221543312, + "prompt_tokens": 7498, + "cached_tokens": 0, + "completion_tokens": 250, + "reasoning_tokens": 147, + "output_tps": 8.506786299354092, + "error": null + }, + { + "ok": true, + "elapsed_sec": 42.85823520086706, + "ttft_sec": 23.074742704629898, + "prompt_tokens": 34177, + "cached_tokens": 7488, + "completion_tokens": 121, + "reasoning_tokens": 75, + "output_tps": 6.116210270912193, + "error": null + }, + { + "ok": true, + "elapsed_sec": 46.396307623013854, + "ttft_sec": 3.7564049027860165, + "prompt_tokens": 35384, + "cached_tokens": 34160, + "completion_tokens": 256, + "reasoning_tokens": 256, + "output_tps": 6.003766042330974, + "error": null + }, + { + "ok": true, + "elapsed_sec": 40.55220231600106, + "ttft_sec": 10.105002513155341, + "prompt_tokens": 19274, + "cached_tokens": 7472, + "completion_tokens": 256, + "reasoning_tokens": 256, + "output_tps": 8.407998162644606, + "error": null + }, + { + "ok": true, + "elapsed_sec": 47.4568429403007, + "ttft_sec": 4.107830764725804, + "prompt_tokens": 37099, + "cached_tokens": 35376, + "completion_tokens": 256, + "reasoning_tokens": 256, + "output_tps": 5.90555556290724, + "error": null + }, + { + "ok": true, + "elapsed_sec": 36.76491709984839, + "ttft_sec": 6.331659993156791, + "prompt_tokens": 14661, + "cached_tokens": 7472, + "completion_tokens": 256, + "reasoning_tokens": 256, + "output_tps": 8.411850203957014, + "error": null + }, + { + "ok": true, + "elapsed_sec": 47.44748286344111, + "ttft_sec": 3.74263353087008, + "prompt_tokens": 38199, + "cached_tokens": 37088, + "completion_tokens": 256, + "reasoning_tokens": 256, + "output_tps": 5.85747357351524, + "error": null + }, + { + "ok": true, + "elapsed_sec": 47.73618622124195, + "ttft_sec": 3.59681879542768, + "prompt_tokens": 39207, + "cached_tokens": 38192, + "completion_tokens": 256, + "reasoning_tokens": 256, + "output_tps": 5.799811255343957, + "error": null + } + ] +}[exp] gpu after benchmark +Timestamp Wed Jul 15 02:41:32 2026 ++-----------------------------------------------------------------------------+ +| IX-ML: 3.2.3 Driver Version: 3.2.1 CUDA Version: 10.2 | +|-------------------------------+----------------------+----------------------| +| GPU Name | Bus-Id | Clock-SM Clock-Mem | +| Fan Temp Perf Pwr:Usage/Cap| Memory-Usage | GPU-Util Compute M. | +|===============================+======================+======================| +| 0 Iluvatar BI-V100 | 00000000:4B:00.0 | 1500MHz 1200MHz | +| 0% 33C P0 64W / 250W | 29967MiB / 32768MiB | 0% Default | ++-------------------------------+----------------------+----------------------+ +| 1 Iluvatar BI-V100 | 00000000:4C:00.0 | 1500MHz 1200MHz | +| 0% 36C P0 63W / 250W | 29906MiB / 32768MiB | 0% Default | ++-------------------------------+----------------------+----------------------+ +| 2 Iluvatar BI-V100 | 00000000:4D:00.0 | 1500MHz 1200MHz | +| 0% 36C P0 62W / 250W | 29910MiB / 32768MiB | 0% Default | ++-------------------------------+----------------------+----------------------+ +| 3 Iluvatar BI-V100 | 00000000:4E:00.0 | 1500MHz 1200MHz | +| 0% 34C P0 61W / 250W | 29770MiB / 32768MiB | 0% Default | ++-------------------------------+----------------------+----------------------+ + ++-----------------------------------------------------------------------------+ +| Processes: GPU Memory | +| GPU PID Process name Usage(MiB) | +|=============================================================================| ++-----------------------------------------------------------------------------+ diff --git a/worklogs/remote_results/2026-07-15-official-like-baseline/eager_100k_b8192_c1_r8_t256_cap40k.json b/worklogs/remote_results/2026-07-15-official-like-baseline/eager_100k_b8192_c1_r8_t256_cap40k.json new file mode 100644 index 0000000..389966d --- /dev/null +++ b/worklogs/remote_results/2026-07-15-official-like-baseline/eager_100k_b8192_c1_r8_t256_cap40k.json @@ -0,0 +1,124 @@ +{ + "created_at": "2026-07-15T02:41:32", + "url": "http://127.0.0.1:1111", + "model": "llm", + "dataset": "/root/work/logs/synthetic_cumulative_8_s3_cap40k.jsonl", + "concurrency": 1, + "max_requests": 8, + "max_tokens": 256, + "wall_sec": 345.89166797697544, + "success_rate": 1.0, + "ttft_p90_sec": 13.995924570597705, + "output_tps_p10_per_request": 5.840174878063855, + "aggregate_output_tps": 5.513286894574578, + "aggregate_input_tps_uncached": 168.40821966222535, + "aggregate_cache_tps": 483.5271140764599, + "cache_hit_rate": 0.7416795639891973, + "weighted_token_throughput": 834.7509573986608, + "totals": { + "requests": 8, + "success": 8, + "prompt_tokens": 225499, + "input_tokens_uncached": 58251, + "cached_tokens": 167248, + "completion_tokens": 1907, + "reasoning_tokens": 1758 + }, + "targets": { + "output_tps_p10_per_request_gte_20": false, + "ttft_p90_lte_5": false, + "cache_hit_rate_gte_50pct": true, + "success_rate_gte_99pct": true, + "weighted_token_throughput_gte_8000": false + }, + "results": [ + { + "ok": true, + "elapsed_sec": 36.67137165553868, + "ttft_sec": 7.283070221543312, + "prompt_tokens": 7498, + "cached_tokens": 0, + "completion_tokens": 250, + "reasoning_tokens": 147, + "output_tps": 8.506786299354092, + "error": null + }, + { + "ok": true, + "elapsed_sec": 42.85823520086706, + "ttft_sec": 23.074742704629898, + "prompt_tokens": 34177, + "cached_tokens": 7488, + "completion_tokens": 121, + "reasoning_tokens": 75, + "output_tps": 6.116210270912193, + "error": null + }, + { + "ok": true, + "elapsed_sec": 46.396307623013854, + "ttft_sec": 3.7564049027860165, + "prompt_tokens": 35384, + "cached_tokens": 34160, + "completion_tokens": 256, + "reasoning_tokens": 256, + "output_tps": 6.003766042330974, + "error": null + }, + { + "ok": true, + "elapsed_sec": 40.55220231600106, + "ttft_sec": 10.105002513155341, + "prompt_tokens": 19274, + "cached_tokens": 7472, + "completion_tokens": 256, + "reasoning_tokens": 256, + "output_tps": 8.407998162644606, + "error": null + }, + { + "ok": true, + "elapsed_sec": 47.4568429403007, + "ttft_sec": 4.107830764725804, + "prompt_tokens": 37099, + "cached_tokens": 35376, + "completion_tokens": 256, + "reasoning_tokens": 256, + "output_tps": 5.90555556290724, + "error": null + }, + { + "ok": true, + "elapsed_sec": 36.76491709984839, + "ttft_sec": 6.331659993156791, + "prompt_tokens": 14661, + "cached_tokens": 7472, + "completion_tokens": 256, + "reasoning_tokens": 256, + "output_tps": 8.411850203957014, + "error": null + }, + { + "ok": true, + "elapsed_sec": 47.44748286344111, + "ttft_sec": 3.74263353087008, + "prompt_tokens": 38199, + "cached_tokens": 37088, + "completion_tokens": 256, + "reasoning_tokens": 256, + "output_tps": 5.85747357351524, + "error": null + }, + { + "ok": true, + "elapsed_sec": 47.73618622124195, + "ttft_sec": 3.59681879542768, + "prompt_tokens": 39207, + "cached_tokens": 38192, + "completion_tokens": 256, + "reasoning_tokens": 256, + "output_tps": 5.799811255343957, + "error": null + } + ] +} \ No newline at end of file diff --git a/worklogs/remote_scripts/run_batched_tokens_experiment.sh b/worklogs/remote_scripts/run_batched_tokens_experiment.sh new file mode 100644 index 0000000..2a46213 --- /dev/null +++ b/worklogs/remote_scripts/run_batched_tokens_experiment.sh @@ -0,0 +1,111 @@ +#!/usr/bin/env bash +set -u + +MAX_BATCHED_TOKENS="${1:?usage: run_batched_tokens_experiment.sh MAX_BATCHED_TOKENS LABEL}" +LABEL="${2:?usage: run_batched_tokens_experiment.sh MAX_BATCHED_TOKENS LABEL}" + +OUT_DIR="/root/work/logs/${LABEL}" +MODEL_PATH="/root/public-storage/models/Qwen/Qwen3.6-35B-A3B" +DATASET="/root/work/logs/synthetic_cumulative_8_s3_cap40k.jsonl" +RESULT_JSON="${OUT_DIR}/eager_100k_b${MAX_BATCHED_TOKENS}_c1_r8_t256_cap40k.json" +SERVER_LOG="${OUT_DIR}/server.log" +DRIVER_LOG="${OUT_DIR}/driver.log" + +mkdir -p "${OUT_DIR}" +exec > >(tee -a "${DRIVER_LOG}") 2>&1 + +echo "[exp] label=${LABEL}" +echo "[exp] max_num_batched_tokens=${MAX_BATCHED_TOKENS}" +echo "[exp] out_dir=${OUT_DIR}" +date + +echo "[exp] stopping existing api_server" +PIDS="$(pgrep -f 'vllm.entrypoints.openai.api_server' || true)" +if [ -n "${PIDS}" ]; then + kill -TERM ${PIDS} 2>/dev/null || true + sleep 8 + kill -KILL ${PIDS} 2>/dev/null || true +fi + +export PYTHONPATH=/usr/local/corex/lib64/python3/dist-packages +export LD_LIBRARY_PATH=/usr/local/corex/lib64:/usr/local/iluvatar/lib64:/usr/local/openmpi/lib +export PATH=/usr/local/corex/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/local/openmpi/bin +export MOE_NATIVE=1 +export CHUNK_PARALLEL=1 +export PREFIX_FLASH=1 +export RMSNORM_NATIVE=1 +export LOOP1_NATIVE=1 +export PROF_TRACE=0 +export VLLM_ENGINE_ITERATION_TIMEOUT_S=3600 + +echo "[exp] gpu before start" +LD_LIBRARY_PATH=/usr/local/corex-3.2.3/lib64:/usr/local/corex/lib64:/usr/local/corex/lib:/usr/local/iluvatar/lib64 \ + timeout 15 /usr/local/corex/bin/ixsmi || true + +echo "[exp] starting server" +cd /root || exit 1 +nohup python3 -m vllm.entrypoints.openai.api_server \ + --model "${MODEL_PATH}" \ + --served-model-name llm \ + --host 0.0.0.0 \ + --port 1111 \ + --max-model-len 100000 \ + --enforce-eager \ + --gpu-memory-utilization 0.9 \ + --trust-remote-code \ + -tp 4 \ + --max-num-seqs 1 \ + --disable-log-requests \ + --disable-frontend-multiprocessing \ + --max-num-batched-tokens "${MAX_BATCHED_TOKENS}" \ + --enable-chunked-prefill \ + --max-seq-len-to-capture 32768 \ + --enable-auto-tool-choice \ + --tool-call-parser qwen3_coder \ + --reasoning-parser qwen3 \ + --enable-prefix-caching \ + --chat-template /workspace/chat_template_multi_system.jinja \ + > "${SERVER_LOG}" 2>&1 & +SERVER_PID="$!" +echo "[exp] server_pid=${SERVER_PID}" + +echo "[exp] waiting for health" +for i in $(seq 1 90); do + if python3 -c "import urllib.request; urllib.request.urlopen('http://127.0.0.1:1111/health', timeout=3).read()" >/dev/null 2>&1; then + echo "[exp] health ok after ${i} checks" + break + fi + if ! kill -0 "${SERVER_PID}" 2>/dev/null; then + echo "[exp] server exited before health" + tail -120 "${SERVER_LOG}" || true + exit 2 + fi + sleep 5 +done + +if ! python3 -c "import urllib.request; urllib.request.urlopen('http://127.0.0.1:1111/health', timeout=5).read()" >/dev/null 2>&1; then + echo "[exp] health failed" + tail -120 "${SERVER_LOG}" || true + exit 3 +fi + +echo "[exp] running benchmark" +cd /root/work || exit 1 +python3 /root/work/formal_perf_bench.py \ + --url http://127.0.0.1:1111 \ + --model llm \ + --dataset "${DATASET}" \ + --concurrency 1 \ + --max-requests 8 \ + --max-tokens 256 \ + --timeout 1800 \ + --out "${RESULT_JSON}" +BENCH_RC="$?" + +echo "[exp] benchmark rc=${BENCH_RC}" +cat "${RESULT_JSON}" || true +echo "[exp] gpu after benchmark" +LD_LIBRARY_PATH=/usr/local/corex-3.2.3/lib64:/usr/local/corex/lib64:/usr/local/corex/lib:/usr/local/iluvatar/lib64 \ + timeout 15 /usr/local/corex/bin/ixsmi || true + +exit "${BENCH_RC}"