Fix: ACK-gate L2 swimlane rotation after moving AICore FIN early

docs/investigations/2026-07-aicore-swimlane-switch-overhead-and-ack-gate.md

@@ -0,0 +1,123 @@
+# L2 swimlane AICore: switch-overhead source + FIN-early reorder & ACK-gate
+
+**Date**: 2026-07-08
+**Verdict**: measured — the ~0.8 µs inter-task "switch" is the per-task
+record write-back (`dcci(record, CACHELINE_OUT) + dsb`) on AICore's own
+timeline; it is **inherent, not reducible by reordering**. Two changes
+shipped alongside the measurement: (1) sample the swimlane `end_time`
+after an early FIN so the record write no longer sits on the
+completion-signal path; (2) an AICPU-side **ACK-gate** on buffer
+rotation, required because that early FIN otherwise races the record
+flush at BUFFER_SIZE boundaries.
+
+## Question
+
+Switching between two back-to-back AICore tasks shows a ~0.7–1.0 µs gap
+on the L2 swimlane in normal dispatch (not in speculative early
+dispatch). Where does it come from, and can moving the FIN write earlier
+(release the core to AICPU sooner) shrink it?
+
+## What was tried
+
+Ran `qwen3_14b_decode` (`StressBatch16Seq3500`, block_dim auto → 72
+cores, 1088 AICore tasks) with `--enable-l2-swimlane 4` on a2a3 silicon
+via `task-submit`. Decomposed each core's inter-task gap from the
+records (`aicore_tasks = [core, token, reg_task_id, start, end,
+receive_to_start_cycles]`, 50 MHz → 20 ns/tick), classifying a gap as a
+**switch** when the next task was already dispatched before the previous
+ended (`dispatch(K+1) < end(K)`, i.e. work was waiting) vs a **WAIT**
+gap (core idle, scheduler/dep-bound). Switches split at `receive_time`
+(`= start − receive_to_start_cycles`):
+
+- `prev_tail = receive(K+1) − end(K)` — AICore's own post-task work:
+  `record_task` (the `dcci(record, OUT) + dsb`) + loop-around pickup.
+- `setup = receive_to_start_cycles(K+1)` — payload `dcci(ENTIRE)` + ACK.
+
+## Result
+
+| metric (steady state) | mean | p50 | p90 | p99 |
+| --------------------- | ---- | --- | --- | --- |
+| STEADY switch (`disp < end`) | 0.81 | 0.80 | 1.00 | 1.22 |
+| ↳ prev_tail (record + loop) | 0.52 | 0.50 | 0.66 | 0.88 |
+| ↳ setup (payload dcci + ack) | 0.29 | 0.28 | 0.40 | 0.60 |
+| first switch / core (cold) | 1.39 | 1.48 | 1.86 | 1.98 |
+| WAIT gap (core idle) | 126 | 54 | 381 | 698 |
+
+(µs; n = 581 steady switches, 403 wait gaps, 32 cores.)
+
+The switch's dominant half is **prev_tail ≈ 0.5 µs = the record
+write-back `dcci(record, CACHELINE_OUT) + dsb`**. `setup` (~0.28 µs) is
+the payload invalidate + ACK. The **WAIT gap (p99 ~700 µs)** dwarfs the
+whole switch — decode latency is a scheduler/dep-graph question, not a
+DFX one.
+
+**The switch gap is largely profiling self-cost, not a real hardware
+task switch.** With the swimlane on, every task issues three
+`get_sys_cnt_aicore()` SPR reads (receive / start / end), each ~100–200
+ns, and one record write-back. The `receive` read lands entirely inside
+the switch gap; the `end`/`start` reads contribute their boundary
+fractions. So the ~0.8 µs decomposes roughly as **get_sys_cnt reads
+(~0.2–0.4 µs) + record write-back `dcci+dsb` (~0.4–0.5 µs)** — i.e. the
+gap is dominated by the instrumentation itself. This is an *observer
+effect*: with the swimlane off none of these reads or the record write
+happen, so the gap vanishes — which is exactly why the overhead "only
+appears on the swimlane" and not in a non-profiled / early-dispatch run.
+`prev_tail`'s "record + loop" therefore includes the `receive` read, and
+`setup` includes part of the `start` read; neither is pure dcci/ack.
+
+**Moving FIN earlier does not shrink the AICore switch.** `record_task`
+still runs between `end(K)` and `receive(K+1)`, so prev_tail is
+unchanged. What the early FIN *does* change: AICPU observes completion
+~0.5 µs sooner (before the record write), decoupling the record flush
+from the completion signal. That is a pipelining nicety on the AICPU
+side, not a switch-gap reduction.
+
+## What shipped
+
+1. **`end_time` after an early FIN** (`aicore_executor.cpp`, tmr):
+   op order is now `ACK → pmu_begin → start → execute → FIN → end →
+   pmu_end → dump → record`. FIN fires right after `execute_task`;
+   `record_task` runs last, off the completion path. The three swimlane
+   timestamps are gated on `l2_swimlane_enabled`.
+
+2. **AICPU ACK-gate on rotation** (`l2_swimlane_collector_aicpu.cpp`,
+   shared a2a3). Because tmr now writes FIN *before* the record, the
+   completion-before-dispatch invariant no longer proves the old
+   buffer's tail record has drained at a BUFFER_SIZE rotation — AICPU
+   could enqueue a buffer whose last record's `dcci+dsb` is still in
+   flight (host then discards it as `start_time == 0`). Fix: at
+   rotation, publish the new buffer to AICore but **stash** the
+   just-filled buffer; release it to the host only when AICPU observes
+   AICore ACK the new buffer's first task (`reg_task_id == gate`). By
+   AICore's single-threaded program order that ACK is emitted only
+   after the previous task's `record_task + dsb`, so the tail record is
+   proven drained. `host_build_graph` writes the record *before* FIN,
+   so it has no such window — it does not wire the ACK hook and relies
+   on the next-rotation / run-end backstop.
+
+## Why not chase the switch further
+
+The 0.5 µs is a cache-line clean-out + `dsb` on a DFX-only path; it is
+sub-noise against the ~700 µs WAIT tail and self-correcting (the host
+tolerates a dropped tail record). The per-task `dcci(head)` poll was
+separately measured as effectively free, and deferring the record
+`wmb`/`dsb` already measured as sub-noise
+(`2026-06-l2-swimlane-defer-wmb.md`). The accuracy-over-performance rule
+for profiling paths applies.
+
+## When to reconsider
+
+- If a workload runs **> 1024 AICore tasks on a single core** the
+  ACK-gate's boundary path becomes live (qwen decode's ~15 tasks/core
+  never crosses it, so the ST smoke and this run exercise only the
+  common path). Re-measure buffer-tail record loss there to confirm the
+  gate eliminates the `start_time == 0` discards.
+- If the record write-back moves off HBM (e.g. an on-chip swimlane
+  staging buffer), the 0.5 µs prev_tail would shrink and the switch
+  decomposition should be re-run.
+
+## References
+
+- [2026-06 — L2 swimlane: defer per-task wmb to rotation](2026-06-l2-swimlane-defer-wmb.md)
+- `.claude/rules/codestyle.md` (no logging on AICPU hot paths),
+  `docs/hardware/mmio-performance.md` (dcci/dsb costs).

