30s recording で 14,909 encoder / iter 約 40 encoder を観測。当初は STIME 70% = sync overhead と解釈したが、B-mini プロト (scatter wait_until_completed 削除) で iter 速度が < 1% しか変わらず仮説撤回。真の time breakdown は GPU compute ~70% / CPU encoding ~30%、fusion ROI は小さい。
Phase 5 step 30 で M4 Max 上の 30s Metal System Trace を取得 (646MB bundle)。1 iter で約 40 個の Metal encoder を作成、CPU 時間の 70% が syscall (mach_msg_trap)。当初は「dispatch sync が dominant な遅さの主因」と判断し step 31.5 軽量 fusion を推奨したが、B-mini プロト (scatter wait_until_completed 削除) で iter 速度がほぼ変わらず (< 1% 改善) → 解釈の誤りを発見。
| 指標 | 値 | 補足 |
|---|---|---|
| 取得 iter 数 | ~375 | 30s ÷ 80ms/iter |
| 総 encoder 数 | 14,909 | metal-application-encoders-list table |
| encoders/iter | ~40 | これが想定外に多い |
| Trace bundle サイズ | 646MB | finalize 後 (raw 3.5GB → 圧縮) |
| GPU execution points | 520,546 | 個別 GPU event (詳細すぎ、集計困難) |
| CPU samples (timer fired) | 10,777 | 1ms 周期、Running 時のみ捕捉 |
| 指標 | 値 | 含意 |
|---|---|---|
| %CPU | 47.9% | 単スレッド換算で 0.5 core 程度 |
| UTIME (user time) | 1:13.56 | Rust app 自身の計算 |
| STIME (system time) | 2:41.94 | kernel/syscall = mach_msg_trap (wait_until_completed) |
| STIME / (UTIME + STIME) | 70% | CPU 時間の 7 割が GPU 同期待ち (初期解釈、後に撤回) |
| Wall time | 746s | lam0.10 全 10k iter |
| 総 CPU time / Wall time | 31.5% | 残 68.5% は GPU active or 全体 idle |
commit() + wait_until_completed() cycle を伴うmach_msg_trap 経由の wait_until_completed() が dominant、Rust user code は CPU 時間の 30% のみstep 31.5 (1 iter 1 commit にする、IndirectCommandBuffer なし、共有 cmd buffer 引数化): 工数 2-3 日、期待 iter 速度 80ms → 40-50ms (step 32 と同等の効果)、ICB なしでも cmd buffer fusion だけで主要効果は得られる、と推定。
full step 32 (ICB + 動的 dispatch chain): 工数 1 週間、期待 iter 速度は step 31.5 と同程度、ただし dynamic refine やスケール時にメリット。現状の固定 iter loop なら step 31.5 で十分、と推定 (後に B-mini で撤回)。
選択肢 B (step 31.5 軽量 fusion) を推奨。理由:
ただし以下は事前確認が必要: gradient check が fusion 後も全 pass する保証、ssim.rs の独立 cmd buffer use case (training context 外) を残す設計、run-time impact: H baseline (22.42 dB) を fusion 後に再走させて bit-identical 検証 (atomic 順序変化で ±ULP は許容)。
CLI 抽出ではカバー仕切れない情報: CPU/GPU 同時タイムライン (どこで GPU が idle 待ちか)、mach_msg_trap の callstack (どの Rust 関数が wait してるか)、per-encoder GPU 実行時間ヒストグラム、thermal throttling 時刻と GPU clock 推移。open runs/phase5-step30/profile-30s-lam0.20.trace で Instruments.app に開いて視覚分析推奨。所要 15-30 分。
gpu_tile.rs::radix_sort で buf_shift を 16 個独立 buffer に分離 (race 回避)、中間 pass の scatter wait_until_completed を削除、最終 pass のみ残す。同 queue 内 cmd buffer は GPU 上で順次実行されるため、論理的には wait 不要。
下表のとおり改善幅 < 1%、noise floor (±0.3 ms) 内。unit test 7/7 全 pass。
| iter | pre-fusion | post-fusion | 差 |
|---|---|---|---|
| 200 | 73.3 ms | 72.2 ms | -1.1 ms |
| 500 | 64.5 ms | 63.7 ms | -0.8 ms |
| 800 | 60.3 ms | 60.4 ms | +0.1 ms |
| 1000 | 61.6 ms | 63.1 ms | +1.5 ms |
過去の解釈には 2 つの誤りがあった:
実際: 同 queue 内 cmd buffer は既に GPU 上で順次実行されている。wait_until_completed は CPU 側の観測ポイントを変えるだけで、GPU 待ち時間自体は短縮しない。次 cmd buffer の wait で結局 GPU 完了を待つことになる。
実際: STIME は CPU が kernel mode で実行してる時間 (encoding, mach IPC processing)。CPU が wait_until_completed で blocked してる時間は STIME に 入らない (Blocked state)。「22% wall time = 同期 overhead」は誤った推論。
80ms/iter の内訳:
fusion で削れるのは 25ms 内のごく一部のみ。GPU compute 部分は kernel-level 最適化が必要。
dispatch 系の最適化は GPU compute bottleneck の状況では効かない。後続の path:
gpu_tile.rs の変更 (buf_shift 16 buffer 化 + scatter wait 部分削除) は commit 済: 正しさは保たれている (unit test 7/7 pass)、速度向上は微小だが、コードはより明示的になった (race 回避策が文書化されている)、後の最適化作業で base point として再利用可能。
Profile 数値の解釈は実験で裏取りすること。STIME ≠ GPU 同期待ち、wait_until_completed 削除 ≠ sync overhead 削減。kernel-level の per-call timing (step 30b) が必要 → step 30b でその場で rasterize_backwards 24ms/call が dominant と判明する流れに繋がる。