Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
@@ -0,0 +1,157 @@
# 2026-07 — Removing PTO2LocalReadyBuffer exposed a missing dcci in EP dispatch

## Status

**RESOLVED** in PR #1245. Root cause was a latent kernel bug (dispatch never
flushed `recv_count_out` to HBM), unmasked by the dispatch-timing change from
removing `PTO2LocalReadyBuffer`. Fixed by a one-line `dcci` in the example
kernel; the local-buffer removal itself is correct. Onboard a2a3 3/3 pass after
the fix. See "Fix" below.

## Symptom

`examples/workers/l3/ep_dispatch_combine` (a2a3 onboard, `device_count=2`)
fails its golden check **deterministically** after the local-buffer removal:

- baseline (local buffer present): onboard **3/3 PASS**
- current (local buffer removed): onboard **3/3 FAIL**, sim **PASS**

No runtime-error signatures at all (zero 507018 / HandleTaskTimeout / deadlock /
stall in the device log). It is a **wrong result**, not a hang.

## Isolation (what the diagnostics prove)

The example verifies two stages; only the second fails:

- **dispatch stage** (`_verify_recv_outputs`: recv_x / recv_w / recv_idx /
recv_count) — **passes** (prints nothing; it only prints on mismatch).
- **combine stage** (`_verify_routed_y`) — **fails**, and the chip's `routed_y`
is **all zero**: `got min=0 median=0 max=0`, `bad=524287/524288`, `rel=1.0`,
bad-d span = full [0,4095], bad rows = 128/128 on both chips.

So dispatch (which does the same class of cross-rank TPUT/TNOTIFY) is fine; the
combine kernel produces an entirely empty result.

## Hypothesis history

### REJECTED: dispatch→combine pub_counts visibility gap

Original theory: combine's push loop no-ops because `pub_counts` (written by
dispatch into window scratch, read by combine) reads as zero under the new
dispatch timing, leaving `routed_y_buf` untouched → all-zero `routed_y`.

**Disproved by direct measurement.** A temporary probe summed the whole
`pub_counts` table combine reads and broadcast it into `routed_y[0]` (host-
visible); on current-onboard it read **non-zero** (chip0 sum surfaced as
`got max=20476.7`). So the dispatch→combine scratch dataflow IS visible — combine
sees correct counts. This edge is NOT the bug.

### OPEN: root cause is in combine's push→reduce section

With pub_counts confirmed visible, the all-zero `routed_y` must come from
downstream of that read, inside combine.cpp:

1. **push phase** — the cross-rank `TPUT` of `recv_y` rows into the peer's
`routed_y_buf` never lands, or
2. **combine_done barrier** (TNOTIFY/TWAIT) — mis-synchronizes, or
3. **reduce phase** — reads `routed_y_buf` as zero.

A second probe (sum `routed_y_buf` after the barrier, before reduce) would
disambiguate push-landed vs reduce-read, but the ad-hoc GM-scalar-loop probe
**failed to compile** on AICore (bisheng frontend error 70). Next approach:
runtime-side timing comparison (baseline vs current [STRACE] / PTO2_SCHED_PROFILING
of the combine task) rather than more in-kernel probes.

### NARROWED: the empty result originates at local_expert, not combine

Python-side probes (main.py, host-visible OUTPUT_EXISTING tensors, no kernel
recompile) on current-onboard show:

| tensor | producer | state after run |
| ------ | -------- | --------------- |
| recv_x_out | dispatch | **correct** (nz≈3.2M, absmax 5472) |
| recv_w_out | dispatch | **correct** (nz=782) |
| recv_count_out | dispatch | **correct** (sum 782 / 754) |
| recv_y | local_expert | **ALL ZERO** (nz=0) |
| routed_y | combine | all zero (combine pushes recv_y's zeros) |

So combine is a red herring — it correctly propagates an already-empty input.
The regression is at the **dispatch → local_expert** task edge: local_expert
had all three inputs correct in the *final* state, yet produced nothing.

local_expert (`kernels/aiv/local_expert.cpp`) bounds its work by
`n_rows = recv_count[e]` and skips the row loop entirely when it reads 0.
**Leading hypothesis:** under the new dispatch timing, local_expert's AICore
reads `recv_count` (dispatch's HBM OUTPUT_EXISTING output, reused as
local_expert INPUT) as stale/zero → every expert does 0 rows → recv_y stays
zero. The host sees recv_count=782 afterwards because dispatch's write *did*
land — just not before local_expert consumed it.

Two overlapping-sched-window facts, established via device_wall.sched markers:
the two ranks' combine tasks DO run concurrently (rules out "one rank exits
before the other's push"), consistent with the fault being upstream in
local_expert, not the cross-rank combine.

A kernel sentinel probe to confirm "did local_expert read count=0" crashed the
AICore (507015 — bad UB slot addresses in the ad-hoc probe) and was reverted.

### CONFIRMED ROOT CAUSE: dispatch never flushes recv_count_out to HBM

A compile-safe probe settled it: forcing local_expert to process **all R rows**
(`n_rows = R`, ignoring `recv_count[e]`) makes the whole test **PASS** on
current-onboard. So recv_x / recv_w are visible and correct — the *only* wrong
input is `recv_count`, which local_expert reads as **0**.

Why: in `dispatch.cpp`, `recv_count_out[e] = sum;` (line ~304) is a **raw scalar
GM store** from the AICore scalar unit, followed only by `pipe_barrier(PIPE_ALL)`.
`pipe_barrier` orders on-core pipelines but does **NOT** flush the cache line to
HBM — that needs a `dcci(..., CACHELINE_OUT)`. recv_x/recv_w/recv_idx are safe
because they go out through `TSTORE` (a real vector→GM write). `recv_count_out`
sits in cache; whether the downstream `local_expert` task's AICore sees it in
HBM depended on incidental timing.

Removing `PTO2LocalReadyBuffer` changed AICPU dispatch timing enough that
local_expert now reads `recv_count_out` before dispatch's cached scalar store
lands in HBM → every expert runs 0 rows → recv_y all-zero → combine faithfully
pushes zeros → routed_y all-zero. Baseline timing happened to let the store
land first; sim has no cache so it never reproduced.

This is a **latent kernel bug**, not a runtime regression: the local-buffer
removal is correct; it merely unmasked a missing `dcci` in the example kernel.

## Fix

In `examples/workers/l3/ep_dispatch_combine/kernels/aiv/dispatch.cpp`, after the
`recv_count_out[e] = sum;` loop, flush the written range to HBM with `dcci`
(pattern already used in `qwen3_14b_decode/fa_work_build.cpp` and
`deferred_notify_demo/kernel_producer.cpp`: `dcci(ptr, ENTIRE_DATA_CACHE,
CACHELINE_OUT)` / `dcci(ptr, SINGLE_CACHE_LINE, CACHELINE_OUT)`). The runtime's
completion-before-dispatch invariant then carries the flushed value to
local_expert correctly. Codegen-owned area (`examples/`); no runtime change.

Robustness note: the same raw-scalar-store-without-dcci pattern should be
audited elsewhere in dispatch.cpp (any non-TSTORE GM write consumed by a later
task), since all of them were relying on the same incidental timing.

## Superseded ambiguity (kept for history)

- If the dispatch→combine **window-scratch visibility** is a guarantee the
runtime is supposed to provide across a task dependency edge, the real fix is
in the **runtime** (`src/{arch}/runtime/tensormap_and_ringbuffer/`) — restore
the cross-task visibility the local buffer was incidentally providing — and
the local-buffer removal is fine once that guarantee is explicit. This is the
Runtime-owned area.
- If combine is simply **missing a synchronization** it always needed (and only
passed before by timing luck), the fix is in the **kernel**
(`examples/.../combine.cpp`, Codegen-owned) — e.g. a barrier / acquire on
`pub_counts` before the push loop.

Deciding requires the pub_counts dump above. Do not edit either area before the
dump confirms which edge actually fails.

## Do NOT re-derive

- sim passes; the bug is hardware-timing-only. Reproducing needs a2a3 onboard,
`device_count=2`, via `task-submit`.
- dispatch is not the culprit — it verifies clean. Focus on the dispatch→combine
window edge (`pub_counts`) and the combine push loop's `n == 0` early-out.
1 change: 1 addition & 0 deletions docs/investigations/README.md
Original file line number Diff line number Diff line change
Expand Up @@ -84,6 +84,7 @@ that ...".

Newest first.

- [2026-07 — Removing PTO2LocalReadyBuffer exposed a missing dcci in EP dispatch](2026-07-local-buffer-removal-ep-combine-regression.md) — RESOLVED in #1245: local-buffer removal changed dispatch timing and unmasked a latent kernel bug (dispatch never dcci'd `recv_count_out` to HBM → local_expert read count=0 → all-zero output); fixed with a one-line dcci in the example kernel
- [2026-06 — Gating the two residual profiling enable() calls on the orch/scheduler hot path](2026-06-orch-profiling-enable-gates-hot-path.md) — gated under existing `PTO2_PROFILING`; magnitude unmeasured, no new macro
- [2026-06 — Replacing COND with GM+dcci for AICore→AICPU notification](2026-06-cond-vs-gm-notification.md)
- [2026-06 — Letting AICore directly read or write the SPR MMIO window](2026-06-aicore-mmio-to-spr.md)
Expand Down
4 changes: 2 additions & 2 deletions docs/scheduler.md
Original file line number Diff line number Diff line change
Expand Up @@ -84,8 +84,8 @@ ReadyQueue ready_next_level_queue_; // WorkerType::NEXT_LEVEL tasks
ReadyQueue ready_sub_queue_; // WorkerType::SUB tasks
```

Matching L2's per-shape ready buffer (`PTO2_LocalReadyBuffer` fan-out to
AIC / AIV / MIX queues), with the L3+ exception that we use `std::queue`
Matching L2's per-shape ready queues (the shared MPMC `ready_queues[]` split
by AIC / AIV / MIX), with the L3+ exception that we use `std::queue`
(Allowed Exception 3: dynamic data structures on host) and only two
worker types (Allowed Exception 2: `NEXT_LEVEL` + `SUB` at L3+, not
AIC / AIV / MIX). `Orchestrator::submit_*` routes each slot to the queue
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -303,6 +303,12 @@ extern "C" __aicore__ __attribute__((always_inline)) void kernel_entry(__gm__ in
}
recv_count_out[e] = sum;
}
// recv_count_out is written by the scalar unit (raw GM store), not TSTORE,
// so it stays in cache; the downstream local_expert task reads it to bound
// its row loop. Flush the one cache line ([L=16,1] INT32 = 64 B) so its HBM
// value is visible regardless of dispatch/consumer timing. (recv_x/recv_w/
// recv_idx go out via TSTORE and need no dcci.)
dcci((__gm__ void *)recv_count_out, SINGLE_CACHE_LINE, CACHELINE_OUT);

// ------------------------------------------------------------------
// payload_push: push x / weight / idx payloads via TPUT.
Expand Down
30 changes: 4 additions & 26 deletions simpler_setup/tools/swimlane_converter.py
Original file line number Diff line number Diff line change
Expand Up @@ -1549,17 +1549,11 @@ def _find_containing_complete(thread_idx: int, finish_us: float):

# Queue-depth snapshot fields. Layout per
# L2SwimlaneAicpuSchedPhaseRecord docstring: [AIC, AIV, MIX].
local_at_start = record.get("local_at_start")
local_at_end = record.get("local_at_end")
shared_at_start = record.get("shared_at_start")
shared_at_end = record.get("shared_at_end")
depths_valid = (
isinstance(local_at_start, list)
and isinstance(local_at_end, list)
and isinstance(shared_at_start, list)
isinstance(shared_at_start, list)
and isinstance(shared_at_end, list)
and len(local_at_start) == 3
and len(local_at_end) == 3
and len(shared_at_start) == 3
and len(shared_at_end) == 3
)
Expand All @@ -1579,8 +1573,6 @@ def _find_containing_complete(thread_idx: int, finish_us: float):
# parser-safe while still self-documenting.
phase_args.update(
{
f"T{thread_idx}_local_at_start (aic,aiv,mix)": list(local_at_start),
f"T{thread_idx}_local_at_end (aic,aiv,mix)": list(local_at_end),
"shared_at_start (aic,aiv,mix)": list(shared_at_start),
"shared_at_end (aic,aiv,mix)": list(shared_at_end),
}
Expand Down Expand Up @@ -1611,27 +1603,13 @@ def _find_containing_complete(thread_idx: int, finish_us: float):
# start, so emitting both is redundant. Two samples at the
# SAME ts (e.g. final-drain emit where start_time==end_time)
# also breaks Perfetto's rate calc (divide-by-zero → NULL).
# Track name carries thread index so it reads standalone
# even with the thread tree collapsed. Only complete/dispatch
# carry real queue depths; release/resolve/early_dispatch zero-
# fill them, so skip their counter samples to avoid spurious 0
# dips.
# Only complete/dispatch carry real queue depths; release/
# resolve/early_dispatch zero-fill them, so skip their counter
# samples to avoid spurious 0 dips.
if phase not in ("complete", "dispatch"):
continue
if not depths_valid:
continue
local_track_name = f"local_ready_buf_T{thread_idx}"
events.append(
{
"args": {"AIC": local_at_end[0], "AIV": local_at_end[1], "MIX": local_at_end[2]},
"cat": "queue",
"name": local_track_name,
"ph": "C",
"pid": 2,
"tid": tid,
"ts": end_us,
}
)
# Shared queue: dedicated tid 3999 so all 3 schedulers'
# snapshots compose onto one timeline (it's the same global
# queue regardless of who sampled it). Samples from different
Expand Down
14 changes: 4 additions & 10 deletions src/a2a3/platform/include/aicpu/l2_swimlane_collector_aicpu.h
Original file line number Diff line number Diff line change
Expand Up @@ -166,11 +166,9 @@ void l2_swimlane_aicpu_init_phase(int worker_count, int num_sched_phase_threads,
* pool. Silently drops records when the buffer is full or the pool was not
* primed (init failed for this thread).
*
* Queue-depth snapshots distinguish "task hidden in T0's local_buf" from
* "shared queue has it but peers spin on the wrong shape" — the former shows
* `local_depth > 0, shared_depth == 0` for the owning thread while peers see
* `shared_depth == 0` until overflow. Pass nullptr for any of the four arrays
* when not capturing (the record's corresponding slot is zero-filled).
* Queue-depth snapshots record the per-shape shared ready-queue occupancy at
* phase boundaries. Pass nullptr for either array when not capturing (the
* record's corresponding slot is zero-filled).
*
* @param thread_idx Scheduler thread index
* @param kind Complete or Dispatch
Expand All @@ -180,16 +178,12 @@ void l2_swimlane_aicpu_init_phase(int worker_count, int num_sched_phase_threads,
* @param tasks_processed Tasks processed in this phase batch
* @param pop_hit Dispatch delta since last emit (0 for Complete)
* @param pop_miss Dispatch delta since last emit (0 for Complete)
* @param local_at_start Per-shape PTO2LocalReadyBuffer.count at phase start (size L2SWIMLANE_NUM_QUEUE_SHAPES; may be
* nullptr)
* @param shared_at_start Per-shape sched.ready_queues[shape].size() at phase start (may be nullptr)
* @param local_at_end Per-shape PTO2LocalReadyBuffer.count at phase end (may be nullptr)
* @param shared_at_end Per-shape sched.ready_queues[shape].size() at phase end (may be nullptr)
*/
void l2_swimlane_aicpu_record_sched_phase(
int thread_idx, L2SwimlaneSchedPhaseKind kind, uint64_t start_time, uint64_t end_time, uint32_t loop_iter,
uint32_t tasks_processed, uint32_t pop_hit = 0, uint32_t pop_miss = 0, const int16_t *local_at_start = nullptr,
const int16_t *shared_at_start = nullptr, const int16_t *local_at_end = nullptr,
uint32_t tasks_processed, uint32_t pop_hit = 0, uint32_t pop_miss = 0, const int16_t *shared_at_start = nullptr,
const int16_t *shared_at_end = nullptr
);

Expand Down
29 changes: 12 additions & 17 deletions src/a2a3/platform/include/common/l2_swimlane_profiling.h
Original file line number Diff line number Diff line change
Expand Up @@ -535,27 +535,22 @@ constexpr int L2SWIMLANE_NUM_QUEUE_SHAPES = 3;
* (zero for Complete). Kept named, not "extra1"/"extra2", so the device-side
* commit and the host-side JSON emit don't drift on which extra means which.
*
* Queue-depth snapshots (local_depth_*, shared_depth_*) record the per-shape
* scheduler queue occupancy at phase boundaries. They surface the
* dep-release-then-discovery latency that head OH alone can't distinguish from
* register-write latency: a phase whose start sees `local_depth=N, shared=0`
* and end sees `local_depth=N-K` shows that K tasks were popped from this
* thread's private buffer (invisible to peer threads) — peers must spin until
* those tasks overflow into shared. Filled with 0 below SCHED_PHASES.
* Queue-depth snapshots (shared_depth_*) record the per-shape scheduler ready
* queue occupancy at phase boundaries. They surface the dep-release-then-
* discovery latency that head OH alone can't distinguish from register-write
* latency. Filled with 0 below SCHED_PHASES.
*/
struct L2SwimlaneAicpuSchedPhaseRecord {
uint64_t start_time; // Phase start timestamp
uint64_t end_time; // Phase end timestamp
uint32_t loop_iter; // Scheduler-loop iteration number on this thread
L2SwimlaneSchedPhaseKind kind; // see enum above
uint32_t tasks_processed; // Tasks processed in this phase batch
uint32_t pop_hit; // SCHED_DISPATCH delta since last emit (0 for Complete)
uint32_t pop_miss; // SCHED_DISPATCH delta since last emit (0 for Complete)
int16_t local_depth_at_start[L2SWIMLANE_NUM_QUEUE_SHAPES]; // this thread's PTO2LocalReadyBuffer.count
int16_t local_depth_at_end[L2SWIMLANE_NUM_QUEUE_SHAPES];
uint64_t start_time; // Phase start timestamp
uint64_t end_time; // Phase end timestamp
uint32_t loop_iter; // Scheduler-loop iteration number on this thread
L2SwimlaneSchedPhaseKind kind; // see enum above
uint32_t tasks_processed; // Tasks processed in this phase batch
uint32_t pop_hit; // SCHED_DISPATCH delta since last emit (0 for Complete)
uint32_t pop_miss; // SCHED_DISPATCH delta since last emit (0 for Complete)
int16_t shared_depth_at_start[L2SWIMLANE_NUM_QUEUE_SHAPES]; // sched->ready_queues[shape].size()
int16_t shared_depth_at_end[L2SWIMLANE_NUM_QUEUE_SHAPES];
uint32_t _pad; // 64B alignment padding
uint32_t _pad[4]; // 64B alignment padding
};
static_assert(sizeof(L2SwimlaneAicpuSchedPhaseRecord) == 64, "L2SwimlaneAicpuSchedPhaseRecord layout drift");

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -796,8 +796,8 @@ static Record *acquire_phase_slot(

void l2_swimlane_aicpu_record_sched_phase(
int thread_idx, L2SwimlaneSchedPhaseKind kind, uint64_t start_time, uint64_t end_time, uint32_t loop_iter,
uint32_t tasks_processed, uint32_t pop_hit, uint32_t pop_miss, const int16_t *local_at_start,
const int16_t *shared_at_start, const int16_t *local_at_end, const int16_t *shared_at_end
uint32_t tasks_processed, uint32_t pop_hit, uint32_t pop_miss, const int16_t *shared_at_start,
const int16_t *shared_at_end
) {
if (!s_phase_initialized) return;
auto *state = s_sched_phase_pools[thread_idx];
Expand Down Expand Up @@ -829,9 +829,7 @@ void l2_swimlane_aicpu_record_sched_phase(
dst[i] = src[i];
}
};
copy_snapshot(record->local_depth_at_start, local_at_start);
copy_snapshot(record->shared_depth_at_start, shared_at_start);
copy_snapshot(record->local_depth_at_end, local_at_end);
copy_snapshot(record->shared_depth_at_end, shared_at_end);
}

Expand Down
Loading
Loading