[PR #426] [Bug] Fix bench_kineto returning zero on the first call in a process #437

Open
opened 2026-10-26 21:17:46 +00:00 by bsakaguchi · 0 comments
Owner

📋 Pull Request Information

Original PR: https://github.com/deepseek-ai/DeepGEMM/pull/426
Author: @HangruiCao2000
Created: 9/2/2026
Status: 🔄 Open

Base: main ← Head: fix/bench-kineto-first-call-empty-table


📝 Commits (1)

  • af9e1ed Fix bench_kineto returning zero on the first call in a process

📊 Changes

1 file changed (+23 additions, -0 deletions)

View changed files

📝 deep_gemm/testing/bench.py (+23 -0)

📄 Description

Summary

bench_kineto returns 0 for every kernel on the first call in a process. The first torch.profiler.profile(activities=[CUDA]) session records no device activity at all — key_averages() comes back empty, nothing matches any kernel name, and the parser falls through to its else 0 branch.

Since the first bench_kineto call in each test file feeds a division, six of our own test files abort four frames away from the cause:

Testing GEMM:
Traceback (most recent call last):
  File "tests/test_bf16.py", line 245, in <module>
    test_gemm()
  File "tests/test_bf16.py", line 49, in test_gemm
    f'{2 * m * n * k / t / 1e12:4.0f} TFLOPS | '
       ~~~~~~~~~~~~~~^~~
ZeroDivisionError: division by zero

test_bf16, test_fp8_fp4, test_einsum, test_attention, test_hyperconnection and test_legacy all fail this way. test_layout survives only because it happens to guard its division — it silently reports its first shape as 0 us | 0 GB/s instead.

Root cause

This is a property of the profiler, not of DeepGEMM. It reproduces with no DeepGEMM code at all, and only the first session in the process is affected:

import torch
P = torch.profiler.ProfilerActivity
a = torch.randn(4096, 4096, device='cuda', dtype=torch.bfloat16)
b = torch.randn(4096, 4096, device='cuda', dtype=torch.bfloat16)

def run(i):
    sch = torch.profiler.schedule(wait=0, warmup=1, active=1, repeat=1)
    p = torch.profiler.profile(activities=[P.CUDA], schedule=sch, acc_events=True)
    with p:
        for _ in range(2):
            for _ in range(30): a @ b
            torch.cuda.synchronize(); p.step()
    print(f'call {i}: table lines =', len(p.key_averages().table().split('\n')))

for i in range(4): run(i)
call 0: table lines = 1     <-- empty
call 1: table lines = 10
call 2: table lines = 10
call 3: table lines = 10

I tried each candidate fix in a fresh process:

variant result
baseline (wait=0, warmup=1, active=1) empty
more warmup (wait=1, warmup=2, active=1, 4 iters) empty
no schedule at all empty
add ProfilerActivity.CPU works
one throwaway profiler session first works

More warmup steps do not help, so this is CUPTI lazy initialization at session level rather than a schedule problem. Adding ProfilerActivity.CPU also works, but it puts CPU op rows in the table where they can match kernel-name substrings and trip the existing uniqueness assertion — so this PR uses the throwaway session. Its with body is empty, so it runs no GPU work and costs nothing.

Changes

  1. _warmup_kineto() — open and close one empty profiler session, once per process, before the measured session.
  2. Assert the profiling table is non-empty. An absent kernel name legitimately means "this kernel did not run" (e.g. the reduce name in test_bf16 when there is no split-K), so that case must keep returning 0; but a table with no device activity at all is always a profiling failure and should say so rather than report every kernel as infinitely fast. test_layout already wraps its call in try/except AssertionError, so it is unaffected.

Verification

Measured end-to-end on GB200 / sm_100a: capability (10, 0), get_arch_major() == 10, cubins built for sm_100 (cuobjdump --list-elf -> kernel.sm_100.cubin), aarch64, CUDA 13.1, PyTorch 2.9.0+cu130, third-party/cutlass at the pinned f3fde58.

Determinism. Unpatched tests/test_bf16.py fails 3/3 independent runs with the identical traceback. Patched, it passes.

Recovered data point. tests/test_layout.py, first row:

- > Perf (num_groups= 1, mn= 4096, k=  128, transpose=1, use_ue8m0=0, gran_k= 32):    0 us |    0 GB/s
+ > Perf (num_groups= 1, mn= 4096, k=  128, transpose=1, use_ue8m0=0, gran_k= 32):    3 us |   49 GB/s

3 us | 49 GB/s is what the same shape measures later in the same run, and every subsequent row is unchanged.

Paired first-call check against a real sm100 kernel, at test_bf16's actual first shape and at a large square:

pre-fix  m=1 n=2112 k=7168  call 0: no device activity recorded
pre-fix  m=1 n=2112 k=7168  call 1: t =  20.30 us
pre-fix  m=1 n=2112 k=7168  call 2: t =  20.27 us
fixed    m=1 n=2112 k=7168  call 0: t =  20.10 us
fixed    m=1 n=2112 k=7168  call 1: t =  20.40 us
fixed    m=1 n=2112 k=7168  call 2: t =  20.42 us

Post-fix call 0 agrees with calls 1 and 2 to within run-to-run noise: the warmup recovers the measurement without shifting it.

Rows produced. Perf rows emitted, and how many of them read 0.0 us:

test file before after zero-time rows after
test_bf16 0 (aborted) 272 0
test_fp8_fp4 0 (aborted) 384 0
test_einsum 0 (aborted) 50 0

test_bf16 also now reports Average speedup over cuBLASLt: 0.894x, an aggregate that previously could not be computed at all. Coverage spans the sm100 GEMM family: sm100_bf16_gemm, sm100_bf16_k_grouped_gemm, sm100_bf16_m_grouped_gemm_contiguous, sm100_bf16_m_grouped_gemm_masked, sm100_fp8_fp4_gemm_1d1d, sm100_tf32_hc_prenorm_gemm, sm100_bmn_bnk_mn_gemm.

Out of scope

Two test files fail on this machine both before and after, for reasons unrelated to this bug:

  • test_mega_moe needs at least 6 GPUs (ValueError: device_id cuda:5 is out of range); this box has 4.
  • test_sanitizer hits a JIT assertion under compute-sanitizer's build flags: not std::regex_search(output, std::regex(R"(Local memory used)")) while compiling fp8_gemm_nt_skip_head_mid, i.e. that kernel spills local memory. Reported separately if useful.

🤖 Generated with Claude Code


🔄 This issue represents a GitHub Pull Request. It cannot be merged through Gitea due to API limitations.

## 📋 Pull Request Information **Original PR:** https://github.com/deepseek-ai/DeepGEMM/pull/426 **Author:** [@HangruiCao2000](https://github.com/HangruiCao2000) **Created:** 9/2/2026 **Status:** 🔄 Open **Base:** `main` ← **Head:** `fix/bench-kineto-first-call-empty-table` --- ### 📝 Commits (1) - [`af9e1ed`](https://github.com/deepseek-ai/DeepGEMM/commit/af9e1ed184542d97b05fae3e460f53599aa8210b) Fix bench_kineto returning zero on the first call in a process ### 📊 Changes **1 file changed** (+23 additions, -0 deletions) <details> <summary>View changed files</summary> 📝 `deep_gemm/testing/bench.py` (+23 -0) </details> ### 📄 Description ## Summary `bench_kineto` returns `0` for every kernel on the **first call in a process**. The first `torch.profiler.profile(activities=[CUDA])` session records no device activity at all — `key_averages()` comes back empty, nothing matches any kernel name, and the parser falls through to its `else 0` branch. Since the first `bench_kineto` call in each test file feeds a division, **six of our own test files abort** four frames away from the cause: ``` Testing GEMM: Traceback (most recent call last): File "tests/test_bf16.py", line 245, in <module> test_gemm() File "tests/test_bf16.py", line 49, in test_gemm f'{2 * m * n * k / t / 1e12:4.0f} TFLOPS | ' ~~~~~~~~~~~~~~^~~ ZeroDivisionError: division by zero ``` `test_bf16`, `test_fp8_fp4`, `test_einsum`, `test_attention`, `test_hyperconnection` and `test_legacy` all fail this way. `test_layout` survives only because it happens to guard its division — it silently reports its *first* shape as `0 us | 0 GB/s` instead. ## Root cause This is a property of the profiler, not of DeepGEMM. It reproduces with **no DeepGEMM code at all**, and only the first session in the process is affected: ```python import torch P = torch.profiler.ProfilerActivity a = torch.randn(4096, 4096, device='cuda', dtype=torch.bfloat16) b = torch.randn(4096, 4096, device='cuda', dtype=torch.bfloat16) def run(i): sch = torch.profiler.schedule(wait=0, warmup=1, active=1, repeat=1) p = torch.profiler.profile(activities=[P.CUDA], schedule=sch, acc_events=True) with p: for _ in range(2): for _ in range(30): a @ b torch.cuda.synchronize(); p.step() print(f'call {i}: table lines =', len(p.key_averages().table().split('\n'))) for i in range(4): run(i) ``` ``` call 0: table lines = 1 <-- empty call 1: table lines = 10 call 2: table lines = 10 call 3: table lines = 10 ``` I tried each candidate fix in a fresh process: | variant | result | |---|---| | baseline (`wait=0, warmup=1, active=1`) | **empty** | | more warmup (`wait=1, warmup=2, active=1`, 4 iters) | **empty** | | no schedule at all | **empty** | | add `ProfilerActivity.CPU` | works | | one throwaway profiler session first | works | More warmup *steps* do not help, so this is CUPTI lazy initialization at session level rather than a schedule problem. Adding `ProfilerActivity.CPU` also works, but it puts CPU op rows in the table where they can match kernel-name substrings and trip the existing uniqueness assertion — so this PR uses the throwaway session. Its `with` body is empty, so it runs no GPU work and costs nothing. ## Changes 1. `_warmup_kineto()` — open and close one empty profiler session, once per process, before the measured session. 2. Assert the profiling table is non-empty. An *absent kernel name* legitimately means "this kernel did not run" (e.g. the `reduce` name in `test_bf16` when there is no split-K), so that case must keep returning `0`; but a table with **no device activity at all** is always a profiling failure and should say so rather than report every kernel as infinitely fast. `test_layout` already wraps its call in `try/except AssertionError`, so it is unaffected. ## Verification Measured end-to-end on **GB200 / sm_100a**: capability `(10, 0)`, `get_arch_major() == 10`, cubins built for `sm_100` (`cuobjdump --list-elf` -> `kernel.sm_100.cubin`), aarch64, CUDA 13.1, PyTorch 2.9.0+cu130, `third-party/cutlass` at the pinned `f3fde58`. **Determinism.** Unpatched `tests/test_bf16.py` fails 3/3 independent runs with the identical traceback. Patched, it passes. **Recovered data point.** `tests/test_layout.py`, first row: ``` - > Perf (num_groups= 1, mn= 4096, k= 128, transpose=1, use_ue8m0=0, gran_k= 32): 0 us | 0 GB/s + > Perf (num_groups= 1, mn= 4096, k= 128, transpose=1, use_ue8m0=0, gran_k= 32): 3 us | 49 GB/s ``` `3 us | 49 GB/s` is what the same shape measures later in the same run, and every subsequent row is unchanged. **Paired first-call check** against a real sm100 kernel, at `test_bf16`'s actual first shape and at a large square: ``` pre-fix m=1 n=2112 k=7168 call 0: no device activity recorded pre-fix m=1 n=2112 k=7168 call 1: t = 20.30 us pre-fix m=1 n=2112 k=7168 call 2: t = 20.27 us fixed m=1 n=2112 k=7168 call 0: t = 20.10 us fixed m=1 n=2112 k=7168 call 1: t = 20.40 us fixed m=1 n=2112 k=7168 call 2: t = 20.42 us ``` Post-fix call 0 agrees with calls 1 and 2 to within run-to-run noise: the warmup recovers the measurement without shifting it. **Rows produced.** Perf rows emitted, and how many of them read `0.0 us`: | test file | before | after | zero-time rows after | |---|---|---|---| | `test_bf16` | 0 (aborted) | 272 | 0 | | `test_fp8_fp4` | 0 (aborted) | 384 | 0 | | `test_einsum` | 0 (aborted) | 50 | 0 | `test_bf16` also now reports `Average speedup over cuBLASLt: 0.894x`, an aggregate that previously could not be computed at all. Coverage spans the sm100 GEMM family: `sm100_bf16_gemm`, `sm100_bf16_k_grouped_gemm`, `sm100_bf16_m_grouped_gemm_contiguous`, `sm100_bf16_m_grouped_gemm_masked`, `sm100_fp8_fp4_gemm_1d1d`, `sm100_tf32_hc_prenorm_gemm`, `sm100_bmn_bnk_mn_gemm`. ### Out of scope Two test files fail on this machine both before and after, for reasons unrelated to this bug: - `test_mega_moe` needs at least 6 GPUs (`ValueError: device_id cuda:5 is out of range`); this box has 4. - `test_sanitizer` hits a JIT assertion under compute-sanitizer's build flags: `not std::regex_search(output, std::regex(R"(Local memory used)"))` while compiling `fp8_gemm_nt_skip_head_mid`, i.e. that kernel spills local memory. Reported separately if useful. 🤖 Generated with [Claude Code](https://claude.com/claude-code) --- <sub>🔄 This issue represents a GitHub Pull Request. It cannot be merged through Gitea due to API limitations.</sub>
Sign in to join this conversation.
No labels
pull-request
No milestone
No project
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set.

Reference
deepseek-ai/DeepGEMM#437
No description provided.