docs/investigations/README.md

@@ -84,6 +84,7 @@ that ...".
 
 Newest first.
 
+- [2026-07 — L2 swimlane AICore: switch-overhead source + FIN-early reorder & ACK-gate](2026-07-aicore-swimlane-switch-overhead-and-ack-gate.md) — measured: the ~0.8 µs inter-task switch is the record write-back `dcci(record,OUT)+dsb` (~0.5 µs) + payload setup (~0.28 µs), inherent and not reducible by moving FIN; the WAIT gap (p99 ~700 µs) dominates decode. Shipped: sample `end_time` after an early FIN, and an AICPU ACK-gate on buffer rotation (release the old buffer only when AICore ACKs the new buffer's first task) to close the FIN-before-record boundary race the reorder introduced
 - [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)

src/a2a3/platform/include/aicore/l2_swimlane_collector_aicore.h

@@ -66,12 +66,15 @@ struct L2SwimlaneAicoreLocalState {
  *
  * Race avoidance: AICPU rotates strictly before `write_reg(DATA_MAIN_BASE)`
  * for the first task of a new BUFFER_SIZE batch — driven by AICPU's own
- * per-core dispatch count (no AICore-side signal). The runtime's
- * completion-before-dispatch invariant (AICore per core is single-threaded
- * and AICPU does not dispatch task K+1 until K FIN'd) guarantees all prior
- * tasks have FIN'd at rotation time, so AICore has already finished writing
- * their records and dcci'd them out before AICPU enqueues the old buffer to
- * the ready queue.
+ * per-core dispatch count (no AICore-side signal). At rotation AICPU only
+ * publishes the new buffer; it does NOT hand the old buffer to the host there.
+ * The completion-before-dispatch invariant proves all prior tasks FIN'd, but
+ * this runtime writes FIN before the record below, so a FIN-gated release could
+ * publish a buffer whose tail record's `dcci(record, CACHELINE_OUT) + dsb` has
+ * not landed. AICPU instead releases the old buffer once it observes AICore ACK
+ * the new buffer's first task (l2_swimlane_aicpu_on_aicore_ack): by this core's
+ * single-threaded program order that ACK is emitted only after the previous
+ * task's record dcci+dsb, so the old buffer's last record is guaranteed drained.
  *
  * @param head            Per-core L2SwimlaneActiveHead channel. The executor
  *                        resolves it right after Phase 1 handshake exit

src/a2a3/platform/include/aicpu/l2_swimlane_collector_aicpu.h

@@ -85,24 +85,47 @@ void l2_swimlane_aicpu_init(int worker_count);
  *
  *   1. Maintain the per-core AICPU-side dispatch count.
  *   2. Rotate the AICore buffer when the count is about to cross a
- *      PLATFORM_AICORE_BUFFER_SIZE boundary — enqueue the just-filled buffer
- *      to the ready queue and pop the next one from free_queue.
+ *      PLATFORM_AICORE_BUFFER_SIZE boundary — publish the next buffer from
+ *      free_queue to AICore and STASH the just-filled buffer for deferred,
+ *      ACK-gated release (see l2_swimlane_aicpu_on_aicore_ack).
  *   3. Bump the AICore pool's `total_record_count` so host reconcile
  *      (total == collected + dropped) stays accurate at all levels —
  *      including AICORE_TIMING (level=1), where `complete_task` is bypassed.
  *
- * Race safety: rotation runs BEFORE the dispatch register write. The runtime's
- * completion-before-dispatch invariant (AICore per core is single-threaded
- * and AICPU does not dispatch task K+1 until K FIN'd) guarantees AICore has
- * FIN'd — and dcci'd out — every record in the old buffer by then. No
- * AICore-side signal is needed; AICPU has full dispatch visibility itself.
+ * Race safety: rotation runs BEFORE the dispatch register write. The
+ * completion-before-dispatch invariant proves prior tasks FIN'd, but
+ * tensormap_and_ringbuffer writes FIN before the swimlane record, so the old
+ * buffer's tail record may not have drained at rotation time. The old buffer is
+ * therefore not enqueued here; it is released once AICore ACKs the boundary
+ * dispatch (whose token is `reg_task_id`). host_build_graph writes the record
+ * before FIN so it has no such window and need not wire the ACK hook.
  *
  * No-op if l2_swimlane is disabled or `core_id` is out of range.
  *
- * @param core_id     Core index this dispatch targets
- * @param thread_idx  Owning AICPU thread (target ready-queue for rotation)
+ * @param core_id      Core index this dispatch targets
+ * @param thread_idx   Owning AICPU thread (target ready-queue for rotation)
+ * @param reg_task_id  Per-core dispatch token of this dispatch; when it is the
+ *                     boundary dispatch it becomes the ACK gate for releasing
+ *                     the just-filled buffer
  */
-void l2_swimlane_aicpu_on_aicore_dispatch(int core_id, int thread_idx);
+void l2_swimlane_aicpu_on_aicore_dispatch(int core_id, int thread_idx, uint32_t reg_task_id);
+
+/**
+ * Post-completion hook: release an ACK-gated AICore buffer.
+ *
+ * Called from the completion path on every matched AICore COND event (ACK or
+ * FIN). When a rotation has stashed the previous buffer with a gate equal to
+ * `reg_task_id`, that event proves AICore reached at least the new buffer's
+ * first-task ACK — hence passed the old buffer's last record dcci+dsb — so the
+ * stashed buffer is enqueued to the ready queue. No-op when nothing is stashed
+ * or the token does not match the gate. Only tensormap_and_ringbuffer wires
+ * this; host_build_graph relies on the next-rotation / run-end backstop.
+ *
+ * @param core_id      Core index the COND event was observed on
+ * @param thread_idx   Owning AICPU thread (target ready-queue)
+ * @param reg_task_id  Task token extracted from the observed COND value
+ */
+void l2_swimlane_aicpu_on_aicore_ack(int core_id, int thread_idx, uint32_t reg_task_id);
 
 /**
  * Commit an AICPU-side timing record for one completed task.

src/a2a3/runtime/host_build_graph/aicpu/aicpu_executor.cpp

@@ -281,11 +281,14 @@ inline bool AicpuExecutor::try_dispatch_task(
     pending_task_ids_[core_id] = task_id;
 
     // AICore buffer rotation: count this dispatch and rotate before write_reg
-    // when crossing a BUFFER_SIZE boundary. The completion-before-dispatch
-    // invariant makes this race-free (all prior tasks on this core have FIN'd,
-    // so AICore has dcci'd their records out of the old buffer).
+    // when crossing a BUFFER_SIZE boundary. This runtime writes the swimlane
+    // record before FIN, so the completion-before-dispatch invariant already
+    // guarantees the old buffer's records are drained at rotation; the shared
+    // rotate still stashes the buffer for ACK-gated release, drained here by the
+    // next-rotation / run-end backstop (no ACK hook wired). `task_id` is passed
+    // as the (unused-for-hbg) gate token.
     if (l2_swimlane_enabled) {
-        l2_swimlane_aicpu_on_aicore_dispatch(core_id, thread_idx);
+        l2_swimlane_aicpu_on_aicore_dispatch(core_id, thread_idx, static_cast<uint32_t>(task_id));
     }
 
     // Publish task data before AICore can observe the dispatched task_id.

src/a2a3/runtime/tensormap_and_ringbuffer/aicore/aicore_executor.cpp

@@ -133,28 +133,20 @@ __aicore__ __attribute__((weak)) void aicore_execute(__gm__ Runtime *runtime, in
         }
 
         {
-            // receive_time marks the moment AICPU's full "task is ready to
-            // execute" signal landed on this core. Paired with start_time
-            // (captured after the per-task dcci + ack pair) it lets DFX split
-            // head_OH into the AICPU→AICore-ready propagation (dispatch_ts →
-            // receive_time, hardware + scheduling-bound) and the AICore-local
-            // critical-path prep (receive_time → start_time, software-tunable).
-            // Stored in the record as a 32-bit delta `start_time - receive_time`.
+            // receive_time = task pickup: DATA_MAIN_BASE returned a new task_id.
+            // Paired with start_time (captured after the per-task dcci + ack) it
+            // lets DFX split head_OH into the AICPU→AICore-ready propagation
+            // (dispatch_ts → receive_time) and the AICore-local prep
+            // (receive_time → start_time). Stored as a 32-bit delta
+            // `start_time - receive_time`.
             //
-            // For the common path (not_ready == 0) the new task_id on
-            // DATA_MAIN_BASE is itself the ready signal, so receive_time is
-            // stamped immediately and local_setup covers dcci + ack.
-            //
-            // For the speculative early-dispatch path (not_ready == 1) the
-            // dcci ran BEFORE the dependency-wait spin, so its cost is hidden
-            // behind the doorbell-wait — not on the critical path between
-            // "task genuinely ready" and "kernel begins". receive_time is
-            // re-stamped after the doorbell arrives, so propagation absorbs
-            // both the original NoC delivery AND any speculation overshoot,
-            // while local_setup stays the pure ack-on-critical-path cost. This
-            // makes local_setup the clean "AICore prep we can't hide" figure
-            // for both paths.
-            uint64_t receive_time = get_sys_cnt_aicore();
+            // Common path (not_ready == 0): the new task_id is itself the ready
+            // signal, so receive_time is the true ready moment. Speculative path
+            // (not_ready == 1): receive_time stays at pickup — before the
+            // doorbell wait — so it precedes the producer's end_time; the host
+            // folds it to start_time for those tasks (detected when receive
+            // precedes the producer task's end_time).
+            uint64_t receive_time = l2_swimlane_enabled ? get_sys_cnt_aicore() : 0;
 
             uint32_t task_id = reg_val;  // Decode: register holds task_id directly
 
@@ -195,27 +187,24 @@ __aicore__ __attribute__((weak)) void aicore_execute(__gm__ Runtime *runtime, in
                     write_reg(RegId::COND, AICORE_EXITED_VALUE);
                     break;
                 }
-                // Re-stamp receive_time at the moment the doorbell landed: the
-                // dcci above ran during the speculative-staging window
-                // (overlapped with the dependency wait, off the critical path).
-                // Propagation now absorbs the speculation overshoot; local_setup
-                // = start - receive stays the pure ack-on-critical-path cost.
-                receive_time = get_sys_cnt_aicore();
             }
 
             write_reg(RegId::COND, MAKE_ACK_VALUE(task_id));
 
-            // Performance profiling: record start time
-            uint64_t start_time = get_sys_cnt_aicore();
-
-            // PMU: start counting window around kernel execution
+            // PMU window brackets kernel execution.
             if (pmu_enabled) {
                 pmu_aicore_begin();
             }
 
-            // Execute the task
+            uint64_t start_time = l2_swimlane_enabled ? get_sys_cnt_aicore() : 0;
+
             execute_task(exec_payload);
 
+            last_reg_val = reg_val;
+            write_reg(RegId::COND, MAKE_FIN_VALUE(task_id));
+
+            uint64_t end_time = l2_swimlane_enabled ? get_sys_cnt_aicore() : 0;
+
             if (pmu_enabled) {
                 pmu_aicore_end();
             }
@@ -224,7 +213,6 @@ __aicore__ __attribute__((weak)) void aicore_execute(__gm__ Runtime *runtime, in
                 pipe_barrier(PIPE_ALL);
             }
 
-            // Performance profiling: record task execution.
             // Two identity fields go into the record (different roles):
             //   - task_token_raw (PTO2 ring/local) is pulled from the dispatch
             //     payload's LocalContext.async_ctx — already in AICore cache
@@ -238,16 +226,7 @@ __aicore__ __attribute__((weak)) void aicore_execute(__gm__ Runtime *runtime, in
             //     under SPMD (block_num > num_cores) and MIX cluster spread,
             //     where multiple dispatches of the same task share the same
             //     task_token_raw.
-            last_reg_val = reg_val;
-            write_reg(RegId::COND, MAKE_FIN_VALUE(task_id));
-
-            // Sample end_time AFTER the FIN write so the op-event end marks the
-            // moment the AICPU can first observe completion — any compute-end ->
-            // FIN gap (epilogue / write-back) shows directly on the bar instead
-            // of being inferred. The record write itself stays off the critical
-            // path (it runs after FIN, so it no longer delays completion).
             if (l2_swimlane_enabled) {
-                uint64_t end_time = get_sys_cnt_aicore();
                 uint64_t task_token_raw = exec_payload->local_context.async_ctx.task_token.raw;
                 l2_swimlane_aicore_record_task(
                     l2_swimlane_head, &l2_swimlane_local, task_token_raw, task_id, receive_time, start_time, end_time