disable profiling trace by default

qwen3_6_scripts/qwen3_5.py

@@ -43,14 +43,14 @@ logger = init_logger(__name__)
 
 
 # ---------------------------------------------------------------------------
-# Profiling debug prints (locate where startup hangs after weight load).
-# Gate on PROF_TRACE=1 (default on, since we are diagnosing a startup hang).
-# Each print flushes; grep "[PROF]" in the server log.
+# Profiling debug prints. Disabled by default for benchmark runs because each
+# print flushes and decode emits many per-token layer events. Enable only with
+# PROF_TRACE=1 when collecting code-level traces.
 # ---------------------------------------------------------------------------
 import os as _os_prof
 import sys as _sys_prof
 import time as _time_prof
-_PROF_TRACE = _os_prof.environ.get("PROF_TRACE", "1") != "0"
+_PROF_TRACE = _os_prof.environ.get("PROF_TRACE", "0") == "1"
 _t0 = _time_prof.time()
 def _prof(msg):
     if _PROF_TRACE:

worklogs/decode_analysis_report_2026-07-14.md

@@ -1062,3 +1062,48 @@ topk_weights = torch.softmax(topk_logits, dim=-1)
 - 小样本中输出 token 数不同，仍需看趋势而不是单条。
 
 操作结论：不保留该代码改动，回退到 full-softmax router。下一步继续围绕 MoE expert GEMM、all-reduce、prefill/cache 路径做实验。
+
+## 2026-07-15：关闭默认 PROF_TRACE
+
+### 改动
+
+`qwen3_5.py` 中 `_prof()` 原本默认开启：
+
+```python
+_PROF_TRACE = os.environ.get("PROF_TRACE", "1") != "0"
+```
+
+这会在 decode 阶段输出大量 `[PROF]` 行，并且每次 `flush=True`。改为默认关闭：
+
+```python
+_PROF_TRACE = os.environ.get("PROF_TRACE", "0") == "1"
+```
+
+需要代码级 profiling 时再显式设置 `PROF_TRACE=1`。
+
+### 结果
+
+本地归档：
+
+- `worklogs/remote_results/2026-07-15-official-like-baseline/eager_100k_no_prof_c1_r8_t256_cap40k.json`
+
+| 指标 | 100K 基线 | PROF_TRACE 默认关闭 | 目标 |
+| --- | ---: | ---: | ---: |
+| Success Rate | 100.00% | 100.00% | >= 99% |
+| Cache Hit Rate | 74.17% | 74.17% | >= 50% |
+| TTFT P90 | 9.803s | 12.739s | <= 5s |
+| Output TPS P10 | 5.825 | 5.851 | >= 20 |
+| Aggregate Output TPS | 5.789 | 5.674 | - |
+| Uncached Input TPS | 178.330 | 169.148 | - |
+| Cache TPS | 512.015 | 485.652 | - |
+| Weighted Throughput | 883.109 | 840.712 | >= 8000 |
+
+### 结论
+
+关闭默认 profiling 没有带来明显性能收益，说明当前主要瓶颈不是日志 I/O。不过该改动仍应保留在生产提交中：
+
+- 避免评测日志膨胀；
+- 避免 profiling 输出影响长时间 benchmark 稳定性；
+- profiling 仍可通过 `PROF_TRACE=1` 手动开启。
+
+下一步继续看 MoE routed expert 和 TP all-reduce；服务日志中 decode 稳态仍约 5.8 tok/s，说明专家计算/通信路径仍是核心。

worklogs/remote_results/2026-07-15-official-like-baseline/eager_100k_no_prof_c1_r8_t256_cap40k.json

@@ -0,0 +1,124 @@
+{
+  "created_at": "2026-07-14T20:36:39",
+  "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": 344.37798644416034,
+  "success_rate": 1.0,
+  "ttft_p90_sec": 12.73888401035219,
+  "output_tps_p10_per_request": 5.851249699499549,
+  "aggregate_output_tps": 5.673997981624281,
+  "aggregate_input_tps_uncached": 169.148442388739,
+  "aggregate_cache_tps": 485.6524127076243,
+  "cache_hit_rate": 0.7416795639891973,
+  "weighted_token_throughput": 840.7123114617115,
+  "totals": {
+    "requests": 8,
+    "success": 8,
+    "prompt_tokens": 225499,
+    "input_tokens_uncached": 58251,
+    "cached_tokens": 167248,
+    "completion_tokens": 1954,
+    "reasoning_tokens": 1797
+  },
+  "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.636799186468124,
+      "ttft_sec": 7.329275650903583,
+      "prompt_tokens": 7498,
+      "cached_tokens": 0,
+      "completion_tokens": 256,
+      "reasoning_tokens": 148,
+      "output_tps": 8.734958437868189,
+      "error": null
+    },
+    {
+      "ok": true,
+      "elapsed_sec": 46.99894358962774,
+      "ttft_sec": 21.139840373769403,
+      "prompt_tokens": 34177,
+      "cached_tokens": 7488,
+      "completion_tokens": 162,
+      "reasoning_tokens": 113,
+      "output_tps": 6.264718410677597,
+      "error": null
+    },
+    {
+      "ok": true,
+      "elapsed_sec": 45.031732741743326,
+      "ttft_sec": 3.066617039963603,
+      "prompt_tokens": 35384,
+      "cached_tokens": 34160,
+      "completion_tokens": 256,
+      "reasoning_tokens": 256,
+      "output_tps": 6.100304877490023,
+      "error": null
+    },
+    {
+      "ok": true,
+      "elapsed_sec": 39.382855931296945,
+      "ttft_sec": 9.138474140316248,
+      "prompt_tokens": 19274,
+      "cached_tokens": 7472,
+      "completion_tokens": 256,
+      "reasoning_tokens": 256,
+      "output_tps": 8.464381972467455,
+      "error": null
+    },
+    {
+      "ok": true,
+      "elapsed_sec": 46.742042660713196,
+      "ttft_sec": 3.5163993053138256,
+      "prompt_tokens": 37099,
+      "cached_tokens": 35376,
+      "completion_tokens": 256,
+      "reasoning_tokens": 256,
+      "output_tps": 5.922410405674684,
+      "error": null
+    },
+    {
+      "ok": true,
+      "elapsed_sec": 35.704231740906835,
+      "ttft_sec": 5.4012624602764845,
+      "prompt_tokens": 14661,
+      "cached_tokens": 7472,
+      "completion_tokens": 256,
+      "reasoning_tokens": 256,
+      "output_tps": 8.448017012103007,
+      "error": null
+    },
+    {
+      "ok": true,
+      "elapsed_sec": 46.75327887199819,
+      "ttft_sec": 3.1515272110700607,
+      "prompt_tokens": 38199,
+      "cached_tokens": 37088,
+      "completion_tokens": 256,
+      "reasoning_tokens": 256,
+      "output_tps": 5.871323748431043,
+      "error": null
+    },
+    {
+      "ok": true,
+      "elapsed_sec": 47.12014847807586,
+      "ttft_sec": 3.015753908082843,
+      "prompt_tokens": 39207,
+      "cached_tokens": 38192,
+      "completion_tokens": 256,
+      "reasoning_tokens": 256,
+      "output_tps": 5.8044102519927305,
+      "error": null
+    }
+  ]
+}