From 9a6fff4ea4a65f8be209af156f83713465fd86f6 Mon Sep 17 00:00:00 2001 From: zhusy54 Date: Thu, 3 Sep 2026 17:18:32 +0800 Subject: [PATCH 1/2] Support: unify chip-swimlane scheduler schema Move A2/A3 and A5 scheduler record ABIs into their architecture trees. Share host-only JSON serialization while preserving schema version 1. Restrict runtime extensions to fixed artifact slots and select their publishers when each host runtime is linked. Keep the converter compatible with legacy scheduler artifacts. --- docs/dfx/chip-swimlane-profiling.md | 75 +-- simpler_setup/runtime_builder.py | 5 + simpler_setup/tools/README.md | 27 +- simpler_setup/tools/deps_viewer.py | 4 +- .../tools/sched_overhead_analysis.py | 125 +++-- simpler_setup/tools/swimlane_converter.py | 450 ++++++++++++++---- .../include/common/scheduler_profiling.h | 65 +++ src/a2a3/platform/onboard/host/CMakeLists.txt | 8 +- src/a2a3/platform/sim/host/CMakeLists.txt | 8 +- .../include/common/scheduler_profiling.h | 65 +++ src/a5/platform/onboard/host/CMakeLists.txt | 8 +- .../platform/onboard/host/device_runner.cpp | 14 + src/a5/platform/sim/host/CMakeLists.txt | 8 +- src/a5/platform/sim/host/device_runner.cpp | 11 + .../aicore/aicore_legacy_executor.cpp | 2 +- .../include/common/chip_swimlane_extension.h | 61 +++ .../include/common/chip_swimlane_profiling.h | 102 +--- src/common/platform/include/common/host_api.h | 17 + .../include/host/chip_swimlane_collector.h | 5 + .../include/host/scheduler_profiling_json.h | 114 +++++ .../platform/onboard/host/c_api_shared.cpp | 8 + .../onboard/host/device_runner_base.h | 5 + .../shared/host/chip_swimlane_collector.cpp | 198 ++++---- src/common/platform/sim/host/c_api_shared.cpp | 8 + .../platform/sim/host/device_runner_base.h | 5 + .../dfx/chip_swimlane/_swimlane_validate.py | 14 +- .../dfx/chip_swimlane/_swimlane_validate.py | 14 +- tests/ut/cpp/common/test_host_api.cpp | 31 ++ tests/ut/py/test_runtime_builder.py | 11 +- tests/ut/py/test_sched_overhead_analysis.py | 77 +++ tests/ut/py/test_swimlane_converter.py | 289 ++++++++++- 31 files changed, 1446 insertions(+), 388 deletions(-) create mode 100644 src/a2a3/platform/include/common/scheduler_profiling.h create mode 100644 src/a5/platform/include/common/scheduler_profiling.h create mode 100644 src/common/platform/include/common/chip_swimlane_extension.h create mode 100644 src/common/platform/include/host/scheduler_profiling_json.h diff --git a/docs/dfx/chip-swimlane-profiling.md b/docs/dfx/chip-swimlane-profiling.md index 414fa6bf98..f4c3eb466c 100644 --- a/docs/dfx/chip-swimlane-profiling.md +++ b/docs/dfx/chip-swimlane-profiling.md @@ -28,8 +28,8 @@ end-to-end runtime numbers. Two cases dominate the profiler diet: pinpoints the fix. chip swimlane profiling captures both: per-task `(start, end, -dispatch, finish)` records on the AICore side, plus per-iteration -phase records on the AICPU scheduler side and per-submit orchestrator +dispatch, finish)` records, plus per-iteration phase records from the active +AICPU or AICore scheduler producer and per-submit orchestrator envelopes. The host writes a Chrome Trace Event JSON that loads directly in Perfetto, and the same file feeds a scheduler-overhead deep-dive report when a device log is @@ -45,7 +45,7 @@ available. `chip_swimlane_records.json` with `deps.json` from [`dep_gen`](dep-gen.md) at post-process time; see [§3.5](#35-dependency-arrows-from-dep_gen). -- **AICPU scheduler phases** — per-iteration breakdown into mutually +- **Scheduler phases** — producer-specific per-iteration breakdown. AICPU uses mutually time-exclusive **outer** phases (`complete` / `async_poll` / `dispatch` / `release` / `dummy` / `early_dispatch` / `drain` / `graph_prepare`), plus nested phases. @@ -106,9 +106,9 @@ backward-compatible with the old boolean behavior). | Level | Collects | Notes | | ----- | -------- | ----- | | 0 | Nothing (disabled) | Default when flag is absent | -| 1 | AICore timing only (start_time_us/end_time_us/task_id/func_id/core_type) | No AICPU timestamps | -| 2 | + dispatch_time_us, finish_time_us | Full per-task AICPU record | -| 3 | + scheduler phases (`aicpu_scheduler_phases[]`) | Skips orchestrator phases | +| 1 | AICore timing only (start_time_us/end_time_us/task_id/func_id/core_type) | No Scheduler timestamps | +| 2 | + Scheduler per-task dispatch_time_us, finish_time_us | Producer is identified as `aicpu` or `aicore` | +| 3 | + scheduler phases (`scheduler_records`) | Skips orchestrator phases | | 4 | + orchestrator phases (`aicpu_orchestrator_phases[]`) | Full collection | Dependency arrows are not produced by any swimlane level — see @@ -135,13 +135,13 @@ The flag sets `CallConfig::enable_chip_swimlane` to the chosen level. The host then allocates the per-core / per-thread shared region and publishes its base address through `kernel_args.chip_swimlane_data_base`. AICore writes timing into -per-task WIP slots; AICPU commits the records on FIN. Per-task -dispatch/finish timestamps are recorded only at level >= 2, +per-task WIP slots; the active Scheduler records dispatch/finish timestamps. +Per-task Scheduler timestamps are recorded only at level >= 2, scheduler phase records only at level >= 3, and orchestrator phase records only at level >= 4. The JSON output `"chip_swimlane_level"` field is the captured perf_level: -`1` = AICore timing only, `2` = +AICPU dispatch/finish, +`1` = AICore timing only, `2` = +Scheduler per-task dispatch/finish, `3` = +scheduler phases, `4` = +orchestrator phases. Chip-swimlane collection is disabled when `--rounds > 1` so benchmark @@ -231,31 +231,51 @@ layers to be aware of:** "core_to_thread": [, ...] // optional; level >= 3 only }, - // Bulk task streams — flat array of tuples. Column order is fixed. + // Bulk task streams. Tuple column order is fixed. // aicore_tasks: [core_id, task_token_raw, reg_task_id, // start_cycles, end_cycles] - // aicpu_tasks: [core_id, reg_task_id, - // dispatch_cycles, finish_cycles] + // scheduler_tasks.records: [core_id, reg_task_id, + // dispatch_cycles, finish_cycles] "aicore_tasks": [[...], ...], - "aicpu_tasks": [[...], ...], + "scheduler_tasks": { + "schema_version": 1, + "producer": "", + "records": [[...], ...] + }, + + // Producer-neutral per-Scheduler streams (level >= 3 only). + "scheduler_records": { + "schema_version": 1, + "streams": [{ + "platform": "", + "runtime": "", + "producer": "", + "scheduler_id": , + "worker_id": , + "core_type": "", + "physical_core_id": "", + "capture": {"committed": , "dropped": , "truncated": }, + "records": [{"start_cycles": , "end_cycles": , + "loop_iter": , "kind": , + "tasks_processed": , "task_id": ""}], + "metrics": [{"record_index": , ...}] + }] + }, - // Per-scheduler-thread arrays of objects (level >= 3 only). - // sched record: {kind, start_cycles, end_cycles, loop_iter, - // tasks_processed, [pop_hit, pop_miss]} + // Orchestrator records (level >= 4 only). // orch record: {submit_idx, task_id, start_cycles, end_cycles} - // pop_hit / pop_miss are present only on Dispatch records. - "aicpu_scheduler_phases": [ [ {...}, ... ], ... ], "aicpu_orchestrator_phases": [ [ {...}, ... ], ... ] // level >= 4 only } ``` All timestamps on disk are raw `get_sys_cnt` cycles (uint64). The -join key between `aicore_tasks` and `aicpu_tasks` is +join key between `aicore_tasks` and `scheduler_tasks.records` is `(core_id, reg_task_id)` — *not* `task_token_raw`, because SPMD `block_num > num_cores` and MIX cluster spread can dispatch the same `task_token_raw` to the same core multiple times. AICore is the -canonical producer of `task_token_raw`; AICPU only stamps the -dispatch / finish timestamps and the per-core join token. +canonical producer of `task_token_raw`; the Scheduler producer stamps the +dispatch / finish timestamps and the per-core join token. Archived raw files +with the former `aicpu_tasks` array remain readable as `producer: "aicpu"`. #### Reader output (µs domain) @@ -268,15 +288,16 @@ microseconds, downstream code sees: | `func_id` | Kernel function id. Always `-1` on disk; resolved post-process from `deps.json::tasks[].kernel_ids[3]` (see `swimlane_converter.resolve_func_id_from_kernel_map`) | | `core_id` / `core_type` | Physical core index and `"aic"` / `"aiv"` string | | `start_time_us` / `end_time_us` / `duration_us` | AICore execution window in microseconds | -| `dispatch_time_us` | AICPU timestamp when this task was dispatched (filled at level >= 2; `0.0` at level 1) | -| `finish_time_us` | AICPU timestamp when AICPU observed FIN (filled at level >= 2; `0.0` at level 1) | +| `dispatch_time_us` | Scheduler timestamp when dispatch publication completed (filled at level >= 2) | +| `finish_time_us` | Scheduler timestamp when completion processing began (filled at level >= 2) | Note: per-task records carry **no** fanout edges. Dependency arrows come from a separate `deps.json` (dep_gen) joined at convert time — see [§3.5](#35-dependency-arrows-from-dep_gen). -Phase records (per scheduler thread, level >= 3 for -`aicpu_scheduler_phases[]` and level >= 4 for +Phase records (per Scheduler stream, level >= 3 in raw +`scheduler_records`—also exposed through the legacy reader alias +`aicpu_scheduler_phases`—and level >= 4 for `aicpu_orchestrator_phases[]`): | Field | Meaning | @@ -446,13 +467,13 @@ same lane structure — the directory form repeats it once per Rank under the - **Orchestrator** (pid=1) — per-submit `orch_submit` envelope blocks (level >= 4). -- **AICPU Scheduler** (pid=2) — per-iteration scheduler phase +- **Scheduler** (pid=2) — per-iteration scheduler phase blocks coloured by `phase` (level >= 3). Outer phases appear as sibling bars on each scheduler thread's first `Sched_N` lane. TMR's nested `resolve` appears on an adjacent `Sched_N` sub-lane; HBG's standalone `resolve` stays on the P thread's first lane. `drain_prepare` and `drain_publish` nest within `drain`. -- **Scheduler View** (pid=3) — task-execution overlay using AICPU +- **Scheduler View** (pid=3) — task-execution overlay using Scheduler dispatch/finish timestamps (level >= 2), with the same labels as Worker View. - **Worker View** (pid=4) — one swim-lane per physical worker: diff --git a/simpler_setup/runtime_builder.py b/simpler_setup/runtime_builder.py index 9602a17cb4..1affcbe6ed 100644 --- a/simpler_setup/runtime_builder.py +++ b/simpler_setup/runtime_builder.py @@ -389,6 +389,11 @@ def _compile_target(target: str) -> Path: pto_root = ensure_pto_isa_root(verbose=True) defines["PTO_ISA_ROOT"] = pto_root if target == "host": + # host_runtime.so is built once per runtime implementation, so + # bake that immutable artifact identity into the shared host + # platform code. Runtime code must not grow a virtual/static + # API merely to report the directory it was compiled from. + defines["SIMPLER_RUNTIME_NAME"] = name if build_pto_isa_commit: defines["SIMPLER_PTO_ISA_BUILD_COMMIT"] = build_pto_isa_commit for opt_in_define in ("SIMPLER_ENABLE_PTO_URMA_WORKSPACE",): diff --git a/simpler_setup/tools/README.md b/simpler_setup/tools/README.md index 07f0fc7f4e..d66d8c858e 100644 --- a/simpler_setup/tools/README.md +++ b/simpler_setup/tools/README.md @@ -295,7 +295,8 @@ After the test passes, the tool will: ## sched_overhead_analysis -Answer **"is the AICPU scheduler the bottleneck, or is it starved?"** by +Answer **"is the scheduler the bottleneck, or is it starved?"** for either an +AICPU or AICore scheduler by measuring, dependency- and MIX-aware, how much of the makespan a free core has ready, undispatched work — vs. legitimately busy or dependency-limited. Full model: [docs/dfx/sched-overhead-model.md](../../docs/dfx/sched-overhead-model.md). @@ -305,9 +306,10 @@ model: [docs/dfx/sched-overhead-model.md](../../docs/dfx/sched-overhead-model.md `sched_overhead_analysis` needs **two artifacts, captured in SEPARATE runs** (co-running the flags perturbs timing — `dep_gen` adds per-submit overhead): -1. **Perf profiling data** (`chip_swimlane_records_*.json`, level >= 3) from a - `--enable-chip-swimlane` run — per-task dispatch/start/end/finish + - `aicpu_scheduler_phases`. +1. **Perf profiling data** (`chip_swimlane_records_*.json`, level >= 2) from a + `--enable-chip-swimlane` run — per-task dispatch/start/end/finish. Level >= 3 + also supplies `scheduler_records` for the phase breakdown (legacy artifacts + with `aicpu_scheduler_phases` remain readable). 2. **`deps.json`** (the task DAG) from a separate `--enable-dep-gen` run. It drives `ready(C) = max(producer.end)`, which is what separates scheduler bubbles from dependency stalls. **Required** — the tool errors without it. @@ -333,7 +335,7 @@ python -m simpler_setup.tools.sched_overhead_analysis \ | Option | Description | | ------ | ----------- | -| `--chip-swimlane-records-json` | Path to the chip_swimlane_records_*.json file (level >= 3). If omitted, the latest under outputs/ is auto-selected. | +| `--chip-swimlane-records-json` | Path to the chip_swimlane_records_*.json file (level >= 2). If omitted, the latest under outputs/ is auto-selected. | | `--deps-json` | Path to deps.json from a `--enable-dep-gen` run. **Required.** Falls back to a `deps.json` sibling of the perf JSON if present. | ### Outputs @@ -343,10 +345,11 @@ Emitted in six parts: - **Part 1: Overhead verdict** — per-engine overhead (idle T-core *and* a ready, undispatched T-task, MIX-aware) + system `all_overhead` / `has_overhead`, all as % of makespan. An engine with no ready work is not overhead (dependency-mandated idle, not waste). - **Part 2: aicore switch** — the pre-dispatched pickup gap (`dispatch < prev_end`), reported **per core** (min/mean/max, ~0.8 µs each), the overhead-vs-independent split, and the makespan switch bound `[min over cores, sum of per-engine minima]`. - **Part 3 / 4: Head / Tail OH distributions** — P10–P99 + mean + total (per-task pickup and detect-latency magnitude). -- **Part 5: AICPU scheduler loop breakdown** — per-thread loops, ns/loop, complete/dispatch/idle phase ratios, pop_hit / pop_miss, fanout / fanin, + the tail-vs-loop cause analysis. +- **Part 5: Scheduler phase breakdown** — Level >= 3 reports the producer's phases. AICPU includes per-thread loop, queue-pop, fanout/fanin, and tail-vs-loop metrics; AICore reports its bootstrap/fanin/ready/dispatch/complete/refill/resolve/idle phase totals without applying AICPU-only queue formulas. At Level 2 this section is explicitly marked unavailable while Parts 1–4 and 6 remain available. - **Part 6: Critical-path latency attribution** — along the makespan path, scheduler-injected µs vs compute µs ("scheduler adds X% to the critical path"). -The perf JSON must be captured at chip_swimlane_level >= 3 so that `aicpu_scheduler_phases` is non-empty (rerun the case with `--enable-chip-swimlane` if the tool reports the field is missing). +The common dependency-aware analysis works at chip_swimlane_level >= 2 for +both scheduler producers. Capture level >= 3 when phase attribution is needed. --- @@ -717,9 +720,13 @@ not from the perf JSON. See [`swimlane_converter --deps-json`](#swimlane_convert Top-level layout depends on `chip_swimlane_level`: - All levels: `chip_swimlane_level`, `tasks[]` (per-task fields above). -- `>= 3`: also `aicpu_scheduler_phases[]` (per-thread phase records: - scan / complete / dispatch / idle) and `core_to_thread[]` (core_id → - scheduler thread index). +- A5 HBG `>= 2`: also `aicpu_lifecycle_records[]`; the converter renders the + real handshake, topology/configuration, context-publication, bootstrap-wait, + register-release, and exit timestamps under `AICPU Lifecycle`. +- `>= 3`: also `scheduler_records.streams[]`. Every Record has the common + `start_cycles`, `end_cycles`, `loop_iter`, `kind`, `tasks_processed`, and + nullable `task_id` fields. Stream metadata selects the AICPU or AICore + interpretation; producer-specific counters live in `metrics[]`. - `>= 4`: also `aicpu_orchestrator_phases[]` (per-task orchestrator phase records). diff --git a/simpler_setup/tools/deps_viewer.py b/simpler_setup/tools/deps_viewer.py index 1f917fdca8..f11fd830d6 100644 --- a/simpler_setup/tools/deps_viewer.py +++ b/simpler_setup/tools/deps_viewer.py @@ -709,8 +709,8 @@ def _load_task_meta(deps_path, func_names=None): if not perf_path.exists(): return {} try: - # Route through swimlane_converter.read_perf_data so v2 raw on-disk - # JSON (aicore_tasks/aicpu_tasks flat tuples in cycle domain) gets + # Route through swimlane_converter.read_perf_data so raw on-disk + # JSON (AICore and Scheduler tuples in the cycle domain) gets # joined into the v1-shape dict this function expects. Direct # json.load would see no top-level `tasks` array on v2 and silently # return {} — leaving every node uncolored / unlabeled. diff --git a/simpler_setup/tools/sched_overhead_analysis.py b/simpler_setup/tools/sched_overhead_analysis.py index 62dbb94a13..d067c3abc7 100644 --- a/simpler_setup/tools/sched_overhead_analysis.py +++ b/simpler_setup/tools/sched_overhead_analysis.py @@ -11,8 +11,9 @@ Inputs (BOTH required, captured in SEPARATE runs — do not co-run the flags, as dep_gen perturbs the swimlane timing): - 1. Per-task perf profiling data (chip_swimlane_records_*.json) with - ``aicpu_scheduler_phases``, from a ``--enable-chip-swimlane`` (level >= 3) run. + 1. Per-task perf profiling data (chip_swimlane_records_*.json) from a + ``--enable-chip-swimlane`` level >= 2 run. Level >= 3 additionally supplies + ``scheduler_records`` for the producer-specific phase breakdown. 2. deps.json (the task DAG) from a separate ``--enable-dep-gen`` run. It drives ready(C) = max(producer.end), which separates scheduler bubbles from dependency stalls. Required — the report errors without it. @@ -20,7 +21,7 @@ Report (see docs/dfx/sched-overhead-model.md for the model): Part 1 Overhead verdict (per-engine + system all/has overhead, % of makespan) | Part 2 aicore switch (per-core pickup totals + makespan bound) | - Part 3/4 Head/Tail OH distributions | Part 5 scheduler loop budget | + Part 3/4 Head/Tail OH distributions | Part 5 scheduler phase budget | Part 6 critical-path attribution. Usage: @@ -181,7 +182,7 @@ def parse_scheduler_from_json_phases(data): # noqa: PLR0912 """Extract scheduler Phase breakdown from chip_swimlane_records JSON. Computes per-thread loop counts, logical task counts, FIN/retire counts, - and phase totals from aicpu_scheduler_phases records (present at + and phase totals from scheduler_records records (present at chip_swimlane_level >= 3). Complete.tasks_processed is a FIN/retire count; logical task counts are reconstructed from the final finish row per task. @@ -191,7 +192,7 @@ def parse_scheduler_from_json_phases(data): # noqa: PLR0912 and finishes_per_loop. Returns empty dict if phase data is not available. """ - phases_by_thread = data.get("aicpu_scheduler_phases", []) + phases_by_thread = data.get("scheduler_records") or data.get("aicpu_scheduler_phases", []) if not phases_by_thread: return {} @@ -322,6 +323,60 @@ def parse_scheduler_from_json_phases(data): # noqa: PLR0912 return threads +def print_aicore_scheduler_phase_breakdown(data): + """Print AICore Scheduler phase totals without AICPU queue assumptions.""" + scheduler_records = data.get("scheduler_records") or [] + scheduler_streams = data.get("scheduler_streams") or [] + totals = defaultdict(float) + counts = defaultdict(int) + dropped = 0 + for stream_index, records in enumerate(scheduler_records): + for record in records: + kind = canonical_sched_phase(record.get("phase", "unknown")) + totals[kind] += max(0.0, record.get("end_time_us", 0.0) - record.get("start_time_us", 0.0)) + counts[kind] += 1 + if stream_index < len(scheduler_streams): + capture = scheduler_streams[stream_index].get("capture") or {} + dropped += int(capture.get("dropped") or 0) + + print("=" * 90) + print("Part 5: AICore scheduler phase breakdown") + print("=" * 90) + if not scheduler_records: + print(" (phase records unavailable at chip-swimlane Level 2; capture Level >= 3 for this section)") + print("=" * 90) + return + + print(f" Scheduler streams: {len(scheduler_records)}") + print(" Phase time is summed over AICore scheduler streams and can exceed wall-clock time.") + print() + for kind in sorted(totals): + print(f" {kind:<16} records={counts[kind]:>6} total={totals[kind]:>10.3f} us") + print(f" dropped={dropped}") + print(" Queue-pop and AICPU polling-loop metrics are producer-specific and are omitted.") + print("=" * 90) + + +def print_critical_path(preds_by_id, end_by_id, finish_by_id, start_by_id, dispatch_by_id, w0): + """Print dependency-aware critical-path latency attribution.""" + cp = compute_critical_path(preds_by_id, end_by_id, finish_by_id, start_by_id, dispatch_by_id, w0) + print() + print("=" * 90) + print("Part 6: Critical-path latency attribution") + print("=" * 90) + if cp and cp["span"] > 0: + sched_pct = cp["sched"] / cp["span"] * 100 + exec_pct = cp["exec"] / cp["span"] * 100 + print(f" Makespan-determining path: {cp['hops']} hops, span {cp['span']:.1f} us") + print(f" Compute (exec) on path : {cp['exec']:.1f} us ({exec_pct:.1f}%)") + print(f" Scheduler injected : {cp['sched']:.1f} us ({sched_pct:.1f}%)") + print(f" Other (dep wait on path): {max(0.0, cp['span'] - cp['exec'] - cp['sched']):.1f} us") + print(f" -> scheduler adds ~{sched_pct:.1f}% to the critical path's end-to-end latency.") + else: + print(" (could not resolve a critical path from the DAG)") + print("=" * 90) + + def _summarize_scheduler_loops(threads): """Aggregate loop budgets without mixing scheduler and resolution loops.""" summary = {} @@ -686,8 +741,12 @@ def compute_critical_path(preds_by_id, end_by_id, finish_by_id, start_by_id, dis exec_total += max(0.0, end_by_id.get(cur, 0.0) - start_by_id.get(cur, 0.0)) if not preds: # root: dispatch->start head - sched_total += max(0.0, start_by_id.get(cur, w0) - dispatch_by_id.get(cur, w0)) - path_start = min(path_start, start_by_id.get(cur, w0)) + root_dispatch = dispatch_by_id.get(cur, start_by_id.get(cur, w0)) + sched_total += max(0.0, start_by_id.get(cur, w0) - root_dispatch) + # The root's dispatch->start delay is part of scheduler latency, + # so the path span must begin at dispatch as well. Starting at the + # kernel start made scheduler+compute exceed 100% of the span. + path_start = min(path_start, root_dispatch) break pend, p = max(preds) sched_total += max(0.0, start_by_id.get(cur, 0.0) - pend) # producer.end -> consumer.start @@ -743,11 +802,20 @@ def run_analysis( # noqa: PLR0912, PLR0915 else: # Lazy import to avoid an import cycle: swimlane_converter imports # run_analysis from this module at top level. read_perf_data does the - # AICore↔AICPU join — direct json.load would see only the raw - # aicore_tasks / aicpu_tasks arrays. + # AICore↔Scheduler join; direct json.load sees only the raw streams. from .swimlane_converter import read_perf_data # noqa: PLC0415 data = read_perf_data(chip_swimlane_records_path) + scheduler_producers = { + stream.get("producer") for stream in data.get("scheduler_streams", []) if stream.get("producer") + } + task_producer = data.get("scheduler_task_producer") + if task_producer: + scheduler_producers.add(task_producer) + if len(scheduler_producers) > 1: + print("Error: mixed AICPU/AICore scheduler producers are unsupported", file=sys.stderr) + return 1 + scheduler_producer = next(iter(scheduler_producers), "aicpu") tasks = data["tasks"] n_total = len(tasks) @@ -895,15 +963,23 @@ def _pct(x, denom): print_distribution("Tail OH", tails) print() - # === Part 5: AICPU scheduler loop breakdown (+ tail-vs-loop cause analysis) === + # === Part 5: producer-specific scheduler phase breakdown === + # Parts 1-4 and 6 are based on the common per-task dispatch/start/end/finish + # contract and therefore apply equally to AICPU and AICore schedulers. + if scheduler_producer == "aicore": + print_aicore_scheduler_phase_breakdown(data) + print_critical_path(preds_by_id, end_by_id, finish_by_id, start_by_id, dispatch_by_id, w0) + return 0 + threads = parse_scheduler_from_json_phases(data) if not threads: - print( - "Error: perf JSON has no aicpu_scheduler_phases — rerun the case " - "with --enable-chip-swimlane so phase data is captured.", - file=sys.stderr, - ) - return 1 + print("=" * 90) + print("Part 5: AICPU scheduler loop breakdown") + print("=" * 90) + print(" (phase records unavailable at chip-swimlane Level 2; capture Level >= 3 for this section)") + print("=" * 90) + print_critical_path(preds_by_id, end_by_id, finish_by_id, start_by_id, dispatch_by_id, w0) + return 0 # Per-thread fanout / fanin from the (already-loaded, required) deps.json. dag_stats_available = True @@ -1057,22 +1133,7 @@ def _pct(x, denom): print("=" * 90) # === Part 6: Critical-path latency attribution === - cp = compute_critical_path(preds_by_id, end_by_id, finish_by_id, start_by_id, dispatch_by_id, w0) - print() - print("=" * 90) - print("Part 6: Critical-path latency attribution") - print("=" * 90) - if cp and cp["span"] > 0: - sched_pct = cp["sched"] / cp["span"] * 100 - exec_pct = cp["exec"] / cp["span"] * 100 - print(f" Makespan-determining path: {cp['hops']} hops, span {cp['span']:.1f} us") - print(f" Compute (exec) on path : {cp['exec']:.1f} us ({exec_pct:.1f}%)") - print(f" Scheduler injected : {cp['sched']:.1f} us ({sched_pct:.1f}%)") - print(f" Other (dep wait on path): {max(0.0, cp['span'] - cp['exec'] - cp['sched']):.1f} us") - print(f" -> scheduler adds ~{sched_pct:.1f}% to the critical path's end-to-end latency.") - else: - print(" (could not resolve a critical path from the DAG)") - print("=" * 90) + print_critical_path(preds_by_id, end_by_id, finish_by_id, start_by_id, dispatch_by_id, w0) return 0 diff --git a/simpler_setup/tools/swimlane_converter.py b/simpler_setup/tools/swimlane_converter.py index 6ba0aad42b..59140cc915 100644 --- a/simpler_setup/tools/swimlane_converter.py +++ b/simpler_setup/tools/swimlane_converter.py @@ -236,7 +236,7 @@ def _decode_perf_data(data, *, timeline_origin_ns=None): # noqa: PLR0912, PLR09 """Decode performance data from an already-loaded swimlane document. Host dumps raw cycle-domain per-stream records plus metadata; this - function does the AICore↔AICPU join. Schema: + function joins AICore execution records with Scheduler task timing. Schema: { "chip_swimlane_level": <1..4>, @@ -248,8 +248,13 @@ def _decode_perf_data(data, *, timeline_origin_ns=None): # noqa: PLR0912, PLR09 }, "aicore_tasks": [[core_id, task_token_raw, reg_task_id, start_cycles, end_cycles, receive_to_start_cycles], ...], - "aicpu_tasks": [[core_id, reg_task_id, dispatch_cycles, finish_cycles], ...], - "aicpu_scheduler_phases": [ [ {kind, start_cycles, end_cycles, ...}, ... ], ... ], + "scheduler_tasks": { + "schema_version": 1, + "producer": "", + "records": [[core_id, reg_task_id, dispatch_cycles, finish_cycles], ...] + }, + "scheduler_records": {"schema_version": 1, "streams": [...]}, + "aicpu_lifecycle_records": [{worker_id, aicpu_thread_id, ..._cycles}, ...], "aicpu_orchestrator_phases": [ [ {submit_idx, task_id, start_cycles, end_cycles}, ... ], ... ], "host_orchestrator_phases": [ [ {submit_idx, task_id, start_host_ns, end_host_ns}, ... ], ... ] } @@ -270,7 +275,7 @@ def _decode_perf_data(data, *, timeline_origin_ns=None): # noqa: PLR0912, PLR09 Returns a dict shaped for `generate_chrome_trace_json`, `print_task_statistics`, and `sched_overhead_analysis`: `tasks`, - `aicpu_scheduler_phases`, `aicpu_orchestrator_phases`, + `scheduler_records` (plus the legacy internal alias), `aicpu_orchestrator_phases`, `core_to_thread`. The join logic that used to live in `export_swimlane_json` (host C++): @@ -281,10 +286,11 @@ def _decode_perf_data(data, *, timeline_origin_ns=None): # noqa: PLR0912, PLR09 phase, orch) - cycles → µs via `clock_freq_hz` from metadata (a2a3=50 MHz, a5=1 GHz — the freq MUST come from the host, never be hardcoded here) - - join `aicpu_tasks` by `(core_id, reg_task_id)`; unmatched rows are + - join `scheduler_tasks.records` by `(core_id, reg_task_id)`; unmatched rows are dropped and counted - - TASK_TIMING (level=1): aicpu_tasks is empty by construction, so - synthesize one task per aicore record (dispatch/finish = 0) + - archived JSON with `aicpu_tasks` is accepted as an AICPU-produced stream + - level 1 accepts AICore-only task records; higher levels require Scheduler + dispatch/finish timing for every emitted task - sort joined `tasks` by `task_id` (= task_token_raw) - convert phase records from `*_cycles` → `*_time_us` @@ -303,8 +309,114 @@ def _decode_perf_data(data, *, timeline_origin_ns=None): # noqa: PLR0912, PLR09 core_to_thread = list(metadata.get("core_to_thread") or []) aicore_rows = data.get("aicore_tasks") or [] - aicpu_rows = data.get("aicpu_tasks") or [] - sched_phases_raw = data.get("aicpu_scheduler_phases") or [] + scheduler_task_section = data.get("scheduler_tasks") + legacy_aicpu_rows = data.get("aicpu_tasks") + if scheduler_task_section is not None: + if legacy_aicpu_rows is not None: + raise ValueError("both scheduler_tasks and legacy aicpu_tasks are present") + if not isinstance(scheduler_task_section, dict): + raise ValueError("scheduler_tasks must be an object") + scheduler_task_schema_version = int(scheduler_task_section.get("schema_version") or 0) + if scheduler_task_schema_version != 1: + raise ValueError(f"Unsupported scheduler_tasks schema_version: {scheduler_task_schema_version}") + scheduler_task_producer = scheduler_task_section.get("producer") + if scheduler_task_producer not in ("aicpu", "aicore"): + raise ValueError("scheduler_tasks.producer must be 'aicpu' or 'aicore'") + scheduler_task_rows = scheduler_task_section.get("records") + if not isinstance(scheduler_task_rows, list) or any( + not isinstance(row, list) or len(row) != 4 for row in scheduler_task_rows + ): + raise ValueError("scheduler_tasks.records must contain four-column arrays") + else: + scheduler_task_rows = legacy_aicpu_rows or [] + scheduler_task_producer = "aicpu" if legacy_aicpu_rows is not None else None + lifecycle_raw = data.get("aicpu_lifecycle_records") or [] + if not isinstance(lifecycle_raw, list) or any(not isinstance(record, dict) for record in lifecycle_raw): + raise ValueError("aicpu_lifecycle_records must be an array of objects") + scheduler_stream_metadata = [] + scheduler_section = data.get("scheduler_records") + if scheduler_section is not None: + if not isinstance(scheduler_section, dict): + raise ValueError("scheduler_records must be an object") + scheduler_schema_version = int(scheduler_section.get("schema_version") or 0) + if scheduler_schema_version != 1: + raise ValueError(f"Unsupported scheduler_records schema_version: {scheduler_schema_version}") + scheduler_streams = scheduler_section.get("streams") + if not isinstance(scheduler_streams, list): + raise ValueError("scheduler_records.streams must be an array") + sched_phases_raw = [] + for stream_index, stream in enumerate(scheduler_streams): + if not isinstance(stream, dict): + raise ValueError(f"scheduler_records.streams[{stream_index}] must be an object") + records = stream.get("records") + metrics = stream.get("metrics") or [] + if not isinstance(records, list) or not isinstance(metrics, list): + raise ValueError(f"scheduler stream {stream_index} records/metrics must be arrays") + record_fields = { + "start_cycles", + "end_cycles", + "loop_iter", + "kind", + "tasks_processed", + "task_id", + } + merged_records = [] + for record_index, record in enumerate(records): + if not isinstance(record, dict) or set(record) != record_fields: + raise ValueError( + f"scheduler stream {stream_index} record {record_index} must contain exactly " + f"{sorted(record_fields)}" + ) + if int(record["end_cycles"]) < int(record["start_cycles"]): + raise ValueError(f"scheduler stream {stream_index} record {record_index} has a negative interval") + merged_records.append(dict(record)) + for metric in metrics: + if not isinstance(metric, dict) or "record_index" not in metric: + raise ValueError(f"scheduler stream {stream_index} has malformed metrics") + record_index = int(metric["record_index"]) + if record_index < 0 or record_index >= len(merged_records): + raise ValueError( + f"scheduler stream {stream_index} metric record_index {record_index} is out of range" + ) + metric_values = {key: value for key, value in metric.items() if key != "record_index"} + overwritten_fields = set(metric_values) & record_fields + if overwritten_fields: + raise ValueError( + f"scheduler stream {stream_index} metric overwrites fixed record fields: " + f"{sorted(overwritten_fields)}" + ) + merged_records[record_index].update(metric_values) + sched_phases_raw.append(merged_records) + scheduler_stream_metadata.append( + { + key: stream.get(key) + for key in ( + "platform", + "runtime", + "producer", + "scheduler_id", + "worker_id", + "core_type", + "physical_core_id", + "capture", + ) + } + ) + else: + sched_phases_raw = data.get("aicpu_scheduler_phases") or [] + scheduler_stream_metadata = [ + { + "platform": None, + "runtime": None, + "producer": "aicpu", + "scheduler_id": index, + "worker_id": index, + "core_type": "aicpu", + "physical_core_id": None, + "capture": None, + } + for index in range(len(sched_phases_raw)) + ] orch_phases_raw = data.get("aicpu_orchestrator_phases") or [] host_orch_phases_raw = data.get("host_orchestrator_phases") or [] raw_host_capture = metadata.get("host_capture") @@ -379,16 +491,33 @@ def _decode_perf_data(data, *, timeline_origin_ns=None): # noqa: PLR0912, PLR09 # (6 cols) both parse — archived JSON from before the receive_time split # still loads with r2s_cycles defaulting to 0. aicore_lookup: dict[tuple[int, int], tuple[int, int, int, int]] = {} - for row in aicore_rows: + for row_index, row in enumerate(aicore_rows): + if not isinstance(row, list) or len(row) not in (5, 6): + raise ValueError(f"aicore_tasks[{row_index}] must contain five or six columns") core_id, task_token_raw, reg_task_id, start_cycles, end_cycles, *rest = row + key = (int(core_id), int(reg_task_id)) + if key in aicore_lookup: + raise ValueError(f"duplicate aicore_tasks join key: {key}") r2s_cycles = int(rest[0]) if rest else 0 - aicore_lookup[(int(core_id), int(reg_task_id))] = ( + aicore_lookup[key] = ( int(task_token_raw), int(start_cycles), int(end_cycles), r2s_cycles, ) + scheduler_task_keys = [(int(row[0]), int(row[1])) for row in scheduler_task_rows] + if len(scheduler_task_keys) != len(set(scheduler_task_keys)): + raise ValueError("scheduler_tasks contains duplicate (core_id, reg_task_id) join keys") + if level >= 2: + missing_scheduler_keys = sorted(set(aicore_lookup) - set(scheduler_task_keys)) + if missing_scheduler_keys: + preview = ", ".join(str(key) for key in missing_scheduler_keys[:3]) + raise ValueError( + f"level {level} requires Scheduler task timing for every AICore task; " + f"missing {len(missing_scheduler_keys)} join key(s): {preview}" + ) + # base_time = min non-zero timestamp across every stream that will be # emitted. Used as the cycle-domain zero for all µs conversions. base_time_cycles = None @@ -409,7 +538,7 @@ def _track(v): r2s_c = int(row[5]) if len(row) > 5 else 0 _track(start_c - r2s_c) _track(end_c) - for _, _, d, f in aicpu_rows: + for _, _, d, f in scheduler_task_rows: _track(int(d)) _track(int(f)) for thread_records in sched_phases_raw: @@ -420,6 +549,21 @@ def _track(v): for pr in thread_records: _track(int(pr.get("start_cycles", 0))) _track(int(pr.get("end_cycles", 0))) + lifecycle_cycle_fields = ( + "handshake_observed_cycles", + "handshake_partition_complete_cycles", + "config_start_cycles", + "topology_complete_cycles", + "context_publish_complete_cycles", + "bootstrap_wait_start_cycles", + "bootstrap_complete_cycles", + "register_release_cycles", + "exit_signal_cycles", + "exit_ack_cycles", + ) + for record in lifecycle_raw: + for field in lifecycle_cycle_fields: + _track(int(record.get(field, 0))) if base_time_cycles is None: base_time_cycles = 0 @@ -429,12 +573,14 @@ def _track(v): start_cycles = int(row[3]) receive_to_start_cycles = int(row[5]) if len(row) > 5 else 0 device_timestamps.extend((start_cycles - receive_to_start_cycles, start_cycles, int(row[4]))) - for _, _, dispatch_cycles, finish_cycles in aicpu_rows: + for _, _, dispatch_cycles, finish_cycles in scheduler_task_rows: device_timestamps.extend((int(dispatch_cycles), int(finish_cycles))) for phase_threads in (sched_phases_raw, orch_phases_raw): for thread_records in phase_threads: for phase in thread_records: device_timestamps.extend((int(phase.get("start_cycles", 0)), int(phase.get("end_cycles", 0)))) + for record in lifecycle_raw: + device_timestamps.extend(int(record.get(field, 0)) for field in lifecycle_cycle_fields) clock_alignment = None if host_mode or clock_anchor_mode: @@ -478,8 +624,8 @@ def _core_type(core_id): tasks = [] unmatched_per_core: dict[int, int] = defaultdict(int) - if aicpu_rows: - for row in aicpu_rows: + if scheduler_task_rows: + for row in scheduler_task_rows: core_id, reg_task_id, dispatch_cycles, finish_cycles = row core_id = int(core_id) reg_task_id = int(reg_task_id) @@ -488,9 +634,17 @@ def _core_type(core_id): unmatched_per_core[core_id] += 1 continue task_token_raw, start_cycles, end_cycles, r2s_cycles = ac + dispatch_cycles = int(dispatch_cycles) + finish_cycles = int(finish_cycles) + if not (0 < dispatch_cycles <= start_cycles <= end_cycles <= finish_cycles): + raise ValueError( + "invalid Scheduler/AICore task timestamp order for " + f"(core_id, reg_task_id)=({core_id}, {reg_task_id}): expected " + "0 < dispatch <= start <= end <= finish" + ) start_us = _to_us(start_cycles) end_us = _to_us(end_cycles) - dispatch_us = _to_us(int(dispatch_cycles)) + dispatch_us = _to_us(dispatch_cycles) receive_us = _to_us(start_cycles - r2s_cycles) local_setup_us = start_us - receive_us tasks.append( @@ -504,15 +658,13 @@ def _core_type(core_id): "end_time_us": end_us, "duration_us": end_us - start_us, "dispatch_time_us": dispatch_us, - "finish_time_us": _to_us(int(finish_cycles)), + "finish_time_us": _to_us(finish_cycles), "receive_time_us": receive_us, "local_setup_us": local_setup_us, "propagation_us": receive_us - dispatch_us, } ) - elif level == 1: - # TASK_TIMING fallback: AICPU records are absent (complete_task - # bypassed). The AICore stream alone is the source of truth. + elif aicore_rows and level == 1: for row in aicore_rows: core_id, task_token_raw, _reg_task_id, start_cycles, end_cycles, *rest = row r2s_cycles = int(rest[0]) if rest else 0 @@ -532,13 +684,13 @@ def _core_type(core_id): "start_time_us": start_us, "end_time_us": end_us, "duration_us": end_us - start_us, - "dispatch_time_us": 0.0, - "finish_time_us": 0.0, "receive_time_us": receive_us, "local_setup_us": local_setup_us, - # propagation_us requires AICPU dispatch_ts; absent at level 1. + # propagation_us requires a Scheduler dispatch timestamp. } ) + elif aicore_rows: + raise ValueError(f"level {level} requires Scheduler task timing records") tasks.sort(key=lambda t: int(t["task_id"])) @@ -547,7 +699,8 @@ def _core_type(core_id): worst = sorted(unmatched_per_core.items(), key=lambda kv: -kv[1])[:3] worst_str = ", ".join(f"core {c}: {n}" for c, n in worst) print( - f"Warning: {total_unmatched} aicpu_task(s) had no matching AICore record (top offenders: {worst_str}); " + f"Warning: {total_unmatched} Scheduler task timing record(s) had no matching AICore record " + f"(producer={scheduler_task_producer}, top offenders: {worst_str}); " "the missing AICore buffer(s) were dropped on rotation. Bump PLATFORM_AICORE_BUFFERS_PER_CORE if you " "see this regularly.", file=sys.stderr, @@ -585,6 +738,15 @@ def _phase_us(pr): converted.append(out) aicpu_orchestrator_phases.append(converted) + aicpu_lifecycle_records = [] + for record_index, record in enumerate(lifecycle_raw): + converted = dict(record) + for field in lifecycle_cycle_fields: + cycles = int(converted.pop(field, 0)) + converted[field.removesuffix("_cycles") + "_time_us"] = _to_us(cycles) + converted["record_index"] = record_index + aicpu_lifecycle_records.append(converted) + host_device_uploads = [] for pr in data.get("host_device_uploads") or []: start_ns = int(pr.get("start_host_ns", 0)) @@ -622,11 +784,17 @@ def _phase_us(pr): "chip_swimlane_level": level, "tasks": tasks, } + if scheduler_task_producer is not None: + out["scheduler_task_producer"] = scheduler_task_producer if aicpu_scheduler_phases: out["aicpu_scheduler_phases"] = aicpu_scheduler_phases + out["scheduler_records"] = aicpu_scheduler_phases + out["scheduler_streams"] = scheduler_stream_metadata if aicpu_orchestrator_phases: out["aicpu_orchestrator_phases"] = aicpu_orchestrator_phases out["orchestrator_source"] = "aicpu" + if aicpu_lifecycle_records: + out["aicpu_lifecycle_records"] = aicpu_lifecycle_records if host_device_uploads: out["host_device_uploads"] = host_device_uploads if host_mode: @@ -1054,7 +1222,7 @@ def print_task_statistics(tasks, func_id_to_name=None, chip_swimlane_level=None) """Print task statistics grouped by func_id. Exec = kernel execution time (end_time_us - start_time_us) on AICore. - Latency = AICPU view: finish_time_us - dispatch_time_us (includes head OH + Exec + tail OH). + Latency = Scheduler view: finish_time_us - dispatch_time_us (includes head OH + Exec + tail OH). High Latency with low Exec means scheduler/polling overhead (tail OH = finish_ts recorded when the scheduler loop next sees the completed handshake; reordering the loop to process completed tasks first reduces this). @@ -1062,10 +1230,12 @@ def print_task_statistics(tasks, func_id_to_name=None, chip_swimlane_level=None) Args: tasks: List of task dicts func_id_to_name: Optional dict mapping func_id to function name - chip_swimlane_level: Source collection level. Level 1 has no AICPU - dispatch/finish timestamps, so latency-derived metrics are unavailable. + chip_swimlane_level: Source collection level. Level 2 and above include + Scheduler per-task dispatch/finish timestamps. """ - has_aicpu_timing = chip_swimlane_level is None or chip_swimlane_level >= 2 + has_scheduler_timing = any( + task.get("dispatch_time_us", -1) >= 0 and task.get("finish_time_us", 0) > 0 for task in tasks + ) # Group tasks by func_id with extended metrics func_stats: defaultdict[Any, dict[str, Any]] = defaultdict( @@ -1102,7 +1272,7 @@ def print_task_statistics(tasks, func_id_to_name=None, chip_swimlane_level=None) func_stats[func_id]["local_setups"].append(task["local_setup_us"]) # Calculate new metrics if dispatch_time_us and finish_time_us are available - if has_aicpu_timing and "dispatch_time_us" in task and "finish_time_us" in task: + if has_scheduler_timing and "dispatch_time_us" in task and "finish_time_us" in task: dispatch_time = task["dispatch_time_us"] finish_time = task["finish_time_us"] @@ -1136,8 +1306,8 @@ def print_task_statistics(tasks, func_id_to_name=None, chip_swimlane_level=None) print("Task Statistics by Function") level_descriptions = { 1: "AICore timing only", - 2: "AICore + AICPU timing", - 3: "AICore + AICPU timing + scheduler phases", + 2: "AICore + Scheduler task timing", + 3: "AICore + Scheduler task timing + scheduler phases", 4: "full collection with orchestrator phases", } if chip_swimlane_level is None: @@ -1195,10 +1365,10 @@ def print_task_statistics(tasks, func_id_to_name=None, chip_swimlane_level=None) # Calculate execution ratio: total_exec_time / total_latency exec_ratio = (stats["total_exec_time"] / stats["total_latency"] * 100) if stats["total_latency"] > 0 else 0 - latency_str = f"{avg_latency:.2f}" if has_aicpu_timing else "-" - exec_ratio_str = f"{exec_ratio:.1f}%" if has_aicpu_timing else "-" - head_str = f"{avg_head_overhead:.2f}" if has_aicpu_timing else "-" - tail_str = f"{avg_tail_overhead:.2f}" if has_aicpu_timing else "-" + latency_str = f"{avg_latency:.2f}" if has_scheduler_timing else "-" + exec_ratio_str = f"{exec_ratio:.1f}%" if has_scheduler_timing else "-" + head_str = f"{avg_head_overhead:.2f}" if has_scheduler_timing else "-" + tail_str = f"{avg_tail_overhead:.2f}" if has_scheduler_timing else "-" prop_str = f"{avg_propagation:>12.2f}" if avg_propagation is not None else f"{'-':>12}" local_str = f"{avg_local_setup:>13.2f}" if avg_local_setup is not None else f"{'-':>13}" print( @@ -1212,21 +1382,21 @@ def print_task_statistics(tasks, func_id_to_name=None, chip_swimlane_level=None) # Calculate total latency (sum of all latencies) total_latency_sum = sum(stats["total_latency"] for stats in func_stats.values()) - total_latency_str = f"{total_latency_sum:.2f}" if has_aicpu_timing else "-" + total_latency_str = f"{total_latency_sum:.2f}" if has_scheduler_timing else "-" print(f"{'TOTAL':<21} {total_count:>5} {total_duration:>12.2f} {total_latency_str:>15}") # Print total test execution time - if has_aicpu_timing and min_dispatch_time != float("inf") and max_finish_time != float("-inf"): + if has_scheduler_timing and min_dispatch_time != float("inf") and max_finish_time != float("-inf"): total_test_time = max_finish_time - min_dispatch_time print(f"\nTotal Test Time: {total_test_time:.2f} us (from earliest dispatch to latest finish)") - elif chip_swimlane_level == 1 and min_aicore_time != float("inf") and max_aicore_time != float("-inf"): + elif not has_scheduler_timing and min_aicore_time != float("inf") and max_aicore_time != float("-inf"): aicore_observed_span = max_aicore_time - min_aicore_time print( f"\nAICore Observed Span: {aicore_observed_span:.2f} us (from earliest AICore receive to latest AICore end)" ) # Task execution vs Scheduler overhead summary - if has_aicpu_timing and total_count > 0 and total_latency_sum > 0: + if has_scheduler_timing and total_count > 0 and total_latency_sum > 0: avg_exec_us = total_duration / total_count avg_latency_us = total_latency_sum / total_count exec_latency_ratio_pct = total_duration / total_latency_sum * 100 @@ -1387,6 +1557,7 @@ def generate_chrome_trace_json( # noqa: PLR0912, PLR0913, PLR0915 func_id_to_name=None, verbose=False, scheduler_phases=None, + scheduler_streams=None, orchestrator_phases=None, core_to_thread=None, orchestrator_name=None, @@ -1397,6 +1568,7 @@ def generate_chrome_trace_json( # noqa: PLR0912, PLR0913, PLR0915 deps_block_map=None, emit_overhead=False, host_device_uploads=None, + aicpu_lifecycle_records=None, ): """Generate Chrome Trace Event Format JSON from task data. @@ -1404,20 +1576,22 @@ def generate_chrome_trace_json( # noqa: PLR0912, PLR0913, PLR0915 tasks: List of task dicts with fields: - task_id, func_id, core_id, core_type - start_time_us, end_time_us, duration_us - - dispatch_time_us (optional, AICPU dispatch timestamp) - - finish_time_us (optional, AICPU finish timestamp) + - dispatch_time_us (optional, Scheduler dispatch timestamp) + - finish_time_us (optional, Scheduler finish timestamp) output_path: Path to output JSON file func_id_to_name: Optional dict mapping func_id to function name verbose: Print progress information - scheduler_phases: Optional list of per-thread phase record lists (chip_swimlane_level >= 3) + scheduler_phases: Optional list of per-scheduler record lists (chip_swimlane_level >= 3) + scheduler_streams: Optional metadata for each scheduler record list orchestrator_phases: Optional list of per-task orchestrator phase records (chip_swimlane_level >= 4) core_to_thread: Optional list mapping core_id (index) to scheduler thread index (-1 = unassigned) + aicpu_lifecycle_records: Optional A5 HBG AICPU control-plane lifecycle records Generates processes in the trace: - pid=5 "Graph Execution": one end-to-end envelope per Graph task - pid=1 "Host/AICPU Orchestrator": orchestrator phase bars (chip_swimlane_level >= 4) - - pid=2 "AICPU Scheduler": scheduler phase bars (chip_swimlane_level >= 3) - - pid=3 "Scheduler View": dispatch_time_us to finish_time_us (AICPU perspective) + - pid=2 "AICPU/AICore Scheduler": scheduler record bars (chip_swimlane_level >= 3) + - pid=3 "Scheduler View": dispatch_time_us to finish_time_us - pid=4 "Worker View": per-subtask kernel execution on physical cores """ if verbose: @@ -1457,6 +1631,72 @@ def generate_chrome_trace_json( # noqa: PLR0912, PLR0913, PLR0915 # Step 2: Generate JSON events events = [] + if aicpu_lifecycle_records: + events.append( + {"args": {"name": "AICPU Lifecycle"}, "cat": "__metadata", "name": "process_name", "ph": "M", "pid": 6} + ) + events.append( + {"args": {"sort_index": 2}, "cat": "__metadata", "name": "process_sort_index", "ph": "M", "pid": 6} + ) + lifecycle_intervals = ( + ("handshake_partition", "handshake_observed_time_us", "handshake_partition_complete_time_us"), + ("topology_config", "config_start_time_us", "topology_complete_time_us"), + ("context_publish", "topology_complete_time_us", "context_publish_complete_time_us"), + ("bootstrap_wait", "bootstrap_wait_start_time_us", "bootstrap_complete_time_us"), + ("exit_wait", "exit_signal_time_us", "exit_ack_time_us"), + ) + for record in aicpu_lifecycle_records: + worker_id = int(record.get("worker_id", record.get("record_index", 0))) + thread_id = int(record.get("aicpu_thread_id", -1)) + tid = 60000 + worker_id + events.append( + { + "args": {"name": f"worker_{worker_id} (AICPU thread {thread_id})"}, + "cat": "__metadata", + "name": "thread_name", + "ph": "M", + "pid": 6, + "tid": tid, + } + ) + identity = { + "worker_id": worker_id, + "aicpu_thread_id": thread_id, + "core_type": record.get("core_type"), + "physical_core_id": record.get("physical_core_id"), + } + for name, start_field, end_field in lifecycle_intervals: + start = float(record.get(start_field, 0.0)) + end = float(record.get(end_field, 0.0)) + if end <= 0 or end < start: + continue + events.append( + { + "args": identity, + "cat": "aicpu_lifecycle", + "name": name, + "ph": "X", + "pid": 6, + "tid": tid, + "ts": start, + "dur": end - start, + } + ) + register_release = float(record.get("register_release_time_us", 0.0)) + if register_release > 0: + events.append( + { + "args": identity, + "cat": "aicpu_lifecycle", + "name": "register_release", + "ph": "i", + "s": "t", + "pid": 6, + "tid": tid, + "ts": register_release, + } + ) + # Metadata event: Process names and sort order. # pid is renumbered in pipeline order (top → bottom in Perfetto): # pid=1 AICPU Orchestrator (submits tasks — earliest) @@ -1518,10 +1758,12 @@ def generate_chrome_trace_json( # noqa: PLR0912, PLR0913, PLR0915 events.append({"args": {"name": "Worker View"}, "cat": "__metadata", "name": "process_name", "ph": "M", "pid": 4}) events.append({"args": {"sort_index": 4}, "cat": "__metadata", "name": "process_sort_index", "ph": "M", "pid": 4}) - # Check if any task has AICPU timestamps - has_aicpu_data = any(task.get("dispatch_time_us", 0) >= 0 and task.get("finish_time_us", 0) > 0 for task in tasks) + # Check if any task has Scheduler timestamps. + has_scheduler_task_data = any( + task.get("dispatch_time_us", 0) >= 0 and task.get("finish_time_us", 0) > 0 for task in tasks + ) - if has_aicpu_data: + if has_scheduler_task_data: events.append( {"args": {"name": "Scheduler View"}, "cat": "__metadata", "name": "process_name", "ph": "M", "pid": 3} ) @@ -1548,8 +1790,8 @@ def generate_chrome_trace_json( # noqa: PLR0912, PLR0913, PLR0915 # Duration events (Complete events "X") # Build task_id -> event_id mapping for flow events task_to_event_id: dict[tuple[int, int], int] = {} - task_to_aicpu_event_id: dict[tuple[int, int], int] = {} - task_to_aicpu_tid: dict[tuple[int, int], int] = {} + task_to_scheduler_event_id: dict[tuple[int, int], int] = {} + task_to_scheduler_tid: dict[tuple[int, int], int] = {} aicpu_worker_anchor_map: dict[int, list[dict]] = defaultdict(list) event_id = 0 @@ -1643,21 +1885,21 @@ def worker_flow_endpoint(row): # Scheduler View duration events (dispatch_time to finish_time) # Assign overlapping tasks on the same core to different tids so Perfetto # renders each bar on its own row (Perfetto requires strict nesting on a tid). - if has_aicpu_data: + if has_scheduler_task_data: # Build per-core sorted task lists and assign sub-lanes. # Each core gets a base tid from core_to_tid; overlapping tasks get base+1. - _core_aicpu_tasks: dict[int, list] = defaultdict(list) + _core_scheduler_tasks: dict[int, list] = defaultdict(list) for task in tasks: d = task.get("dispatch_time_us", 0) f = task.get("finish_time_us", 0) if d < 0 or f <= 0: continue - _core_aicpu_tasks[task["core_id"]].append(task) - for ct_list in _core_aicpu_tasks.values(): + _core_scheduler_tasks[task["core_id"]].append(task) + for ct_list in _core_scheduler_tasks.values(): ct_list.sort(key=lambda t: t["dispatch_time_us"]) - aicpu_tid_set: set[int] = set() - for core_id, ct_list in _core_aicpu_tasks.items(): + scheduler_tid_set: set[int] = set() + for core_id, ct_list in _core_scheduler_tasks.items(): base_tid = core_to_tid[core_id] # Greedy lane assignment: track finish time per sub-lane lane_finish = [0.0] # lane 0 = base_tid @@ -1673,16 +1915,16 @@ def worker_flow_endpoint(row): lane_finish.append(0.0) lane_finish[assigned] = task["finish_time_us"] tid = base_tid if assigned == 0 else base_tid + assigned - task_to_aicpu_tid[(task["task_id"], task["core_id"])] = tid - aicpu_tid_set.add(tid) + task_to_scheduler_tid[(task["task_id"], task["core_id"])] = tid + scheduler_tid_set.add(tid) # Thread name metadata for Scheduler View (one entry per unique tid used) for core_id, base_tid in core_to_tid.items(): - ct_list = _core_aicpu_tasks.get(core_id) + ct_list = _core_scheduler_tasks.get(core_id) core_type_str = ct_list[0]["core_type"].upper() if ct_list else "unknown" base_name = f"{core_type_str}_{core_id}" # Base lane always gets metadata (even if no tasks, for consistency) - if base_tid in aicpu_tid_set or not aicpu_tid_set: + if base_tid in scheduler_tid_set or not scheduler_tid_set: events.append( { "args": {"name": base_name}, @@ -1695,7 +1937,7 @@ def worker_flow_endpoint(row): ) # Overflow lane (at most one: dual-slot dispatch means max 2 concurrent tasks per core) overflow_tid = base_tid + 1 - if overflow_tid in aicpu_tid_set: + if overflow_tid in scheduler_tid_set: events.append( { "args": {"name": base_name}, @@ -1714,8 +1956,8 @@ def worker_flow_endpoint(row): if dispatch_us < 0 or finish_us <= 0: continue - tid = task_to_aicpu_tid.get((task["task_id"], task["core_id"]), core_to_tid[task["core_id"]]) - aicpu_dur = finish_us - dispatch_us + tid = task_to_scheduler_tid.get((task["task_id"], task["core_id"]), core_to_tid[task["core_id"]]) + scheduler_duration_us = finish_us - dispatch_us # Get function name if available (task(rXtY) when no deps.json # resolved the func_id; see _task_display_name). @@ -1729,7 +1971,7 @@ def worker_flow_endpoint(row): "event-hint": f"Task:{tdisp}, FuncId:{func_id}, CoreId:{task['core_id']}", "dispatch-time-us": dispatch_us, "finish-time-us": finish_us, - "aicpu-duration-us": aicpu_dur, + "scheduler-duration-us": scheduler_duration_us, "taskId": task["task_id"], }, "cat": "event", @@ -1739,10 +1981,10 @@ def worker_flow_endpoint(row): "pid": 3, "tid": tid, "ts": dispatch_us, - "dur": aicpu_dur, + "dur": scheduler_duration_us, } ) - task_to_aicpu_event_id[(task["task_id"], task["core_id"])] = event_id + task_to_scheduler_event_id[(task["task_id"], task["core_id"])] = event_id event_id += 1 flow_id = 0 @@ -1757,8 +1999,10 @@ def sched_lane_tid(thread_idx, lane=0): return 30000 + thread_idx * 10 + lane # Process metadata + producers = {stream.get("producer") for stream in (scheduler_streams or []) if stream.get("producer")} + scheduler_process_name = "AICore Scheduler" if producers == {"aicore"} else "AICPU Scheduler" events.append( - {"args": {"name": "AICPU Scheduler"}, "cat": "__metadata", "name": "process_name", "ph": "M", "pid": 2} + {"args": {"name": scheduler_process_name}, "cat": "__metadata", "name": "process_name", "ph": "M", "pid": 2} ) events.append( {"args": {"sort_index": 2}, "cat": "__metadata", "name": "process_sort_index", "ph": "M", "pid": 2} @@ -1784,6 +2028,12 @@ def sched_lane_tid(thread_idx, lane=0): "drain_prepare": "cq_build_attempt_runnable", # inner: cluster scan + build_payload "drain_publish": "cq_build_attempt_passed", # inner: MMIO write_reg per subtask (the cohort launch) "graph_prepare": "rail_animation", # bounded Scheduler-side Definition expansion + "bootstrap": "rail_animation", + "fanin": "cq_build_running", + "ready_claim": "cq_build_attempt_runnable", + "ready_steal": "cq_build_attempt_failed", + "direct_refill": "cq_build_attempt_passed", + "idle": "grey", # Inner in TMR; standalone on HBG's dedicated P thread. "resolve": "vsync_highlight_color", # on_task_complete: walk consumer list # Separate-lane (Worker View AICPU_N) — fallback color if it ever lands on Sched @@ -1857,9 +2107,17 @@ def _find_containing_complete(thread_idx: int, finish_us: float): ) # Thread name metadata + stream = scheduler_streams[thread_idx] if scheduler_streams and thread_idx < len(scheduler_streams) else {} + scheduler_id = stream.get("scheduler_id", thread_idx) + worker_id = stream.get("worker_id") + core_type = stream.get("core_type") + physical_core_id = stream.get("physical_core_id") + lane_name = f"Sched_{scheduler_id}" + if stream.get("producer") == "aicore": + lane_name = f"Scheduler_{scheduler_id} ({core_type}_{physical_core_id}, worker {worker_id})" events.append( { - "args": {"name": f"Sched_{thread_idx}"}, + "args": {"name": lane_name}, "cat": "__metadata", "name": "thread_name", "ph": "M", @@ -1954,6 +2212,12 @@ def _find_containing_complete(thread_idx: int, finish_us: float): "drain_prepare", "drain_publish", "graph_prepare", + "bootstrap", + "fanin", + "ready_claim", + "ready_steal", + "direct_refill", + "idle", ): continue start_us = record["start_time_us"] @@ -2325,8 +2589,8 @@ def _find_containing_complete(thread_idx: int, finish_us: float): if hb_violation_count > 0: print(f" Happens-before violations: {hb_violation_count} edge(s) flagged as 'hb_violation'") - # Scheduler View dependency mirror (AICPU timestamps). - if has_aicpu_data: + # Scheduler View dependency mirror (Scheduler timestamps). + if has_scheduler_task_data: for pred_id, succ_ids in edges_by_pred.items(): if pred_id not in task_map: continue @@ -2352,34 +2616,34 @@ def _find_containing_complete(thread_idx: int, finish_us: float): src_finish_us = pred_row.get("finish_time_us", 0) dst_dispatch_us = succ_row.get("dispatch_time_us", 0) dst_finish_us = succ_row.get("finish_time_us", 0) - # Skip when AICPU timestamps are missing or zero (matches Scheduler + # Skip when Scheduler timestamps are missing or zero (matches Scheduler # View bar emission, which rejects finish_us <= 0). if src_dispatch_us < 0 or src_finish_us <= 0 or dst_dispatch_us < 0 or dst_finish_us <= 0: continue - aicpu_hb_violated = src_finish_us > dst_dispatch_us - aicpu_flow_name = "hb_violation" if aicpu_hb_violated else "dependency" + scheduler_hb_violated = src_finish_us > dst_dispatch_us + scheduler_flow_name = "hb_violation" if scheduler_hb_violated else "dependency" _append_dependency_flow_pair( events, flow_id, - aicpu_flow_name, + scheduler_flow_name, 3, - task_to_aicpu_tid.get( + task_to_scheduler_tid.get( (pred_row["task_id"], pred_row["core_id"]), core_to_tid[pred_row["core_id"]] ), src_dispatch_us, - task_to_aicpu_event_id.get((pred_row["task_id"], pred_row["core_id"])), + task_to_scheduler_event_id.get((pred_row["task_id"], pred_row["core_id"])), 3, - task_to_aicpu_tid.get( + task_to_scheduler_tid.get( (succ_row["task_id"], succ_row["core_id"]), core_to_tid[succ_row["core_id"]] ), dst_dispatch_us, - task_to_aicpu_event_id.get((succ_row["task_id"], succ_row["core_id"])), + task_to_scheduler_event_id.get((succ_row["task_id"], succ_row["core_id"])), input_task_count=input_task_count, output_task_count=output_task_count, ) flow_id += 1 - # Complete-phase flow arrows. The complete phase wraps the AICPU's + # Complete-phase flow arrows. The complete phase wraps the Scheduler's # completion-polling loop: it observes AICore subtask FINs, increments # the slot's per-task subtask counter, and on the LAST subtask of a # logical task it walks the fanout list and releases each consumer's @@ -2387,14 +2651,14 @@ def _find_containing_complete(thread_idx: int, finish_us: float): # # Inbound: per-task, NOT per-subtask. A task is logically "completed" # only when its LAST subtask is observed (the one that triggers - # phase_complete_count++ in firmware). For SPMD with N subtasks across + # logical completion count in firmware). For SPMD with N subtasks across # N cores, the earlier N-1 subtasks just bump the slot's # completed_subtasks counter inside whatever complete phase happened to # poll them; only the LAST subtask's finish actually completes the # task. So per task: take max(finish_time_us) across its subtasks and # find the complete phase that CONTAINS that time. Each task view starts # its visual arrow on the same independently selected anchor it uses for - # SPMD dependency arrows, then lands at the last subtask's AICPU finish + # SPMD dependency arrows, then lands at the last subtask's Scheduler finish # timestamp inside the complete phase. This keeps related SPMD flows # consistent within each view without changing completion attribution. # @@ -2427,7 +2691,7 @@ def _find_containing_complete(thread_idx: int, finish_us: float): # subtask's core — typical case is the same thread observed # earlier subtasks too, but we don't assume. Each task view selects its # own earliest visible subtask slice; both flows end at the LAST - # subtask's AICPU finish timestamp, preserving completion attribution. + # subtask's Scheduler finish timestamp, preserving completion attribution. task_to_complete: dict[int, dict] = {} task_last_subtask: dict[int, tuple[float, float, int]] = {} # tid -> (last_end_us, last_finish_us, core_id) task_worker_anchors: dict[int, list[dict]] = {} @@ -2514,14 +2778,14 @@ def _find_containing_complete(thread_idx: int, finish_us: float): flow_id += 1 for anchor in task_scheduler_anchors[tid]: - # Scheduler View (pid=3): anchor on the AICPU dispatch→finish + # Scheduler View (pid=3): anchor on the Scheduler dispatch→finish # bar (source ts = finish_time_us). Skip when the anchor has - # no AICPU finish — its pid=3 bar doesn't exist to bind to. + # no Scheduler finish — its pid=3 bar doesn't exist to bind to. anchor_finish_us = anchor.get("finish_time_us") if anchor_finish_us is None or anchor_finish_us <= 0: continue - sched_src_tid = task_to_aicpu_tid.get((tid, anchor["core_id"]), core_to_tid[anchor["core_id"]]) - sched_src_event_id = task_to_aicpu_event_id.get((tid, anchor["core_id"])) + sched_src_tid = task_to_scheduler_tid.get((tid, anchor["core_id"]), core_to_tid[anchor["core_id"]]) + sched_src_event_id = task_to_scheduler_event_id.get((tid, anchor["core_id"])) events.append( { "cat": "flow", @@ -2646,7 +2910,7 @@ def _find_containing_complete(thread_idx: int, finish_us: float): flow_id += 1 # Scheduler DISPATCH → task execution arrows - if scheduler_phases and has_aicpu_data: + if scheduler_phases and has_scheduler_task_data: # Build core_id → scheduler thread mapping. # Prefer explicit core_to_thread from perf JSON (written by AICPU after orchestration). # Fall back to voting heuristic for older data without the mapping. @@ -2693,7 +2957,7 @@ def _find_containing_complete(thread_idx: int, finish_us: float): if matched_thread is not None: sched_tid = sched_lane_tid(matched_thread, 0) core_tid = core_to_tid[task["core_id"]] - aicpu_tid = task_to_aicpu_tid.get((task["task_id"], task["core_id"]), core_tid) + scheduler_view_tid = task_to_scheduler_tid.get((task["task_id"], task["core_id"]), core_tid) # Flow: scheduler DISPATCH → Worker View task start events.append( @@ -2722,7 +2986,7 @@ def _find_containing_complete(thread_idx: int, finish_us: float): flow_id += 1 # Flow: scheduler DISPATCH → Scheduler View task start - aicpu_eid = task_to_aicpu_event_id.get((task["task_id"], task["core_id"])) + scheduler_event_id = task_to_scheduler_event_id.get((task["task_id"], task["core_id"])) events.append( { "cat": "flow", @@ -2740,12 +3004,12 @@ def _find_containing_complete(thread_idx: int, finish_us: float): "name": "dispatch", "ph": "f", "pid": 3, - "tid": aicpu_tid, + "tid": scheduler_view_tid, "ts": dispatch_us, "bp": "e", } - if aicpu_eid is not None: - flow_f["bind_id"] = aicpu_eid + if scheduler_event_id is not None: + flow_f["bind_id"] = scheduler_event_id events.append(flow_f) flow_id += 1 @@ -2782,7 +3046,7 @@ def _find_containing_complete(thread_idx: int, finish_us: float): elif existing is None and phase == "orch_params": orch_anchor_by_task[tid_k] = (record, orch_idx, "params→dispatch") - if has_aicpu_data and orch_anchor_by_task: + if has_scheduler_task_data and orch_anchor_by_task: for task in tasks: tid = normalize_task_id_int(task.get("task_id")) if tid is None: @@ -3522,11 +3786,13 @@ def main(): args.verbose, orchestrator_name=orchestrator_name, scheduler_phases=data.get("aicpu_scheduler_phases"), + scheduler_streams=data.get("scheduler_streams"), orchestrator_phases=data.get("aicpu_orchestrator_phases"), orchestrator_source=data.get("orchestrator_source"), timeline_metadata=data.get("timeline_metadata"), core_to_thread=data.get("core_to_thread"), host_device_uploads=data.get("host_device_uploads"), + aicpu_lifecycle_records=data.get("aicpu_lifecycle_records"), deps_edges=deps_edges, deps_kernel_map=deps_kernel_map, deps_block_map=deps_block_map, diff --git a/src/a2a3/platform/include/common/scheduler_profiling.h b/src/a2a3/platform/include/common/scheduler_profiling.h new file mode 100644 index 0000000000..255ed03659 --- /dev/null +++ b/src/a2a3/platform/include/common/scheduler_profiling.h @@ -0,0 +1,65 @@ +/* + * Copyright (c) PyPTO Contributors. + * This program is free software, you can redistribute it and/or modify it under the terms and conditions of + * CANN Open Software License Agreement Version 2.0 (the "License"). + * Please refer to the License for details. You may not use this file except in compliance with the License. + * THIS SOFTWARE IS PROVIDED ON AN "AS IS" BASIS, WITHOUT WARRANTIES OF ANY KIND, EITHER EXPRESS OR IMPLIED, + * INCLUDING BUT NOT LIMITED TO NON-INFRINGEMENT, MERCHANTABILITY, OR FITNESS FOR A PARTICULAR PURPOSE. + * See LICENSE in the root of the software repository for the full text of the License. + * ----------------------------------------------------------------------------------------------------------- + */ + +#pragma once + +#include +#include + +inline constexpr const char *CHIP_SWIMLANE_ARCHITECTURE_NAME = "a2a3"; + +enum class ChipSwimlaneSchedPhaseKind : uint32_t { + Complete = 0, + Dispatch = 1, + Release = 2, + Dummy = 4, + EarlyDispatch = 5, + Resolve = 6, + DummyTask = 7, + Drain = 8, + DrainPrepare = 9, + DrainPublish = 10, + AsyncPoll = 11, + PredicatedSkip = 12, + GraphPrepare = 13, + ResolveStandalone = 14, +}; + +constexpr int CHIP_SWIMLANE_NUM_QUEUE_SHAPES = 3; + +struct ChipSwimlaneAicpuSchedPhaseRecord { + uint64_t start_time; + uint64_t end_time; + uint32_t loop_iter; + ChipSwimlaneSchedPhaseKind kind; + uint32_t tasks_processed; + union { + struct { + uint32_t pop_hit; + uint32_t pop_miss; + } dispatch; + struct { + uint32_t local_id; + uint32_t ring_id; + } dummy_task; + struct { + uint32_t local_id; + uint32_t ring_id; + } graph_task; + } phase_data; + int16_t shared_depth_at_start[CHIP_SWIMLANE_NUM_QUEUE_SHAPES]; + int16_t shared_depth_at_end[CHIP_SWIMLANE_NUM_QUEUE_SHAPES]; + uint32_t _pad[4]; +}; + +static_assert(sizeof(decltype(ChipSwimlaneAicpuSchedPhaseRecord::phase_data)) == 8); +static_assert(offsetof(ChipSwimlaneAicpuSchedPhaseRecord, phase_data) == 28); +static_assert(sizeof(ChipSwimlaneAicpuSchedPhaseRecord) == 64); diff --git a/src/a2a3/platform/onboard/host/CMakeLists.txt b/src/a2a3/platform/onboard/host/CMakeLists.txt index f1496f516c..5bf9fe1d72 100644 --- a/src/a2a3/platform/onboard/host/CMakeLists.txt +++ b/src/a2a3/platform/onboard/host/CMakeLists.txt @@ -118,7 +118,13 @@ target_compile_options(host_runtime # Platform name baked into the shared get_platform() impl in # src/common/platform/shared/host/platform_compile_info.cpp. -target_compile_definitions(host_runtime PRIVATE SIMPLER_PLATFORM_NAME="a2a3") +if(NOT DEFINED SIMPLER_RUNTIME_NAME OR SIMPLER_RUNTIME_NAME STREQUAL "") + message(FATAL_ERROR "host_runtime requires -DSIMPLER_RUNTIME_NAME=") +endif() +target_compile_definitions(host_runtime PRIVATE + SIMPLER_PLATFORM_NAME="a2a3" + SIMPLER_RUNTIME_NAME="${SIMPLER_RUNTIME_NAME}" +) if(SIMPLER_ENABLE_PTO_SDMA_WORKSPACE) target_compile_definitions(host_runtime PRIVATE SIMPLER_ENABLE_PTO_SDMA_WORKSPACE=1) diff --git a/src/a2a3/platform/sim/host/CMakeLists.txt b/src/a2a3/platform/sim/host/CMakeLists.txt index 7a6dd09af9..27a870113c 100644 --- a/src/a2a3/platform/sim/host/CMakeLists.txt +++ b/src/a2a3/platform/sim/host/CMakeLists.txt @@ -100,7 +100,13 @@ target_compile_options(host_runtime # Platform name baked into the shared get_platform() impl in # src/common/platform/shared/host/platform_compile_info.cpp. -target_compile_definitions(host_runtime PRIVATE SIMPLER_PLATFORM_NAME="a2a3sim") +if(NOT DEFINED SIMPLER_RUNTIME_NAME OR SIMPLER_RUNTIME_NAME STREQUAL "") + message(FATAL_ERROR "host_runtime requires -DSIMPLER_RUNTIME_NAME=") +endif() +target_compile_definitions(host_runtime PRIVATE + SIMPLER_PLATFORM_NAME="a2a3sim" + SIMPLER_RUNTIME_NAME="${SIMPLER_RUNTIME_NAME}" +) # Include directories target_include_directories(host_runtime diff --git a/src/a5/platform/include/common/scheduler_profiling.h b/src/a5/platform/include/common/scheduler_profiling.h new file mode 100644 index 0000000000..8594c22262 --- /dev/null +++ b/src/a5/platform/include/common/scheduler_profiling.h @@ -0,0 +1,65 @@ +/* + * Copyright (c) PyPTO Contributors. + * This program is free software, you can redistribute it and/or modify it under the terms and conditions of + * CANN Open Software License Agreement Version 2.0 (the "License"). + * Please refer to the License for details. You may not use this file except in compliance with the License. + * THIS SOFTWARE IS PROVIDED ON AN "AS IS" BASIS, WITHOUT WARRANTIES OF ANY KIND, EITHER EXPRESS OR IMPLIED, + * INCLUDING BUT NOT LIMITED TO NON-INFRINGEMENT, MERCHANTABILITY, OR FITNESS FOR A PARTICULAR PURPOSE. + * See LICENSE in the root of the software repository for the full text of the License. + * ----------------------------------------------------------------------------------------------------------- + */ + +#pragma once + +#include +#include + +inline constexpr const char *CHIP_SWIMLANE_ARCHITECTURE_NAME = "a5"; + +enum class ChipSwimlaneSchedPhaseKind : uint32_t { + Complete = 0, + Dispatch = 1, + Release = 2, + Dummy = 4, + EarlyDispatch = 5, + Resolve = 6, + DummyTask = 7, + Drain = 8, + DrainPrepare = 9, + DrainPublish = 10, + AsyncPoll = 11, + PredicatedSkip = 12, + GraphPrepare = 13, + ResolveStandalone = 14, +}; + +constexpr int CHIP_SWIMLANE_NUM_QUEUE_SHAPES = 3; + +struct ChipSwimlaneAicpuSchedPhaseRecord { + uint64_t start_time; + uint64_t end_time; + uint32_t loop_iter; + ChipSwimlaneSchedPhaseKind kind; + uint32_t tasks_processed; + union { + struct { + uint32_t pop_hit; + uint32_t pop_miss; + } dispatch; + struct { + uint32_t local_id; + uint32_t ring_id; + } dummy_task; + struct { + uint32_t local_id; + uint32_t ring_id; + } graph_task; + } phase_data; + int16_t shared_depth_at_start[CHIP_SWIMLANE_NUM_QUEUE_SHAPES]; + int16_t shared_depth_at_end[CHIP_SWIMLANE_NUM_QUEUE_SHAPES]; + uint32_t _pad[4]; +}; + +static_assert(sizeof(decltype(ChipSwimlaneAicpuSchedPhaseRecord::phase_data)) == 8); +static_assert(offsetof(ChipSwimlaneAicpuSchedPhaseRecord, phase_data) == 28); +static_assert(sizeof(ChipSwimlaneAicpuSchedPhaseRecord) == 64); diff --git a/src/a5/platform/onboard/host/CMakeLists.txt b/src/a5/platform/onboard/host/CMakeLists.txt index 978afcfe4b..a9ffee4631 100644 --- a/src/a5/platform/onboard/host/CMakeLists.txt +++ b/src/a5/platform/onboard/host/CMakeLists.txt @@ -128,7 +128,13 @@ target_compile_options(host_runtime # Platform name baked into the shared get_platform() impl in # src/common/platform/shared/host/platform_compile_info.cpp. -target_compile_definitions(host_runtime PRIVATE SIMPLER_PLATFORM_NAME="a5") +if(NOT DEFINED SIMPLER_RUNTIME_NAME OR SIMPLER_RUNTIME_NAME STREQUAL "") + message(FATAL_ERROR "host_runtime requires -DSIMPLER_RUNTIME_NAME=") +endif() +target_compile_definitions(host_runtime PRIVATE + SIMPLER_PLATFORM_NAME="a5" + SIMPLER_RUNTIME_NAME="${SIMPLER_RUNTIME_NAME}" +) if(SIMPLER_ENABLE_PTO_SDMA_WORKSPACE) target_compile_definitions(host_runtime PRIVATE SIMPLER_ENABLE_PTO_SDMA_WORKSPACE=1) diff --git a/src/a5/platform/onboard/host/device_runner.cpp b/src/a5/platform/onboard/host/device_runner.cpp index c8259fe927..9abc3efe5c 100644 --- a/src/a5/platform/onboard/host/device_runner.cpp +++ b/src/a5/platform/onboard/host/device_runner.cpp @@ -78,6 +78,14 @@ extern "C" __attribute__((weak, visibility("hidden"))) int dep_gen_host_graph_em return -1; } +// Each host_runtime.so links one runtime source set. A5 HBG replaces this +// no-op with the publisher for its resident scheduler state. +extern "C" __attribute__((weak, visibility("hidden"))) bool publish_runtime_chip_swimlane_extensions( + Runtime * /*runtime*/ +) noexcept { + return true; +} + // ============================================================================= // DeviceRunner Implementation // ============================================================================= @@ -615,11 +623,17 @@ int DeviceRunner::drain_execution(ActiveExecution &active) { recover_device_or_mark_unusable(rc); // Emergency shutdown may already have flushed diagnostics. Export the // manifest on the error path exactly once. + if (enable_chip_swimlane_ && !publish_runtime_chip_swimlane_extensions(prepared.runtime)) { + LOG_WARN("Runtime chip-swimlane extension publication failed"); + } teardown_shared_collectors_after_run(false); return rc; } read_device_wall_ns(); + if (enable_chip_swimlane_ && !publish_runtime_chip_swimlane_extensions(prepared.runtime)) { + LOG_WARN("Runtime chip-swimlane extension publication failed"); + } teardown_shared_collectors_after_run(true); // a5-specific dep_gen teardown: host-orch emits the graph its orchestration diff --git a/src/a5/platform/sim/host/CMakeLists.txt b/src/a5/platform/sim/host/CMakeLists.txt index fbbe275acf..1a50c5762a 100644 --- a/src/a5/platform/sim/host/CMakeLists.txt +++ b/src/a5/platform/sim/host/CMakeLists.txt @@ -101,7 +101,13 @@ target_compile_options(host_runtime # Platform name baked into the shared get_platform() impl in # src/common/platform/shared/host/platform_compile_info.cpp. -target_compile_definitions(host_runtime PRIVATE SIMPLER_PLATFORM_NAME="a5sim") +if(NOT DEFINED SIMPLER_RUNTIME_NAME OR SIMPLER_RUNTIME_NAME STREQUAL "") + message(FATAL_ERROR "host_runtime requires -DSIMPLER_RUNTIME_NAME=") +endif() +target_compile_definitions(host_runtime PRIVATE + SIMPLER_PLATFORM_NAME="a5sim" + SIMPLER_RUNTIME_NAME="${SIMPLER_RUNTIME_NAME}" +) # Include directories target_include_directories(host_runtime diff --git a/src/a5/platform/sim/host/device_runner.cpp b/src/a5/platform/sim/host/device_runner.cpp index 4e6879a1aa..90893a2a88 100644 --- a/src/a5/platform/sim/host/device_runner.cpp +++ b/src/a5/platform/sim/host/device_runner.cpp @@ -74,6 +74,14 @@ extern "C" __attribute__((weak, visibility("hidden"))) int dep_gen_host_graph_em return -1; } +// Each host_runtime.so links one runtime source set. A5 HBG replaces this +// no-op with the publisher for its resident scheduler state. +extern "C" __attribute__((weak, visibility("hidden"))) bool publish_runtime_chip_swimlane_extensions( + Runtime * /*runtime*/ +) noexcept { + return true; +} + // a5 sim: malloc / free wrappers shared by the four profiling subsystems' // init_* methods. Plain function pointers convert implicitly into the // framework's std::function alloc / free shapes. Kept on the subclass (not @@ -668,6 +676,9 @@ int DeviceRunner::drain_execution(ActiveExecution &) { chip_swimlane_collector_.read_phase_header_metadata(); chip_swimlane_collector_.reconcile_counters(); publish_host_phase_records_to_swimlane(); + if (!publish_runtime_chip_swimlane_extensions(active_run_->runtime)) { + LOG_WARN("Runtime chip-swimlane extension publication failed"); + } chip_swimlane_collector_.export_swimlane_json(); } diff --git a/src/a5/runtime/host_build_graph/aicore/aicore_legacy_executor.cpp b/src/a5/runtime/host_build_graph/aicore/aicore_legacy_executor.cpp index febaf9b038..b2737138a8 100644 --- a/src/a5/runtime/host_build_graph/aicore/aicore_legacy_executor.cpp +++ b/src/a5/runtime/host_build_graph/aicore/aicore_legacy_executor.cpp @@ -282,7 +282,7 @@ legacy_aicore_execute(__gm__ Runtime *runtime, int block_idx, CoreType core_type // - reg_task_id is `task_id` (= reg_val, the per-core dispatch // token AICore just read from DATA_MAIN_BASE). Per-dispatch // unique within this core; host uses it as the join key - // against the AICPU record stream. Required for correctness + // against the Scheduler task record stream. Required for correctness // under SPMD (block_num > num_cores) and MIX cluster spread, // where multiple dispatches of the same task share the same // task_token_raw. diff --git a/src/common/platform/include/common/chip_swimlane_extension.h b/src/common/platform/include/common/chip_swimlane_extension.h new file mode 100644 index 0000000000..9a1cfb2d42 --- /dev/null +++ b/src/common/platform/include/common/chip_swimlane_extension.h @@ -0,0 +1,61 @@ +/* + * Copyright (c) PyPTO Contributors. + * This program is free software, you can redistribute it and/or modify it under the terms and conditions of + * CANN Open Software License Agreement Version 2.0 (the "License"). + * Please refer to the License for details. You may not use this file except in compliance with the License. + * THIS SOFTWARE IS PROVIDED ON AN "AS IS" BASIS, WITHOUT WARRANTIES OF ANY KIND, EITHER EXPRESS OR IMPLIED, + * INCLUDING BUT NOT LIMITED TO NON-INFRINGEMENT, MERCHANTABILITY, OR FITNESS FOR A PARTICULAR PURPOSE. + * See LICENSE in the root of the software repository for the full text of the License. + * ----------------------------------------------------------------------------------------------------------- + */ + +#pragma once + +#include +#include +#include + +/** Fixed extension slots emitted by runtime-owned chip-swimlane producers. */ +enum class ChipSwimlaneExtensionSection : uint32_t { + AicoreTasks = 0, + SchedulerTasks = 1, + SchedulerRecords = 2, + AicpuLifecycleRecords = 3, + Count = 4, +}; + +inline constexpr bool chip_swimlane_extension_section_is_valid(ChipSwimlaneExtensionSection section) { + return static_cast(section) < static_cast(ChipSwimlaneExtensionSection::Count); +} + +inline constexpr const char *chip_swimlane_extension_section_name(ChipSwimlaneExtensionSection section) { + switch (section) { + case ChipSwimlaneExtensionSection::AicoreTasks: + return "aicore_tasks"; + case ChipSwimlaneExtensionSection::SchedulerTasks: + return "scheduler_tasks"; + case ChipSwimlaneExtensionSection::SchedulerRecords: + return "scheduler_records"; + case ChipSwimlaneExtensionSection::AicpuLifecycleRecords: + return "aicpu_lifecycle_records"; + case ChipSwimlaneExtensionSection::Count: + break; + } + return nullptr; +} + +inline constexpr bool chip_swimlane_extension_section_is_object(ChipSwimlaneExtensionSection section) { + return section == ChipSwimlaneExtensionSection::SchedulerTasks || + section == ChipSwimlaneExtensionSection::SchedulerRecords; +} + +/** Validate the bounded payload envelope; payload contents come only from internal serializers. */ +inline bool +chip_swimlane_extension_has_expected_root(ChipSwimlaneExtensionSection section, std::string_view json_value) noexcept { + if (!chip_swimlane_extension_section_is_valid(section)) return false; + const size_t first = json_value.find_first_not_of(" \t\r\n"); + const size_t last = json_value.find_last_not_of(" \t\r\n"); + if (first == std::string_view::npos) return false; + const bool expects_object = chip_swimlane_extension_section_is_object(section); + return json_value[first] == (expects_object ? '{' : '[') && json_value[last] == (expects_object ? '}' : ']'); +} diff --git a/src/common/platform/include/common/chip_swimlane_profiling.h b/src/common/platform/include/common/chip_swimlane_profiling.h index 38707d0801..98619ed389 100644 --- a/src/common/platform/include/common/chip_swimlane_profiling.h +++ b/src/common/platform/include/common/chip_swimlane_profiling.h @@ -62,6 +62,7 @@ #include "common/dfx_backpressure_device.h" #include "common/host_phase_kind.h" #include "common/platform_config.h" +#include "common/scheduler_profiling.h" // ============================================================================= // chip swimlane_level — granularity ladder for the chip swimlane profiler. @@ -510,107 +511,6 @@ static_assert(sizeof(ChipSwimlaneDataHeader) % 64 == 0, "ChipSwimlaneDataHeader * surrounding Dummy outer bar (sched lane) carries the actual drain time, * and Resolve inside that bar carries the consumer-release work. */ -enum class ChipSwimlaneSchedPhaseKind : uint32_t { - // Outer - Complete = 0, // check_running_cores_for_completion: observe FINs + - // run on_task_complete inline. tasks_processed = FIN'd - // subtasks + sub-block retires this iter. - Dispatch = 1, // dispatch_ready_tasks: publish ready tasks to AICore. - // tasks_processed = subtasks published this iter. - Release = 2, // Deferred-release drain (on_task_release work). - // tasks_processed = slots released this iter. - Dummy = 4, // dummy_drain outer bar: covers explicit dummies and - // false-predicate tasks popped this iter. - // tasks_processed = dummy_got count. - EarlyDispatch = 5, // try_early_dispatch: early-dispatch pre-staging - // of a flagged producer's consumer's gated blocks. - // tasks_processed = blocks staged this pass. - // Inner in tensormap_and_ringbuffer (parent: Complete | Dummy). - Resolve = 6, // Complete ready work after FIN observation. tasks_processed - // is consumers visited. - // Separate-lane (Worker View pid=4 AICPU_N) - DummyTask = 7, // Per-dummy identity marker (zero-width). phase_data.dummy_task - // carries the local/ring components of the full task identity. - Drain = 8, // handle_drain_mode outer: the sync_start stop-the-world drain - // (ack barrier + availability + parallel stage + finalize). - // One bar per dispatch-loop iteration that enters the drain, - // so retries show as multiple bars. Otherwise this time is a - // swimlane blind spot (the loop `continue`s past all records). - DrainPrepare = 9, // inner: this thread's global sync_start staging prepare pass - // (cluster scan + build_payload). tasks_processed = subtasks. - DrainPublish = 10, // inner: this thread's global sync_start staging publish pass - // (MMIO write_reg per subtask). tasks_processed = subtasks. - // Outer (sched lane): async-wait completion polling, split out of Complete - // so async-engine (SDMA/RoCE/URMA/CCU) wait time is attributed to its own - // bar. tasks_processed = async subtasks completed this iter. - AsyncPoll = 11, - // Separate-lane (Worker View pid=4 AICPU_N) - PredicatedSkip = 12, // Per-task marker for a real task retired inline because - // its dispatch predicate evaluated false. Uses the same - // phase_data.dummy_task identity payload as DummyTask. - // Outer (sched lane): one bounded Graph Definition materialization slice. - // phase_data.graph_task identifies the ring-0 outer Graph task and - // tasks_processed is the number of in-graph tasks patched in this slice. - GraphPrepare = 13, - // Outer on host_build_graph's dedicated P thread. Kept distinct from the - // nested TMR Resolve so post-processing never infers the role from rounded - // timestamps. tasks_processed is completed SPSC slots. - ResolveStandalone = 14, -}; - -/** Index layout of the queue-depth snapshot arrays below: AIC=0, AIV=1, MIX=2. - * Must match ResourceShape's first three values (see submit_types.h). - * Hardcoded here rather than included to keep this header runtime-independent. */ -constexpr int CHIP_SWIMLANE_NUM_QUEUE_SHAPES = 3; - -/** - * AICPU scheduler phase record (64 bytes). - * - * Position in the per-thread buffer is the identity — no thread_id field. - * - * phase_data is tagged by kind: Dispatch uses its ready-queue counters and - * DummyTask and PredicatedSkip use the local/ring components of the full task - * id. Other kinds store zero in the Dispatch view. - * - * 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 ChipSwimlaneAicpuSchedPhaseRecord { - 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 - ChipSwimlaneSchedPhaseKind kind; // see enum above - uint32_t tasks_processed; // Tasks processed in this phase batch - union { - struct { - uint32_t pop_hit; // Ready-queue hit delta since the previous Dispatch emit - uint32_t pop_miss; // Ready-queue miss delta since the previous Dispatch emit - } dispatch; - struct { - uint32_t local_id; // task_id bits [31:0] - uint32_t ring_id; // task_id bits [63:32] - } dummy_task; - struct { - uint32_t local_id; // outer Graph task_id bits [31:0] - uint32_t ring_id; // outer Graph task_id bits [63:32] - } graph_task; - } phase_data; - int16_t shared_depth_at_start[CHIP_SWIMLANE_NUM_QUEUE_SHAPES]; // sched->ready_queues[shape].size() - int16_t shared_depth_at_end[CHIP_SWIMLANE_NUM_QUEUE_SHAPES]; - uint32_t _pad[4]; // 64B alignment padding -}; -static_assert( - sizeof(decltype(ChipSwimlaneAicpuSchedPhaseRecord::phase_data)) == 8, - "ChipSwimlaneAicpuSchedPhaseRecord phase data must remain 8 bytes" -); -static_assert( - offsetof(ChipSwimlaneAicpuSchedPhaseRecord, phase_data) == 28, - "ChipSwimlaneAicpuSchedPhaseRecord phase data offset drift" -); -static_assert(sizeof(ChipSwimlaneAicpuSchedPhaseRecord) == 64, "ChipSwimlaneAicpuSchedPhaseRecord layout drift"); - /** * AICPU orchestrator phase record (32 bytes). * diff --git a/src/common/platform/include/common/host_api.h b/src/common/platform/include/common/host_api.h index 1338560963..b573d44dbe 100644 --- a/src/common/platform/include/common/host_api.h +++ b/src/common/platform/include/common/host_api.h @@ -13,6 +13,8 @@ #include #include +#include "common/chip_swimlane_extension.h" + /** * Host API function pointers for device memory operations. * Allows a runtime to use pluggable device-memory backends. @@ -145,6 +147,9 @@ struct HostApiOps { uint32_t (*get_chip_swimlane_level)(void *runner_ctx); void *(*host_phase_pool_arm)(void *runner_ctx, int producer_wants_records); void (*host_phase_pool_finish)(void *runner_ctx, uint64_t submitted_tasks, uint64_t invocation_id); + bool (*publish_chip_swimlane_extension)( + void *runner_ctx, ChipSwimlaneExtensionSection section, const char *json_value, size_t json_size + ); }; /** @@ -253,6 +258,18 @@ struct HostApi { ops_->host_phase_pool_finish(runner_ctx_, submitted_tasks, invocation_id); } } + bool publish_chip_swimlane_extension( + ChipSwimlaneExtensionSection section, const char *json_value, size_t json_size + ) const noexcept { + if (ops_->publish_chip_swimlane_extension == nullptr || !chip_swimlane_extension_section_is_valid(section) || + json_value == nullptr) + return false; + try { + return ops_->publish_chip_swimlane_extension(runner_ctx_, section, json_value, json_size); + } catch (...) { + return false; + } + } private: void *runner_ctx_{nullptr}; diff --git a/src/common/platform/include/host/chip_swimlane_collector.h b/src/common/platform/include/host/chip_swimlane_collector.h index 3c5076f0ff..189108f0c9 100644 --- a/src/common/platform/include/host/chip_swimlane_collector.h +++ b/src/common/platform/include/host/chip_swimlane_collector.h @@ -25,12 +25,14 @@ #pragma once +#include #include #include #include #include #include +#include "common/chip_swimlane_extension.h" #include "common/chip_swimlane_profiling.h" #include "host/clock_correlation.h" #include "common/memory_barrier.h" @@ -399,6 +401,8 @@ class ChipSwimlaneCollector : public profiling_common::ProfilerBase/chip_swimlane_records.json. std::string output_prefix_; + std::array(ChipSwimlaneExtensionSection::Count)> json_extensions_{}; // Merged data, populated from per-collector shards after collector threads join. std::vector> collected_perf_records_; diff --git a/src/common/platform/include/host/scheduler_profiling_json.h b/src/common/platform/include/host/scheduler_profiling_json.h new file mode 100644 index 0000000000..c53d6c9604 --- /dev/null +++ b/src/common/platform/include/host/scheduler_profiling_json.h @@ -0,0 +1,114 @@ +/* + * Copyright (c) PyPTO Contributors. + * This program is free software, you can redistribute it and/or modify it under the terms and conditions of + * CANN Open Software License Agreement Version 2.0 (the "License"). + * Please refer to the License for details. You may not use this file except in compliance with the License. + * THIS SOFTWARE IS PROVIDED ON AN "AS IS" BASIS, WITHOUT WARRANTIES OF ANY KIND, EITHER EXPRESS OR IMPLIED, + * INCLUDING BUT NOT LIMITED TO NON-INFRINGEMENT, MERCHANTABILITY, OR FITNESS FOR A PARTICULAR PURPOSE. + * See LICENSE in the root of the software repository for the full text of the License. + * ----------------------------------------------------------------------------------------------------------- + */ + +#pragma once + +#include +#include +#include +#include +#include + +#include "common/scheduler_profiling.h" + +inline const char *chip_swimlane_scheduler_kind_name(ChipSwimlaneSchedPhaseKind kind) { + switch (kind) { + case ChipSwimlaneSchedPhaseKind::Complete: + return "complete"; + case ChipSwimlaneSchedPhaseKind::Dispatch: + return "dispatch"; + case ChipSwimlaneSchedPhaseKind::Release: + return "release"; + case ChipSwimlaneSchedPhaseKind::Dummy: + return "dummy"; + case ChipSwimlaneSchedPhaseKind::EarlyDispatch: + return "early_dispatch"; + case ChipSwimlaneSchedPhaseKind::Resolve: + return "resolve"; + case ChipSwimlaneSchedPhaseKind::ResolveStandalone: + return "resolve_standalone"; + case ChipSwimlaneSchedPhaseKind::DummyTask: + return "dummy_task"; + case ChipSwimlaneSchedPhaseKind::PredicatedSkip: + return "predicated_skip"; + case ChipSwimlaneSchedPhaseKind::Drain: + return "drain"; + case ChipSwimlaneSchedPhaseKind::DrainPrepare: + return "drain_prepare"; + case ChipSwimlaneSchedPhaseKind::DrainPublish: + return "drain_publish"; + case ChipSwimlaneSchedPhaseKind::AsyncPoll: + return "async_poll"; + case ChipSwimlaneSchedPhaseKind::GraphPrepare: + return "graph_prepare"; + } + return "unknown"; +} + +inline void chip_swimlane_write_scheduler_records( + std::ostream &out, const std::vector> &streams, + const std::vector &dropped_records, const std::string &runtime_name +) { + out << "{\n \"schema_version\": 1,\n \"streams\": ["; + bool first_stream = true; + for (size_t stream_index = 0; stream_index < streams.size(); ++stream_index) { + const auto &records = streams[stream_index]; + if (records.empty()) continue; + const uint32_t dropped = stream_index < dropped_records.size() ? dropped_records[stream_index] : 0; + if (!first_stream) out << ","; + out << "\n {\"platform\": \"" << CHIP_SWIMLANE_ARCHITECTURE_NAME << "\", \"runtime\": \"" << runtime_name + << "\", \"producer\": \"aicpu\", \"scheduler_id\": " << stream_index << ", \"worker_id\": " << stream_index + << ", \"core_type\": \"aicpu\", \"physical_core_id\": null, \"capture\": {\"committed\": " << records.size() + << ", \"dropped\": " << dropped << ", \"truncated\": " << (dropped == 0 ? "false" : "true") + << "}, \"records\": ["; + for (size_t record_index = 0; record_index < records.size(); ++record_index) { + const auto &record = records[record_index]; + if (record_index != 0) out << ","; + out << "\n {\"start_cycles\": " << record.start_time << ", \"end_cycles\": " << record.end_time + << ", \"loop_iter\": " << record.loop_iter << ", \"kind\": \"" + << chip_swimlane_scheduler_kind_name(record.kind) + << "\", \"tasks_processed\": " << record.tasks_processed << ", \"task_id\": "; + if (record.kind == ChipSwimlaneSchedPhaseKind::DummyTask || + record.kind == ChipSwimlaneSchedPhaseKind::PredicatedSkip) { + out + << ((static_cast(record.phase_data.dummy_task.ring_id) << 32) | + record.phase_data.dummy_task.local_id); + } else if (record.kind == ChipSwimlaneSchedPhaseKind::GraphPrepare) { + out + << ((static_cast(record.phase_data.graph_task.ring_id) << 32) | + record.phase_data.graph_task.local_id); + } else { + out << "null"; + } + out << "}"; + } + if (!records.empty()) out << "\n "; + out << "], \"metrics\": ["; + for (size_t record_index = 0; record_index < records.size(); ++record_index) { + const auto &record = records[record_index]; + if (record_index != 0) out << ","; + out << "\n {\"record_index\": " << record_index; + if (record.kind == ChipSwimlaneSchedPhaseKind::Dispatch) { + out << ", \"pop_hit\": " << record.phase_data.dispatch.pop_hit + << ", \"pop_miss\": " << record.phase_data.dispatch.pop_miss; + } + out << ", \"shared_at_start\": [" << record.shared_depth_at_start[0] << "," + << record.shared_depth_at_start[1] << "," << record.shared_depth_at_start[2] + << "], \"shared_at_end\": [" << record.shared_depth_at_end[0] << "," << record.shared_depth_at_end[1] + << "," << record.shared_depth_at_end[2] << "]}"; + } + if (!records.empty()) out << "\n "; + out << "]}"; + first_stream = false; + } + if (!first_stream) out << "\n "; + out << "]\n }"; +} diff --git a/src/common/platform/onboard/host/c_api_shared.cpp b/src/common/platform/onboard/host/c_api_shared.cpp index 0ad2827ab3..ae8acedbe1 100644 --- a/src/common/platform/onboard/host/c_api_shared.cpp +++ b/src/common/platform/onboard/host/c_api_shared.cpp @@ -206,6 +206,13 @@ static uint32_t get_chip_swimlane_level(void *runner_ctx) { return static_cast(runner_ctx)->chip_swimlane_level(); } +static bool publish_chip_swimlane_extension( + void *runner_ctx, ChipSwimlaneExtensionSection section, const char *json_value, size_t json_size +) { + return runner_ctx != nullptr && + static_cast(runner_ctx)->publish_chip_swimlane_extension(section, json_value, json_size); +} + static void *host_phase_pool_arm(void *runner_ctx, int producer_wants_records) { if (runner_ctx == nullptr) return nullptr; return static_cast(runner_ctx)->host_phase_pool_arm(producer_wants_records != 0); @@ -317,6 +324,7 @@ static const HostApiOps g_host_api_ops = { .get_chip_swimlane_level = get_chip_swimlane_level, .host_phase_pool_arm = host_phase_pool_arm, .host_phase_pool_finish = host_phase_pool_finish, + .publish_chip_swimlane_extension = publish_chip_swimlane_extension, }; /* =========================================================================== diff --git a/src/common/platform/onboard/host/device_runner_base.h b/src/common/platform/onboard/host/device_runner_base.h index 71ebf5d6d0..78821a82ff 100644 --- a/src/common/platform/onboard/host/device_runner_base.h +++ b/src/common/platform/onboard/host/device_runner_base.h @@ -733,6 +733,11 @@ class DeviceRunnerBase { enable_chip_swimlane_ = (chip_swimlane_level_ != ChipSwimlaneLevel::DISABLED); } uint32_t chip_swimlane_level() const { return static_cast(chip_swimlane_level_); } + bool + publish_chip_swimlane_extension(ChipSwimlaneExtensionSection section, const char *json_value, size_t json_size) { + return json_value != nullptr && + chip_swimlane_collector_.set_json_extension(section, std::string(json_value, json_size)); + } HostPhaseRecordPool *host_phase_pool_arm(bool producer_wants_records) noexcept; void host_phase_pool_finish(uint64_t submitted_tasks, uint64_t invocation_id) noexcept { host_phase_records_.finish(submitted_tasks, invocation_id); diff --git a/src/common/platform/shared/host/chip_swimlane_collector.cpp b/src/common/platform/shared/host/chip_swimlane_collector.cpp index 859c82461f..7bd8640420 100644 --- a/src/common/platform/shared/host/chip_swimlane_collector.cpp +++ b/src/common/platform/shared/host/chip_swimlane_collector.cpp @@ -20,6 +20,7 @@ #include "host/chip_swimlane_collector.h" +#include #include #include #include @@ -36,8 +37,13 @@ #include "common/memory_barrier.h" #include "common/unified_log.h" #include "host/profiling_copy.h" +#include "host/scheduler_profiling_json.h" #include "../../../worker/runtime_c_api.h" +#ifndef SIMPLER_RUNTIME_NAME +#error "SIMPLER_RUNTIME_NAME must be defined by RuntimeBuilder" +#endif + // ============================================================================= // ChipSwimlaneCollector Implementation // ============================================================================= @@ -94,6 +100,14 @@ ChipSwimlaneCollector::~ChipSwimlaneCollector() { } } +bool ChipSwimlaneCollector::set_json_extension(ChipSwimlaneExtensionSection section, const std::string &json_value) { + if (!chip_swimlane_extension_has_expected_root(section, json_value)) return false; + std::string &slot = json_extensions_[static_cast(section)]; + if (!slot.empty()) return false; + slot = json_value; + return true; +} + int ChipSwimlaneCollector::initialize( int num_aicore, int aicpu_thread_num, int device_id, const ChipSwimlaneAllocCallback &alloc_cb, ChipSwimlaneRegisterCallback register_cb, const ChipSwimlaneFreeCallback &free_cb @@ -133,6 +147,7 @@ int ChipSwimlaneCollector::initialize( total_orch_phase_collected_ = 0; has_phase_data_ = false; collector_shards_merged_ = false; + json_extensions_.fill({}); // Stash the memory context on the base up-front so alloc_paired_buffer // sees consistent values during init. shm_host_ stays nullptr until the @@ -942,11 +957,23 @@ int ChipSwimlaneCollector::export_swimlane_json() { } merge_collector_shards(); + auto extension = [this](ChipSwimlaneExtensionSection section) -> const std::string * { + const std::string &value = json_extensions_[static_cast(section)]; + return value.empty() ? nullptr : &value; + }; + const std::string *scheduler_extension = extension(ChipSwimlaneExtensionSection::SchedulerRecords); + const std::string *aicore_tasks_extension = extension(ChipSwimlaneExtensionSection::AicoreTasks); + const std::string *scheduler_tasks_extension = extension(ChipSwimlaneExtensionSection::SchedulerTasks); + const std::string *aicpu_lifecycle_extension = extension(ChipSwimlaneExtensionSection::AicpuLifecycleRecords); + // Every stream is independently useful for DFX. In particular, a legal // HBG can contain only host-side dummy/hidden-allocation records and no // AICore dispatch at all. - bool has_any_records = - !host_submit_records_.empty() || !host_upload_records_.empty() || clock_correlation_session_.started(); + bool has_any_records = !host_submit_records_.empty() || !host_upload_records_.empty() || + clock_correlation_session_.started() || + std::any_of(json_extensions_.begin(), json_extensions_.end(), [](const auto &value) { + return !value.empty(); + }); for (const auto &core_records : collected_perf_records_) { if (!core_records.empty()) { has_any_records = true; @@ -968,6 +995,18 @@ int ChipSwimlaneCollector::export_swimlane_json() { return false; }; const bool has_aicpu_orch_phases = any_phase_records(collected_orch_phase_records_); + const bool has_aicpu_scheduler_records = any_phase_records(collected_sched_phase_records_); + if (scheduler_extension != nullptr && has_aicpu_scheduler_records) { + LOG_ERROR("Both runtime and AICPU scheduler records are present; refusing ambiguous export"); + return PTO_RUNTIME_ERR_INTERNAL; + } + const bool has_aicore_tasks = any_phase_records(collected_aicore_records_); + const bool has_platform_scheduler_tasks = any_phase_records(collected_perf_records_); + if ((aicore_tasks_extension != nullptr && has_aicore_tasks) || + (scheduler_tasks_extension != nullptr && has_platform_scheduler_tasks)) { + LOG_ERROR("Both runtime and platform task records are present; refusing ambiguous export"); + return PTO_RUNTIME_ERR_INTERNAL; + } has_any_records = has_any_records || any_phase_records(collected_sched_phase_records_) || has_aicpu_orch_phases; if (!has_any_records) { LOG_WARN("Warning: No performance data to export."); @@ -1127,121 +1166,68 @@ int ChipSwimlaneCollector::export_swimlane_json() { // of swimlane_converter.py's v2 reader. // // aicore_tasks: [core_id, task_token_raw, reg_task_id, start_cycles, end_cycles, receive_to_start_cycles] - // aicpu_tasks: [core_id, reg_task_id, dispatch_cycles, finish_cycles] + // scheduler_tasks.records: [core_id, reg_task_id, dispatch_cycles, finish_cycles] { // copy_aicore_buffer already drops r.start_time == 0 slots when // collecting from the device side, so no defensive filter here. - outfile << " \"aicore_tasks\": ["; - bool first = true; - size_t total = 0; - for (size_t core_idx = 0; core_idx < collected_aicore_records_.size(); core_idx++) { - for (const auto &r : collected_aicore_records_[core_idx]) { - if (!first) outfile << ","; - outfile << "\n [" << core_idx << ", " << r.task_token_raw << ", " << r.reg_task_id << ", " - << r.start_time << ", " << r.end_time << ", " << r.receive_to_start_cycles << "]"; - first = false; - total++; + outfile << " \"aicore_tasks\": "; + if (aicore_tasks_extension != nullptr) { + outfile << *aicore_tasks_extension; + } else { + outfile << "["; + bool first = true; + size_t total = 0; + for (size_t core_idx = 0; core_idx < collected_aicore_records_.size(); core_idx++) { + for (const auto &r : collected_aicore_records_[core_idx]) { + if (!first) outfile << ","; + outfile << "\n [" << core_idx << ", " << r.task_token_raw << ", " << r.reg_task_id << ", " + << r.start_time << ", " << r.end_time << ", " << r.receive_to_start_cycles << "]"; + first = false; + total++; + } } + if (!first) outfile << "\n "; + outfile << "]"; + LOG_INFO(" aicore_tasks: %zu records", total); } - if (!first) outfile << "\n "; - outfile << "]"; - LOG_INFO(" aicore_tasks: %zu records", total); } - { - outfile << ",\n \"aicpu_tasks\": ["; - bool first = true; - size_t total = 0; - for (size_t core_idx = 0; core_idx < collected_perf_records_.size(); core_idx++) { - for (const auto &r : collected_perf_records_[core_idx]) { - if (!first) outfile << ","; - outfile << "\n [" << core_idx << ", " << r.reg_task_id << ", " << r.dispatch_time << ", " - << r.finish_time << "]"; - first = false; - total++; + if (chip_swimlane_level_ >= ChipSwimlaneLevel::SCHEDULE_TIMING) { + outfile << ",\n \"scheduler_tasks\": "; + if (scheduler_tasks_extension != nullptr) { + outfile << *scheduler_tasks_extension; + } else { + outfile << "{\n \"schema_version\": 1,\n \"producer\": \"aicpu\",\n \"records\": ["; + bool first = true; + size_t total = 0; + for (size_t core_idx = 0; core_idx < collected_perf_records_.size(); core_idx++) { + for (const auto &r : collected_perf_records_[core_idx]) { + if (!first) outfile << ","; + outfile << "\n [" << core_idx << ", " << r.reg_task_id << ", " << r.dispatch_time << ", " + << r.finish_time << "]"; + first = false; + total++; + } } + if (!first) outfile << "\n "; + outfile << "]\n }"; + LOG_INFO(" scheduler_tasks: %zu AICPU records", total); } - if (!first) outfile << "\n "; - outfile << "]"; - LOG_INFO(" aicpu_tasks: %zu records", total); } - // Phase records keep their per-thread sub-array shape so the python - // consumer's existing iteration pattern (one thread per inner list) stays - // unchanged; only the field names move from *_us to *_cycles. if (chip_swimlane_level_ >= ChipSwimlaneLevel::SCHED_PHASES) { - auto sched_phase_name = [](ChipSwimlaneSchedPhaseKind kind) -> const char * { - switch (kind) { - case ChipSwimlaneSchedPhaseKind::Complete: - return "complete"; - case ChipSwimlaneSchedPhaseKind::Dispatch: - return "dispatch"; - case ChipSwimlaneSchedPhaseKind::Release: - return "release"; - case ChipSwimlaneSchedPhaseKind::Dummy: - return "dummy"; - case ChipSwimlaneSchedPhaseKind::EarlyDispatch: - return "early_dispatch"; - case ChipSwimlaneSchedPhaseKind::Resolve: - return "resolve"; - case ChipSwimlaneSchedPhaseKind::ResolveStandalone: - return "resolve_standalone"; - case ChipSwimlaneSchedPhaseKind::DummyTask: - return "dummy_task"; - case ChipSwimlaneSchedPhaseKind::PredicatedSkip: - return "predicated_skip"; - case ChipSwimlaneSchedPhaseKind::Drain: - return "drain"; - case ChipSwimlaneSchedPhaseKind::DrainPrepare: - return "drain_prepare"; - case ChipSwimlaneSchedPhaseKind::DrainPublish: - return "drain_publish"; - case ChipSwimlaneSchedPhaseKind::AsyncPoll: - return "async_poll"; - case ChipSwimlaneSchedPhaseKind::GraphPrepare: - return "graph_prepare"; - } - return "unknown"; - }; - - auto emit_depth_array = [&outfile](const char *key, const int16_t arr[CHIP_SWIMLANE_NUM_QUEUE_SHAPES]) { - outfile << ", \"" << key << "\": [" << arr[0] << "," << arr[1] << "," << arr[2] << "]"; - }; - outfile << ",\n \"aicpu_scheduler_phases\": [\n"; - for (size_t t = 0; t < collected_sched_phase_records_.size(); t++) { - outfile << " ["; - bool first = true; - for (const auto &pr : collected_sched_phase_records_[t]) { - if (!first) outfile << ","; - outfile << "\n {\"kind\": \"" << sched_phase_name(pr.kind) << "\"" - << ", \"start_cycles\": " << pr.start_time << ", \"end_cycles\": " << pr.end_time - << ", \"loop_iter\": " << pr.loop_iter << ", \"tasks_processed\": " << pr.tasks_processed; - if (pr.kind == ChipSwimlaneSchedPhaseKind::Dispatch) { - outfile << ", \"pop_hit\": " << pr.phase_data.dispatch.pop_hit - << ", \"pop_miss\": " << pr.phase_data.dispatch.pop_miss; - } - if (pr.kind == ChipSwimlaneSchedPhaseKind::DummyTask || - pr.kind == ChipSwimlaneSchedPhaseKind::PredicatedSkip) { - uint64_t task_id = (static_cast(pr.phase_data.dummy_task.ring_id) << 32) | - pr.phase_data.dummy_task.local_id; - outfile << ", \"task_id\": " << task_id; - } - if (pr.kind == ChipSwimlaneSchedPhaseKind::GraphPrepare) { - uint64_t task_id = (static_cast(pr.phase_data.graph_task.ring_id) << 32) | - pr.phase_data.graph_task.local_id; - outfile << ", \"task_id\": " << task_id; - } - // Queue-depth snapshots — [AIC, AIV, MIX] per ChipSwimlaneAicpuSchedPhaseRecord docstring. - emit_depth_array("shared_at_start", pr.shared_depth_at_start); - emit_depth_array("shared_at_end", pr.shared_depth_at_end); - outfile << "}"; - first = false; + outfile << ",\n \"scheduler_records\": "; + if (scheduler_extension != nullptr) { + outfile << *scheduler_extension; + } else { + std::vector dropped_records(collected_sched_phase_records_.size()); + for (size_t t = 0; t < collected_sched_phase_records_.size(); ++t) { + const auto *pool = get_sched_phase_buffer_state(shm_host_, static_cast(t)); + dropped_records[t] = pool->head.dropped_record_count; } - if (!first) outfile << "\n "; - outfile << "]"; - if (t < collected_sched_phase_records_.size() - 1) outfile << ","; - outfile << "\n"; + chip_swimlane_write_scheduler_records( + outfile, collected_sched_phase_records_, dropped_records, SIMPLER_RUNTIME_NAME + ); } - outfile << " ]"; if (has_aicpu_orch_phases) { size_t orch_lanes = static_cast(get_chip_swimlane_header(shm_host_)->num_orch_phase_threads); @@ -1292,6 +1278,9 @@ int ChipSwimlaneCollector::export_swimlane_json() { } } + if (aicpu_lifecycle_extension != nullptr) + outfile << ",\n \"aicpu_lifecycle_records\": " << *aicpu_lifecycle_extension; + outfile << "\n}\n"; outfile.close(); @@ -1438,6 +1427,7 @@ int ChipSwimlaneCollector::finalize( host_phase_total_records_ = 0; host_phase_dropped_records_ = 0; host_phase_submitted_tasks_ = 0; + json_extensions_.fill({}); clear_memory_context(); LOG_DEBUG("Performance profiling cleanup complete"); diff --git a/src/common/platform/sim/host/c_api_shared.cpp b/src/common/platform/sim/host/c_api_shared.cpp index 6c79eab6a9..03578575a9 100644 --- a/src/common/platform/sim/host/c_api_shared.cpp +++ b/src/common/platform/sim/host/c_api_shared.cpp @@ -190,6 +190,13 @@ static uint32_t get_chip_swimlane_level(void *runner_ctx) { return static_cast(runner_ctx)->chip_swimlane_level(); } +static bool publish_chip_swimlane_extension( + void *runner_ctx, ChipSwimlaneExtensionSection section, const char *json_value, size_t json_size +) { + return runner_ctx != nullptr && static_cast(runner_ctx) + ->publish_chip_swimlane_extension(section, json_value, json_size); +} + static void *host_phase_pool_arm(void *runner_ctx, int producer_wants_records) { if (runner_ctx == nullptr) return nullptr; return static_cast(runner_ctx)->host_phase_pool_arm(producer_wants_records != 0); @@ -302,6 +309,7 @@ static const HostApiOps g_host_api_ops = { .get_chip_swimlane_level = get_chip_swimlane_level, .host_phase_pool_arm = host_phase_pool_arm, .host_phase_pool_finish = host_phase_pool_finish, + .publish_chip_swimlane_extension = publish_chip_swimlane_extension, }; /* =========================================================================== diff --git a/src/common/platform/sim/host/device_runner_base.h b/src/common/platform/sim/host/device_runner_base.h index 7d677f719b..2377adecbd 100644 --- a/src/common/platform/sim/host/device_runner_base.h +++ b/src/common/platform/sim/host/device_runner_base.h @@ -273,6 +273,11 @@ class SimDeviceRunnerBase { enable_chip_swimlane_ = (chip_swimlane_level_ != ChipSwimlaneLevel::DISABLED); } uint32_t chip_swimlane_level() const { return static_cast(chip_swimlane_level_); } + bool + publish_chip_swimlane_extension(ChipSwimlaneExtensionSection section, const char *json_value, size_t json_size) { + return json_value != nullptr && + chip_swimlane_collector_.set_json_extension(section, std::string(json_value, json_size)); + } HostPhaseRecordPool *host_phase_pool_arm(bool producer_wants_records) noexcept; void host_phase_pool_finish(uint64_t submitted_tasks, uint64_t invocation_id) noexcept { host_phase_records_.finish(submitted_tasks, invocation_id); diff --git a/tests/st/a2a3/tensormap_and_ringbuffer/dfx/chip_swimlane/_swimlane_validate.py b/tests/st/a2a3/tensormap_and_ringbuffer/dfx/chip_swimlane/_swimlane_validate.py index e2e4cbbf81..16fe785b76 100644 --- a/tests/st/a2a3/tensormap_and_ringbuffer/dfx/chip_swimlane/_swimlane_validate.py +++ b/tests/st/a2a3/tensormap_and_ringbuffer/dfx/chip_swimlane/_swimlane_validate.py @@ -39,7 +39,7 @@ "start_time_us", "end_time_us", # receive_time_us / local_setup_us are populated unconditionally by the - # AICore-side capture (v3 schema). propagation_us requires AICPU dispatch_ts + # AICore-side capture (v3 schema). propagation_us requires Scheduler dispatch_ts # and is therefore only present at level≥2 — not in this required-set. "receive_time_us", "local_setup_us", @@ -68,15 +68,19 @@ def validate_perf_artifact(case_label: str, *, since: float, expected_task_count out_dir = max(matches, key=lambda p: p.stat().st_mtime) perf = out_dir / "chip_swimlane_records.json" assert perf.exists(), f"chip_swimlane_records.json missing under {out_dir} — swimlane capture failed?" + raw = json.loads(perf.read_text()) # Read via the swimlane_converter loader so v2 host JSON gets joined into # the v1-shaped dict the rest of this validator (and the differential # oracle below) expects. Direct json.load(perf) would see only raw - # aicore_tasks / aicpu_tasks arrays under v2. + # aicore_tasks / scheduler_tasks raw streams. data = read_perf_data(perf) - assert data.get("chip_swimlane_level") in (1, 2, 3, 4), ( - f"unexpected chip_swimlane_level: {data.get('chip_swimlane_level')}" - ) + level = data.get("chip_swimlane_level") + assert level in (1, 2, 3, 4), f"unexpected chip_swimlane_level: {level}" + if level >= 2: + assert data.get("scheduler_task_producer") == "aicpu" + assert raw["scheduler_tasks"]["schema_version"] == 1 + assert raw["scheduler_tasks"]["producer"] == "aicpu" tasks = data.get("tasks") assert isinstance(tasks, list), "tasks field missing or not a list" assert len(tasks) > 0, f"perf records empty under {perf}" diff --git a/tests/st/a5/tensormap_and_ringbuffer/dfx/chip_swimlane/_swimlane_validate.py b/tests/st/a5/tensormap_and_ringbuffer/dfx/chip_swimlane/_swimlane_validate.py index 7d2766fbe6..7f0ea0b0cf 100644 --- a/tests/st/a5/tensormap_and_ringbuffer/dfx/chip_swimlane/_swimlane_validate.py +++ b/tests/st/a5/tensormap_and_ringbuffer/dfx/chip_swimlane/_swimlane_validate.py @@ -39,7 +39,7 @@ "start_time_us", "end_time_us", # receive_time_us / local_setup_us are populated unconditionally by the - # AICore-side capture (v3 schema). propagation_us requires AICPU dispatch_ts + # AICore-side capture (v3 schema). propagation_us requires Scheduler dispatch_ts # and is therefore only present at level≥2 — not in this required-set. "receive_time_us", "local_setup_us", @@ -80,15 +80,19 @@ def validate_perf_artifact( out_dir = max(matches, key=lambda p: p.stat().st_mtime) perf = out_dir / "chip_swimlane_records.json" assert perf.exists(), f"chip_swimlane_records.json missing under {out_dir} — swimlane capture failed?" + raw = json.loads(perf.read_text()) # Read via the swimlane_converter loader so v2 host JSON gets joined into # the v1-shaped dict the rest of this validator (and the differential # oracle below) expects. Direct json.load(perf) would see only raw - # aicore_tasks / aicpu_tasks arrays under v2. + # aicore_tasks / scheduler_tasks raw streams. data = read_perf_data(perf) - assert data.get("chip_swimlane_level") in (1, 2, 3, 4), ( - f"unexpected chip_swimlane_level: {data.get('chip_swimlane_level')}" - ) + level = data.get("chip_swimlane_level") + assert level in (1, 2, 3, 4), f"unexpected chip_swimlane_level: {level}" + if level >= 2: + assert data.get("scheduler_task_producer") == "aicpu" + assert raw["scheduler_tasks"]["schema_version"] == 1 + assert raw["scheduler_tasks"]["producer"] == "aicpu" tasks = data.get("tasks") assert isinstance(tasks, list), "tasks field missing or not a list" assert len(tasks) > 0, f"perf records empty under {perf}" diff --git a/tests/ut/cpp/common/test_host_api.cpp b/tests/ut/cpp/common/test_host_api.cpp index a6c37c7c2e..861bdf52c6 100644 --- a/tests/ut/cpp/common/test_host_api.cpp +++ b/tests/ut/cpp/common/test_host_api.cpp @@ -15,10 +15,12 @@ #include #include #include +#include #include #include #include "common/host_api.h" +#include "common/chip_swimlane_extension.h" namespace { @@ -83,6 +85,10 @@ bool all_equal(const std::vector &values, uint32_t expected) { }); } +bool throwing_extension_callback(void *, ChipSwimlaneExtensionSection, const char *, size_t) { + throw std::runtime_error("publication failed"); +} + } // namespace TEST(HostApiTest, BoundRunnerSlotAndBankSurviveConcurrentCrossThreadCalls) { @@ -125,3 +131,28 @@ TEST(HostApiTest, BoundRunnerSlotAndBankSurviveConcurrentCrossThreadCalls) { EXPECT_TRUE(all_equal(runner_b.pipeline_slots, kRunnerBSlot)); EXPECT_TRUE(all_equal(runner_b.arena_banks, kRunnerBBank)); } + +TEST(HostApiTest, PublicationExceptionsBecomeFailureResults) { + HostApiOps ops{}; + ops.publish_chip_swimlane_extension = throwing_extension_callback; + const HostApi api(nullptr, 0, 0, &ops); + + EXPECT_FALSE(api.publish_chip_swimlane_extension(ChipSwimlaneExtensionSection::SchedulerRecords, "{}", 2)); +} + +TEST(ChipSwimlaneExtensionTest, ExposesOnlyFixedSectionNamesAndShapes) { + EXPECT_STREQ( + chip_swimlane_extension_section_name(ChipSwimlaneExtensionSection::SchedulerRecords), "scheduler_records" + ); + EXPECT_STREQ(chip_swimlane_extension_section_name(ChipSwimlaneExtensionSection::SchedulerTasks), "scheduler_tasks"); + EXPECT_TRUE(chip_swimlane_extension_section_is_object(ChipSwimlaneExtensionSection::SchedulerTasks)); + EXPECT_TRUE(chip_swimlane_extension_section_is_object(ChipSwimlaneExtensionSection::SchedulerRecords)); + EXPECT_FALSE(chip_swimlane_extension_section_is_object(ChipSwimlaneExtensionSection::AicoreTasks)); + EXPECT_FALSE(chip_swimlane_extension_section_is_valid(ChipSwimlaneExtensionSection::Count)); + EXPECT_EQ(chip_swimlane_extension_section_name(ChipSwimlaneExtensionSection::Count), nullptr); + EXPECT_TRUE(chip_swimlane_extension_has_expected_root(ChipSwimlaneExtensionSection::SchedulerRecords, " {} ")); + EXPECT_TRUE(chip_swimlane_extension_has_expected_root(ChipSwimlaneExtensionSection::SchedulerTasks, " {} ")); + EXPECT_TRUE(chip_swimlane_extension_has_expected_root(ChipSwimlaneExtensionSection::AicoreTasks, " [] ")); + EXPECT_FALSE(chip_swimlane_extension_has_expected_root(ChipSwimlaneExtensionSection::SchedulerRecords, "[]")); + EXPECT_FALSE(chip_swimlane_extension_has_expected_root(ChipSwimlaneExtensionSection::AicoreTasks, "{}")); +} diff --git a/tests/ut/py/test_runtime_builder.py b/tests/ut/py/test_runtime_builder.py index 8d73e280a7..84b9cd3a8f 100644 --- a/tests/ut/py/test_runtime_builder.py +++ b/tests/ut/py/test_runtime_builder.py @@ -397,7 +397,10 @@ def test_calls_compiler_three_times(self, MockCompiler, tmp_path, default_test_p "SIMPLER_TENSORMAP_PROFILING": "0", } for call in mock_instance.compile.call_args_list: - assert call.kwargs["cmake_defines"] == expected_defaults + expected = dict(expected_defaults) + if call.args[0] == "host": + expected["SIMPLER_RUNTIME_NAME"] = "test_rt" + assert call.kwargs["cmake_defines"] == expected @patch("simpler_setup.runtime_builder.RuntimeCompiler") def test_reuses_prebuilt_shared_libraries(self, MockCompiler, tmp_path, default_test_platform, test_arch): @@ -434,7 +437,10 @@ def test_passes_profiling_config_to_every_target(self, MockCompiler, tmp_path, d assert mock_instance.compile.call_count == 3 for call in mock_instance.compile.call_args_list: - assert call.kwargs["cmake_defines"] == config + expected = dict(config) + if call.args[0] == "host": + expected["SIMPLER_RUNTIME_NAME"] = "test_rt" + assert call.kwargs["cmake_defines"] == expected @patch("simpler_setup.runtime_builder.RuntimeCompiler") def test_resolves_paths_relative_to_config(self, MockCompiler, tmp_path, default_test_platform, test_arch): @@ -527,6 +533,7 @@ def test_a2a3_onboard_host_build_passes_pto_isa_cmake_define(self, MockCompiler, **profiling, "PTO_ISA_ROOT": "/tmp/pto-isa", "SIMPLER_PTO_ISA_BUILD_COMMIT": pin, + "SIMPLER_RUNTIME_NAME": "test_rt", } # aicore needs the checkout path too, for the SDMA warmup kernel's # vector-only target, but not the commit stamp (that keys the host ccache). diff --git a/tests/ut/py/test_sched_overhead_analysis.py b/tests/ut/py/test_sched_overhead_analysis.py index d838ba7150..35cd8669ee 100644 --- a/tests/ut/py/test_sched_overhead_analysis.py +++ b/tests/ut/py/test_sched_overhead_analysis.py @@ -22,6 +22,7 @@ parse_scheduler_from_json_phases, per_id_timing, print_distribution, + run_analysis, ) @@ -37,6 +38,71 @@ def _task(core_id, dispatch, start, end, finish, core_type="aic"): } +def test_aicore_scheduler_runs_common_analysis_and_own_phase_breakdown(tmp_path, capsys): + perf_path = tmp_path / "chip_swimlane_records.json" + perf_path.write_text("{}") + deps_path = tmp_path / "deps.json" + deps_path.write_text('{"edges": []}') + task = _task(0, 1, 2, 4, 5) + task["task_id"] = 1 + data = { + "tasks": [task], + "scheduler_task_producer": "aicore", + "scheduler_records": [[{"phase": "ready_claim", "start_time_us": 1.0, "end_time_us": 1.5}]], + "scheduler_streams": [{"producer": "aicore", "capture": {"committed": 1, "dropped": 0, "truncated": False}}], + } + + assert run_analysis(perf_path, print_sources=False, perf_data=data, deps_json_path=deps_path) == 0 + output = capsys.readouterr().out + assert "Part 1: Overhead verdict" in output + assert "Part 3: Head OH" in output + assert "Part 4: Tail OH" in output + assert "Part 5: AICore scheduler phase breakdown" in output + assert "ready_claim" in output + assert "Part 6: Critical-path latency attribution" in output + assert "AICPU scheduler loop breakdown" not in output + + +def test_level_two_aicore_runs_common_analysis_without_phase_records(tmp_path, capsys): + perf_path = tmp_path / "chip_swimlane_records.json" + perf_path.write_text("{}") + deps_path = tmp_path / "deps.json" + deps_path.write_text('{"edges": []}') + task = _task(0, 1, 2, 4, 5) + task["task_id"] = 1 + data = { + "tasks": [task], + "scheduler_task_producer": "aicore", + } + + assert run_analysis(perf_path, print_sources=False, perf_data=data, deps_json_path=deps_path) == 0 + output = capsys.readouterr().out + assert "Part 1: Overhead verdict" in output + assert "Part 5: AICore scheduler phase breakdown" in output + assert "phase records unavailable at chip-swimlane Level 2" in output + assert "Part 6: Critical-path latency attribution" in output + + +def test_level_two_aicpu_runs_common_analysis_without_phase_records(tmp_path, capsys): + perf_path = tmp_path / "chip_swimlane_records.json" + perf_path.write_text("{}") + deps_path = tmp_path / "deps.json" + deps_path.write_text('{"edges": []}') + task = _task(0, 1, 2, 4, 5) + task["task_id"] = 1 + data = { + "tasks": [task], + "scheduler_task_producer": "aicpu", + } + + assert run_analysis(perf_path, print_sources=False, perf_data=data, deps_json_path=deps_path) == 0 + output = capsys.readouterr().out + assert "Part 1: Overhead verdict" in output + assert "Part 5: AICPU scheduler loop breakdown" in output + assert "phase records unavailable at chip-swimlane Level 2" in output + assert "Part 6: Critical-path latency attribution" in output + + def test_head_first_task_uses_start_minus_dispatch(): heads, tails = compute_head_tail([_task(0, 10, 12, 20, 22)]) assert heads == [2.0] # start - dispatch = 12 - 10 @@ -140,6 +206,17 @@ def test_critical_path_splits_exec_vs_scheduler(): assert cp["hops"] == 1 assert abs(cp["exec"] - 10.0) < 1e-6 # A 5 + B 5 assert abs(cp["sched"] - 2.0) < 1e-6 # B.start - A.end + assert cp["sched"] + cp["exec"] <= cp["span"] + + +def test_critical_path_span_includes_root_dispatch_head(): + tasks = [_gtask(1, 0, 1, 3, 8, 9)] + _ready, _gating, end_by_id, *_ = build_task_graph(tasks, {"edges": []}, 3.0) + dispatch, start, _end, finish = per_id_timing(tasks) + + cp = compute_critical_path({}, end_by_id, finish, start, dispatch, 3.0) + + assert cp == {"hops": 0, "span": 8.0, "sched": 2.0, "exec": 5.0} def test_print_distribution(capsys): diff --git a/tests/ut/py/test_swimlane_converter.py b/tests/ut/py/test_swimlane_converter.py index 2d7b1d5bfa..4d61d6dd28 100644 --- a/tests/ut/py/test_swimlane_converter.py +++ b/tests/ut/py/test_swimlane_converter.py @@ -372,7 +372,11 @@ def test_l3_directory_merge_rejects_different_or_missing_host_clock_domains(tmp_ sc._generate_l3_trace(args, root) -def test_task_statistics_level_one_hides_aicpu_metrics(capsys): +@pytest.mark.parametrize( + ("level", "description"), + [(1, "AICore timing only"), (3, "AICore + Scheduler task timing + scheduler phases")], +) +def test_task_statistics_without_scheduler_timestamps_hides_scheduler_metrics(capsys, level, description): tasks = [ { "task_id": 1, @@ -389,12 +393,12 @@ def test_task_statistics_level_one_hides_aicpu_metrics(capsys): } ] - sc.print_task_statistics(tasks, {"0": "kernel"}, chip_swimlane_level=1) + sc.print_task_statistics(tasks, {"0": "kernel"}, chip_swimlane_level=level) output = capsys.readouterr().out row = next(line for line in output.splitlines() if line.startswith("0 kernel")) total = next(line for line in output.splitlines() if line.startswith("TOTAL")) - assert "Source chip_swimlane_level: 1 (AICore timing only; recorded in chip_swimlane_records.json)" in output + assert f"Source chip_swimlane_level: {level} ({description}; recorded in chip_swimlane_records.json)" in output assert row.split() == ["0", "kernel", "1", "5.00", "-", "-", "-", "-", "-", "0.50"] assert total.split() == ["TOTAL", "1", "5.00", "-"] assert "AICore Observed Span: 5.50 us (from earliest AICore receive to latest AICore end)" in output @@ -464,6 +468,7 @@ def test_host_orchestrator_phases_without_anchors_are_marked_unaligned(tmp_path) data = sc.read_perf_data(raw) + assert data["scheduler_task_producer"] == "aicpu" assert data["orchestrator_source"] == "host" assert data["aicpu_orchestrator_phases"][0][0]["start_time_us"] == 0.0 assert data["aicpu_orchestrator_phases"][0][0]["end_time_us"] == 2.0 @@ -576,6 +581,284 @@ def test_aicpu_orchestrator_uses_host_timeline_when_clock_anchors_exist(tmp_path assert data["timeline_metadata"]["source_timeline_origin_ns"] == 1_000 +def test_aicore_scheduler_records_keep_common_shape_and_stream_metadata(tmp_path): + raw = tmp_path / "chip_swimlane_records.json" + raw.write_text( + json.dumps( + { + "chip_swimlane_level": 3, + "metadata": {"clock_freq_hz": 1_000_000_000, "num_cores": 1, "core_types": ["aiv"]}, + "aicore_tasks": [[0, 7, 7, 120, 180, 10]], + "scheduler_tasks": { + "schema_version": 1, + "producer": "aicore", + "records": [[0, 7, 115, 185]], + }, + "aicpu_lifecycle_records": [ + { + "worker_id": 6, + "aicpu_thread_id": 1, + "core_type": "aiv", + "physical_core_id": 9, + "handshake_observed_cycles": 90, + "handshake_partition_complete_cycles": 91, + "config_start_cycles": 92, + "topology_complete_cycles": 93, + "context_publish_complete_cycles": 94, + "bootstrap_wait_start_cycles": 95, + "bootstrap_complete_cycles": 96, + "register_release_cycles": 97, + "exit_signal_cycles": 181, + "exit_ack_cycles": 182, + } + ], + "scheduler_records": { + "schema_version": 1, + "streams": [ + { + "platform": "a5", + "runtime": "host_build_graph", + "producer": "aicore", + "scheduler_id": 2, + "worker_id": 6, + "core_type": "aiv", + "physical_core_id": 9, + "capture": {"committed": 2, "dropped": 0, "truncated": False}, + "records": [ + { + "start_cycles": 100, + "end_cycles": 110, + "loop_iter": 3, + "kind": "ready_claim", + "tasks_processed": 1, + "task_id": 7, + }, + { + "start_cycles": 111, + "end_cycles": 119, + "loop_iter": 3, + "kind": "idle", + "tasks_processed": 0, + "task_id": None, + }, + ], + "metrics": [{"record_index": 0, "claim_retries": 2}], + } + ], + }, + } + ) + ) + + data = sc.read_perf_data(raw) + + assert [task["task_id"] for task in data["tasks"]] == [7] + assert data["scheduler_task_producer"] == "aicore" + assert data["tasks"][0]["dispatch_time_us"] == pytest.approx(0.025) + assert data["tasks"][0]["finish_time_us"] == pytest.approx(0.095) + assert data["scheduler_streams"][0]["producer"] == "aicore" + assert data["scheduler_records"][0][0]["claim_retries"] == 2 + assert data["scheduler_records"][0][1]["task_id"] is None + assert data["aicpu_lifecycle_records"][0]["register_release_time_us"] == pytest.approx(0.007) + + trace_path = tmp_path / "merged_swimlane.json" + sc.generate_chrome_trace_json( + data["tasks"], + str(trace_path), + scheduler_phases=data["scheduler_records"], + scheduler_streams=data["scheduler_streams"], + aicpu_lifecycle_records=data["aicpu_lifecycle_records"], + ) + events = json.loads(trace_path.read_text())["traceEvents"] + assert any( + event.get("name") == "process_name" and event.get("args", {}).get("name") == "AICore Scheduler" + for event in events + ) + assert any(event.get("cat") == "scheduler" and event.get("name") == "idle(0)" for event in events) + assert any( + event.get("name") == "process_name" and event.get("args", {}).get("name") == "AICPU Lifecycle" + for event in events + ) + assert any(event.get("cat") == "aicpu_lifecycle" and event.get("name") == "bootstrap_wait" for event in events) + + +def test_level_two_rejects_missing_scheduler_task_timing(tmp_path): + raw = tmp_path / "chip_swimlane_records.json" + raw.write_text( + json.dumps( + { + "chip_swimlane_level": 2, + "metadata": {"clock_freq_hz": 1_000_000_000, "num_cores": 1, "core_types": ["aiv"]}, + "aicore_tasks": [[0, 7, 7, 120, 180, 10]], + } + ) + ) + + with pytest.raises(ValueError, match="level 2 requires Scheduler task timing for every AICore task"): + sc.read_perf_data(raw) + + +@pytest.mark.parametrize("producer", ["aicpu", "aicore"]) +def test_level_two_accepts_task_timing_from_either_scheduler_producer(tmp_path, producer): + raw = tmp_path / "chip_swimlane_records.json" + raw.write_text( + json.dumps( + { + "chip_swimlane_level": 2, + "metadata": {"clock_freq_hz": 1_000_000_000, "num_cores": 1, "core_types": ["aiv"]}, + "aicore_tasks": [[0, 7, 7, 120, 180, 10]], + "scheduler_tasks": { + "schema_version": 1, + "producer": producer, + "records": [[0, 7, 115, 185]], + }, + } + ) + ) + + data = sc.read_perf_data(raw) + + assert data["scheduler_task_producer"] == producer + assert data["tasks"][0]["dispatch_time_us"] == pytest.approx(0.005) + assert data["tasks"][0]["finish_time_us"] == pytest.approx(0.075) + + +def test_level_one_accepts_aicore_only_timing(tmp_path): + raw = tmp_path / "chip_swimlane_records.json" + raw.write_text( + json.dumps( + { + "chip_swimlane_level": 1, + "metadata": {"clock_freq_hz": 1_000_000_000, "num_cores": 1, "core_types": ["aiv"]}, + "aicore_tasks": [[0, 7, 7, 120, 180, 10]], + } + ) + ) + + data = sc.read_perf_data(raw) + + assert [task["task_id"] for task in data["tasks"]] == [7] + assert "dispatch_time_us" not in data["tasks"][0] + assert "finish_time_us" not in data["tasks"][0] + assert "scheduler_task_producer" not in data + + +@pytest.mark.parametrize( + ("scheduler_tasks", "error"), + [ + ({"schema_version": 2, "producer": "aicore", "records": []}, "schema_version"), + ({"schema_version": 1, "producer": "host", "records": []}, "producer"), + ({"schema_version": 1, "producer": "aicore", "records": [[0, 1, 2]]}, "four-column"), + ], +) +def test_scheduler_tasks_reject_schema_drift(tmp_path, scheduler_tasks, error): + raw = tmp_path / "chip_swimlane_records.json" + raw.write_text( + json.dumps( + { + "chip_swimlane_level": 2, + "metadata": {"clock_freq_hz": 1_000_000_000}, + "aicore_tasks": [], + "scheduler_tasks": scheduler_tasks, + } + ) + ) + + with pytest.raises(ValueError, match=error): + sc.read_perf_data(raw) + + +def test_scheduler_tasks_reject_ambiguous_legacy_stream(tmp_path): + raw = tmp_path / "chip_swimlane_records.json" + raw.write_text( + json.dumps( + { + "chip_swimlane_level": 2, + "metadata": {"clock_freq_hz": 1_000_000_000}, + "aicore_tasks": [], + "scheduler_tasks": {"schema_version": 1, "producer": "aicore", "records": []}, + "aicpu_tasks": [], + } + ) + ) + + with pytest.raises(ValueError, match="both scheduler_tasks and legacy aicpu_tasks"): + sc.read_perf_data(raw) + + +def test_scheduler_records_reject_schema_drift(tmp_path): + raw = tmp_path / "chip_swimlane_records.json" + raw.write_text( + json.dumps( + { + "chip_swimlane_level": 3, + "metadata": {"clock_freq_hz": 1_000_000_000}, + "scheduler_records": { + "schema_version": 1, + "streams": [{"records": [{"kind": "idle"}], "metrics": []}], + }, + } + ) + ) + + with pytest.raises(ValueError, match="must contain exactly"): + sc.read_perf_data(raw) + + +def test_scheduler_metrics_cannot_overwrite_fixed_record_fields(tmp_path): + raw = tmp_path / "chip_swimlane_records.json" + raw.write_text( + json.dumps( + { + "chip_swimlane_level": 3, + "metadata": {"clock_freq_hz": 1_000_000_000}, + "scheduler_records": { + "schema_version": 1, + "streams": [ + { + "records": [ + { + "start_cycles": 10, + "end_cycles": 20, + "loop_iter": 0, + "kind": "idle", + "tasks_processed": 0, + "task_id": None, + } + ], + "metrics": [{"record_index": 0, "start_cycles": 30}], + } + ], + }, + } + ) + ) + + with pytest.raises(ValueError, match="metric overwrites fixed record fields"): + sc.read_perf_data(raw) + + +def test_lifecycle_interval_can_start_at_relative_time_origin(tmp_path): + trace_path = tmp_path / "merged_swimlane.json" + sc.generate_chrome_trace_json( + [], + str(trace_path), + aicpu_lifecycle_records=[ + { + "worker_id": 0, + "aicpu_thread_id": 1, + "handshake_observed_time_us": 0.0, + "handshake_partition_complete_time_us": 2.0, + } + ], + ) + + events = json.loads(trace_path.read_text())["traceEvents"] + interval = next(event for event in events if event.get("name") == "handshake_partition") + assert interval["ts"] == 0.0 + assert interval["dur"] == 2.0 + + def test_host_capture_is_complete_when_the_pool_holds_more_than_the_submit_projection(tmp_path): """A pool record count above the projected one is normal, not incomplete. From 65ec0d0c84a7cef71a1ed8e093cd36871803c915 Mon Sep 17 00:00:00 2001 From: zhusy54 Date: Thu, 3 Sep 2026 17:20:10 +0800 Subject: [PATCH 2/2] Support: profile A5 HBG AICore scheduler Record AICore task timing, AICPU lifecycle, and real Scheduler intervals. Stage pre-kernel timestamps outside the callable live set and let the Scheduler consolidate each task trace before publishing valid. Keep bootstrap fanin writes on their owned cache line so they cannot overwrite completed task identity on hardware. Provide the A5 HBG runtime publisher for resident scheduler state. Coalesce consecutive idle iterations so fixed-capacity phase capture remains bounded when host simulation is CPU constrained. --- docs/dfx/args-dump.md | 4 +- docs/dfx/chip-swimlane-profiling.md | 4 +- docs/dfx/dep-gen.md | 2 +- docs/dfx/pmu-profiling.md | 4 +- docs/dfx/profiling-name-map.md | 4 +- docs/testing.md | 2 +- simpler_setup/scene_test.py | 22 +- .../aicore/aicore_executor.cpp | 186 ++++++------ .../aicpu/aicore_lifecycle.cpp | 5 +- .../host_build_graph/docs/profiling_levels.md | 27 +- .../host_build_graph/host/runtime_maker.cpp | 284 +++++++++++++++++- .../runtime/scheduler/scheduler_completion.h | 92 +++++- .../runtime/scheduler/scheduler_layout.h | 2 + .../runtime/scheduler/scheduler_ready.h | 57 +++- .../runtime/scheduler/scheduler_types.h | 211 +++++++++---- .../kernels/aiv/kernel_empty.cpp | 23 ++ .../orchestration/scheduler_phases_orch.cpp | 27 +- .../chip_swimlane/test_scheduler_phases.py | 47 +++ .../single_core_dag/test_single_core_dag.py | 52 ++++ .../cpp/a5/test_hbg_scheduler_contracts.cpp | 15 +- .../ut/cpp/a5/test_hbg_scheduler_dispatch.cpp | 16 + tests/ut/cpp/a5/test_hbg_scheduler_ready.cpp | 30 ++ tests/ut/py/test_scene_test_cli_contract.py | 15 +- 23 files changed, 936 insertions(+), 195 deletions(-) create mode 100644 tests/st/a5/host_build_graph/dfx/chip_swimlane/kernels/aiv/kernel_empty.cpp diff --git a/docs/dfx/args-dump.md b/docs/dfx/args-dump.md index 40e5493e5e..b4043430c4 100644 --- a/docs/dfx/args-dump.md +++ b/docs/dfx/args-dump.md @@ -194,8 +194,8 @@ collector receives no records and exports no manifest — that is the deliberate The dump artifacts land under the per-task output prefix (`CallConfig::output_prefix`, set by -`scene_test.py::_build_output_prefix` to -`outputs/__/` for SceneTest runs): +`scene_test.py::build_output_prefix` to +`outputs/___/` for SceneTest runs): ```text / diff --git a/docs/dfx/chip-swimlane-profiling.md b/docs/dfx/chip-swimlane-profiling.md index f4c3eb466c..caf4c65de4 100644 --- a/docs/dfx/chip-swimlane-profiling.md +++ b/docs/dfx/chip-swimlane-profiling.md @@ -151,8 +151,8 @@ runs are not instrumented. The raw artifact lands under the per-task output prefix (`CallConfig::output_prefix`, set by -`scene_test.py::_build_output_prefix` to -`outputs/__/` for SceneTest +`scene_test.py::build_output_prefix` to +`outputs/___/` for SceneTest runs): ```text diff --git a/docs/dfx/dep-gen.md b/docs/dfx/dep-gen.md index d8ddc1ea6c..6be8a752b0 100644 --- a/docs/dfx/dep-gen.md +++ b/docs/dfx/dep-gen.md @@ -134,7 +134,7 @@ runs that the converter joins back to that captured graph. When `--enable-dep-gen` is on with any other diagnostic flag, an `output_prefix` directory must be set (the runtime throws otherwise). The standard SceneTest path -(`outputs/__/`) handles that automatically. +(`outputs/___/`) handles that automatically. --- diff --git a/docs/dfx/pmu-profiling.md b/docs/dfx/pmu-profiling.md index fa9bc9b1d2..50f91307ff 100644 --- a/docs/dfx/pmu-profiling.md +++ b/docs/dfx/pmu-profiling.md @@ -71,8 +71,8 @@ rounds stay uninstrumented. ### 3.2 Output The PMU artifact is a CSV file under the per-task output prefix -(`CallConfig::output_prefix`, set by `scene_test.py::_build_output_prefix` -to `outputs/__/` for SceneTest runs): +(`CallConfig::output_prefix`, set by `scene_test.py::build_output_prefix` +to `outputs/___/` for SceneTest runs): ```text /pmu.csv diff --git a/docs/dfx/profiling-name-map.md b/docs/dfx/profiling-name-map.md index bb06d30e64..e48e6ac35b 100644 --- a/docs/dfx/profiling-name-map.md +++ b/docs/dfx/profiling-name-map.md @@ -173,8 +173,8 @@ python -m simpler_setup.tools.deps_viewer \ Each test case writes its diagnostic artifacts under `CallConfig::output_prefix` (chosen by -`scene_test.py::_build_output_prefix` as -`outputs/__/`). Filenames are fixed — +`scene_test.py::build_output_prefix` as +`outputs/___/`). Filenames are fixed — the per-case directory is the uniqueness boundary, so parallel runs cannot collide. diff --git a/docs/testing.md b/docs/testing.md index f3ac17918d..1c8c297308 100644 --- a/docs/testing.md +++ b/docs/testing.md @@ -380,7 +380,7 @@ A single file can declare both L2 and L3 classes; they're grouped by `(runtime, ### Profiling under parallelism -Each test case sets its own `CallConfig.output_prefix` (chosen by `scene_test.py::_build_output_prefix` as `outputs/__/`). The C++ runtime writes all diagnostic artifacts under that prefix with fixed filenames: +Each test case sets its own `CallConfig.output_prefix` (chosen by `scene_test.py::build_output_prefix` as `outputs/___/`). The C++ runtime writes all diagnostic artifacts under that prefix with fixed filenames: - `outputs/_/chip_swimlane_records.json` — swimlane (`--enable-chip-swimlane`) - `outputs/_/args_dump/` — args dump (`--dump-args`) diff --git a/simpler_setup/scene_test.py b/simpler_setup/scene_test.py index 5d074d5f93..fc881639cd 100644 --- a/simpler_setup/scene_test.py +++ b/simpler_setup/scene_test.py @@ -29,6 +29,7 @@ import os import platform as host_platform import sys +import tempfile from collections.abc import Mapping from concurrent.futures import ThreadPoolExecutor from contextlib import contextmanager @@ -1019,11 +1020,9 @@ def _outputs_dir() -> Path: def build_output_prefix(case_label: str) -> Path: """Per-case directory for diagnostic artifacts. - Each case gets its own ``outputs/_/`` directory; the + Each invocation gets its own ``outputs/__/`` directory; the runtime writes ``chip_swimlane_records.json``, ``args_dump/``, and ``pmu.csv`` - under that root with fixed filenames. Two cases of the same name run in - the same second is not a contemplated scenario (parallel xdist runs differ - by class+method). + under that root with fixed filenames. The directory is created here: the dep_gen host replay (and any other writer) ``fopen``s ``/`` directly without an mkdir of its @@ -1033,9 +1032,9 @@ def build_output_prefix(case_label: str) -> Path: timestamp = datetime.now().strftime("%Y%m%d_%H%M%S") safe_label = _sanitize_for_filename(case_label) - prefix = _outputs_dir() / f"{safe_label}_{timestamp}" - prefix.mkdir(parents=True, exist_ok=True) - return prefix + outputs = _outputs_dir() + outputs.mkdir(parents=True, exist_ok=True) + return Path(tempfile.mkdtemp(prefix=f"{safe_label}_{timestamp}_", dir=outputs)) def _run_swimlane_converter( @@ -1400,7 +1399,8 @@ def run_class_cases( # noqa: PLR0913 -- shared layer-5 entry; kwargs mirror CLI Caller is responsible for platform/selector/manual filtering. Profiling snapshots wrap each case. Execution failures carry the class and case name, with the original exception preserved as their cause; the caller decides - fail-fast vs collect semantics. + fail-fast vs collect semantics. Returns diagnostic output prefixes keyed by + case name. """ cls_name = type(cls_inst).__name__ callable_spec = getattr(type(cls_inst), "CALLABLE", None) @@ -1412,6 +1412,7 @@ def run_class_cases( # noqa: PLR0913 -- shared layer-5 entry; kwargs mirror CLI or enable_scope_stats or enable_swimlane_overhead ) + output_prefixes = {} for case in cases: case_label = f"{cls_name}_{case['name']}" # Per-case directory the runtime writes into. Required (non-empty) when @@ -1419,6 +1420,8 @@ def run_class_cases( # noqa: PLR0913 -- shared layer-5 entry; kwargs mirror CLI # scope_stats writes below the per-case output prefix, so it uses the # same output-prefix allocation as the other diagnostics. prefix = build_output_prefix(case_label) if diagnostics_on else Path("") + if diagnostics_on: + output_prefixes[case["name"]] = prefix try: cls_inst._run_and_validate( worker, @@ -1447,6 +1450,7 @@ def run_class_cases( # noqa: PLR0913 -- shared layer-5 entry; kwargs mirror CLI scope_stats=enable_scope_stats, swimlane_overhead=enable_swimlane_overhead, ) + return output_prefixes def _compare_outputs(test_args, golden_args, output_names, rtol, atol): @@ -2107,7 +2111,7 @@ def test_run(self, st_platform, st_worker, request): if self._st_level == 3 and chip_handles: callable_obj = {**chip_handles} - run_class_cases( + self._diagnostic_output_prefixes = run_class_cases( st_worker, self, matched, diff --git a/src/a5/runtime/host_build_graph/aicore/aicore_executor.cpp b/src/a5/runtime/host_build_graph/aicore/aicore_executor.cpp index 0062b5e9ad..c9aa65194e 100644 --- a/src/a5/runtime/host_build_graph/aicore/aicore_executor.cpp +++ b/src/a5/runtime/host_build_graph/aicore/aicore_executor.cpp @@ -178,74 +178,31 @@ publish_worker_stats(__gm__ SchedulerWorkerContext *context, const SchedulerWork scheduler_gm_publish(context->bootstrap_ready_claim_aiv_cycles, stats.bootstrap_ready_claim_cycles[1]); } -__aicore__ __attribute__((always_inline)) void commit_task_trace( - __gm__ void *scheduler_state_base, __gm__ SchedulerWorkerContext *context, const SchedulerExecutionRecord &record, - uint64_t ready_scan_start, uint64_t ready_observe, uint64_t kernel_start, uint64_t kernel_end, - uint64_t completion_end, uint64_t bookkeeping_end, uint64_t previous_trace_commit_end, uint64_t aicore_entry_cycles, - uint64_t handshake_publish_cycles, uint64_t register_release_cycles, uint64_t descriptor_cache_observed_cycles, - uint64_t completion_id, uint64_t completion_inbox_index, const SchedulerInterTaskTiming &inter_task_timing +// Keep the pre-kernel timestamps out of the indirect kernel call's live set. +// Inlining this path makes the resident loop spill enough state to fault on A5. +__aicore__ __attribute__((noinline)) void stage_task_trace_before_execution( + __gm__ SchedulerDispatchSlot *slot, uint64_t ready_scan_start, uint64_t ready_observe, uint64_t completion_id, + uint64_t completion_inbox_index ) { - __gm__ SchedulerTaskTrace *cells = - scheduler_state_at(scheduler_state_base, context->trace_cells_offset); - __gm__ SchedulerTaskTrace *trace = &cells[record.task_id]; - trace->ready_source = static_cast(record.ready_source); - trace->worker_id = context->worker_index; - trace->task_id = static_cast(record.task_id); - trace->claim_worker_id = record.claim_worker_id; - trace->claim_start_cycles = record.claim_start_cycles; - trace->claim_end_cycles = record.claim_end_cycles; - trace->previous_trace_commit_end_cycles = previous_trace_commit_end; - trace->kernel_start_cycles = kernel_start; - trace->kernel_end_cycles = kernel_end; - trace->completion_end_cycles = completion_end; - trace->ready_scan_start_cycles = ready_scan_start; - trace->ready_observe_cycles = ready_observe; - trace->completion_bookkeeping_end_cycles = bookkeeping_end; - trace->completion_id = completion_id; - trace->completion_inbox_index = completion_inbox_index; - scheduler_observe_cache_line(&trace->ready_transition_cycles); - trace->inter_task_completion_service_cycles = inter_task_timing.completion_service_cycles; - trace->inter_task_dispatch_aic_cycles = inter_task_timing.dispatch_cycles[0]; - trace->inter_task_dispatch_aiv_cycles = inter_task_timing.dispatch_cycles[1]; - trace->inter_task_ready_poll_cycles = inter_task_timing.ready_poll_cycles; - trace->inter_task_backoff_cycles = inter_task_timing.backoff_cycles; - trace->inter_task_completion_scan_cycles = inter_task_timing.completion.scan_cycles; - trace->inter_task_completion_consume_cycles = inter_task_timing.completion.consume_cycles; - trace->inter_task_completion_resolve_cycles = inter_task_timing.completion.resolve_cycles; - trace->inter_task_completion_ready_publish_cycles = inter_task_timing.completion.ready_publish_cycles; - trace->inter_task_completion_refill_cycles = inter_task_timing.completion.refill_cycles; - trace->inter_task_completion_finalize_cycles = inter_task_timing.completion.finalize_cycles; - trace->inter_task_gang_service_cycles = inter_task_timing.gang_service_cycles; - for (uint32_t type = 0; type < SCHEDULER_CORE_TYPE_COUNT; ++type) { - trace->inter_task_dispatch_probe_cycles[type] = inter_task_timing.dispatch.probe_cycles[type]; - trace->inter_task_dispatch_claim_cycles[type] = inter_task_timing.dispatch.claim_cycles[type]; - trace->inter_task_dispatch_prepare_cycles[type] = inter_task_timing.dispatch.prepare_cycles[type]; - trace->inter_task_dispatch_materialize_cycles[type] = inter_task_timing.dispatch.materialize_cycles[type]; - trace->inter_task_dispatch_publish_cycles[type] = inter_task_timing.dispatch.publish_cycles[type]; - } - if (previous_trace_commit_end == 0) { - trace->aicore_entry_cycles = aicore_entry_cycles; - trace->handshake_publish_cycles = handshake_publish_cycles; - trace->register_release_cycles = register_release_cycles; - trace->descriptor_cache_observed_cycles = descriptor_cache_observed_cycles; - scheduler_publish_cache_line(&trace->register_release_cycles); - } - scheduler_publish_cache_line(&trace->kernel_start_cycles); - scheduler_publish_cache_line(&trace->ready_transition_cycles); - trace->valid = 1; - scheduler_publish_cache_line(trace); + __gm__ SchedulerExecutorTaskTrace *trace = &slot->executor_trace; + scheduler_gm_store(trace->ready_scan_start_cycles, ready_scan_start); + scheduler_gm_store(trace->ready_observe_cycles, ready_observe); + scheduler_gm_store(trace->completion_id, completion_id); + scheduler_gm_store(trace->completion_inbox_index, completion_inbox_index); } -__aicore__ __attribute__((always_inline)) void commit_task_timing_trace( - __gm__ void *scheduler_state_base, __gm__ SchedulerWorkerContext *context, int64_t task_id, uint64_t kernel_start, - uint64_t kernel_end +// Publish the staging generation only after every field is device-visible. The +// completion token follows this call, so the Scheduler cannot observe a partial +// Executor trace. +__aicore__ __attribute__((noinline)) void stage_task_trace_before_completion( + __gm__ SchedulerDispatchSlot *slot, uint64_t kernel_start, uint64_t kernel_end, uint64_t completion_ready ) { - __gm__ SchedulerTaskTrace *cells = - scheduler_state_at(scheduler_state_base, context->trace_cells_offset); - __gm__ SchedulerTaskTrace *trace = &cells[task_id]; - trace->kernel_start_cycles = kernel_start; - trace->kernel_end_cycles = kernel_end; - scheduler_publish_cache_line(&trace->kernel_start_cycles); + __gm__ SchedulerExecutorTaskTrace *trace = &slot->executor_trace; + scheduler_gm_store(trace->kernel_start_cycles, kernel_start); + scheduler_gm_store(trace->kernel_end_cycles, kernel_end); + scheduler_gm_store(trace->completion_end_cycles, completion_ready); + scheduler_gm_store(trace->completion_bookkeeping_end_cycles, completion_ready); + scheduler_gm_publish(trace->generation, slot->generation); } __aicore__ bool bootstrap_ready_graph( @@ -266,12 +223,23 @@ __aicore__ bool bootstrap_ready_graph( scheduler_task_metadata_at(scheduler_state_base, scheduler, static_cast(task_id)); scheduler_observe_cache_line(metadata); if (!scheduler_task_is_executable(metadata->flags)) continue; - SchedulerRouteResult route = - scheduler_task_has_fanin(metadata->flags) ? - scheduler_bootstrap_route_task( - graph, scheduler_state_base, scheduler, run_control, static_cast(task_id), &stats->wake - ) : - SchedulerRouteResult::READY_TO_ENQUEUE; + const bool has_fanin = scheduler_task_has_fanin(metadata->flags); + const uint64_t fanin_start_cycles = trace_enabled && has_fanin ? scheduler_cycles() : 0; + SchedulerRouteResult route = has_fanin ? scheduler_bootstrap_route_task( + graph, scheduler_state_base, scheduler, run_control, + static_cast(task_id), &stats->wake + ) : + SchedulerRouteResult::READY_TO_ENQUEUE; + if (trace_enabled && has_fanin) { + __gm__ SchedulerTaskTrace *traces = + scheduler_state_at(scheduler_state_base, scheduler->trace_cells_offset); + __gm__ SchedulerTaskTrace *trace = &traces[task_id]; + trace->fanin_start_cycles = fanin_start_cycles; + trace->fanin_end_cycles = scheduler_cycles(); + trace->fanin_scheduler_worker_id = scheduler->worker_index; + trace->fanin_loop_iter = 0; + scheduler_publish_cache_line(&trace->ready_transition_cycles); + } if (route == SchedulerRouteResult::ERROR) return false; if (route == SchedulerRouteResult::READY_TO_ENQUEUE && !scheduler_bootstrap_ready_batch_append( @@ -378,8 +346,7 @@ __aicore__ bool bootstrap_ready_graph( __aicore__ bool run_ready_dispatch_loop( const SchedulerGraphView &graph, __gm__ void *scheduler_state_base, __gm__ SchedulerWorkerContext *context, __gm__ SchedulerRunControl *run_control, SchedulerWorkerStats *stats, bool trace_enabled, - uint64_t aicore_entry_cycles, uint64_t handshake_publish_cycles, uint64_t register_release_cycles, - uint64_t descriptor_cache_observed_cycles, SchedulerDeferredAivQueue *deferred_aiv + SchedulerDeferredAivQueue *deferred_aiv ) { uint64_t scheduler_count = scheduler_gm_query(run_control->scheduler_count); bool scheduler_worker = context->is_scheduler != 0; @@ -393,16 +360,24 @@ __aicore__ bool run_ready_dispatch_loop( scheduler_worker ? (context->inbox_index + 1) % scheduler_count : 0, }; uint64_t seen_publication[SCHEDULER_PENDING_SLOT_COUNT]{}; - uint64_t previous_trace_commit_end = 0; - uint64_t inter_task_start_cycles = register_release_cycles; + uint64_t inter_task_start_cycles = context->trace_register_release_cycles; uint32_t scan_start = 0; uint32_t backoff_iterations = kInitialBackoffIterations; uint32_t scheduler_error_poll_count = 0; + uint32_t loop_iter = 0; + uint64_t idle_start_cycles = 0; + bool idle_active = false; SchedulerInterTaskTiming inter_task_timing{}; while (true) { if (static_cast(read_reg(RegId::DATA_MAIN_BASE)) == AICORE_EXIT_SIGNAL) { if (trace_enabled) { stats->exit_observed_cycles = get_sys_cnt_aicore(); + if (scheduler_worker && idle_active) { + scheduler_append_activity( + scheduler_state_base, context, AicoreSchedulerKind::Idle, idle_start_cycles, + stats->exit_observed_cycles + ); + } publish_scheduler_tail_trace( context, inter_task_start_cycles, stats->exit_observed_cycles, inter_task_timing ); @@ -414,6 +389,9 @@ __aicore__ bool run_ready_dispatch_loop( if (scheduler_gm_query(run_control->scheduler_error) != 0) return false; } + if (trace_enabled && scheduler_worker) context->profiling_loop_iter = loop_iter++; + const uint64_t idle_candidate_start = trace_enabled && scheduler_worker ? scheduler_cycles() : 0; + bool scheduler_progress = false; if (scheduler_worker && !scheduler_ready_owner_maintain(scheduler_state_base, context, ready_owner)) { scheduler_record_error( @@ -498,6 +476,13 @@ __aicore__ bool run_ready_dispatch_loop( } } + if (trace_enabled && scheduler_worker && scheduler_progress && idle_active) { + scheduler_append_activity( + scheduler_state_base, context, AicoreSchedulerKind::Idle, idle_start_cycles, idle_candidate_start + ); + idle_active = false; + } + int32_t ready_slot = -1; uint64_t ready_publication = 0; uint64_t ready_scan_start = trace_enabled ? get_sys_cnt_aicore() : 0; @@ -542,6 +527,12 @@ __aicore__ bool run_ready_dispatch_loop( context->dispatch_payload_offset + static_cast(slot_index) * sizeof(DispatchPayload) ); uint64_t ready_observe = get_sys_cnt_aicore(); + if (trace_enabled && scheduler_worker && idle_active) { + scheduler_append_activity( + scheduler_state_base, context, AicoreSchedulerKind::Idle, idle_start_cycles, ready_observe + ); + idle_active = false; + } scheduler_invalidate_cache_line(slot); scheduler_observe_dispatch_payload_control(payload); scheduler_observe_dispatch_payload_arguments(payload); @@ -571,6 +562,13 @@ __aicore__ bool run_ready_dispatch_loop( const bool commit_task_timing = task_metadata->timing_slot >= 0 && task_metadata->timing_slot < SCHEDULER_TASK_TIMING_SLOT_COUNT && should_commit_scheduler_trace(scheduler_state_base, context, slot); + if (commit_scheduler_trace || commit_task_timing) { + uint64_t local_completion_index = stats->completion.enqueue_count; + stage_task_trace_before_execution( + slot, ready_scan_start, ready_observe, scheduler_completion_id(context, local_completion_index), + context->scheduler_index + ); + } OUT_OF_ORDER_STORE_BARRIER(); uint64_t kernel_start = get_sys_cnt_aicore(); if (trace_enabled) { @@ -587,12 +585,13 @@ __aicore__ bool run_ready_dispatch_loop( execute_task(payload); uint64_t kernel_end = get_sys_cnt_aicore(); scheduler_publish_dispatch_payload(payload); - uint64_t completion_start = get_sys_cnt_aicore(); - uint64_t local_completion_index = stats->completion.enqueue_count; - uint64_t completion_id = scheduler_completion_id(context, local_completion_index); - uint64_t completion_inbox_index = context->scheduler_index; __gm__ SchedulerCompletionInbox *completion_line = scheduler_completion_inbox_at(scheduler_state_base, context, context->worker_index); + uint64_t completion_start = get_sys_cnt_aicore(); + if (commit_scheduler_trace || commit_task_timing) { + uint64_t completion_ready = get_sys_cnt_aicore(); + stage_task_trace_before_completion(slot, kernel_start, kernel_end, completion_ready); + } scheduler_gm_store(completion_line->completed_generations[slot_index], slot->generation); ++stats->completion.enqueue_count; uint64_t completion_end = get_sys_cnt_aicore(); @@ -603,17 +602,7 @@ __aicore__ bool run_ready_dispatch_loop( scan_start = (slot_index + 1) % SCHEDULER_PENDING_SLOT_COUNT; backoff_iterations = kInitialBackoffIterations; if (commit_scheduler_trace) { - uint64_t bookkeeping_end = get_sys_cnt_aicore(); - commit_task_trace( - scheduler_state_base, context, record, ready_scan_start, ready_observe, kernel_start, kernel_end, - completion_end, bookkeeping_end, previous_trace_commit_end, aicore_entry_cycles, - handshake_publish_cycles, register_release_cycles, descriptor_cache_observed_cycles, completion_id, - completion_inbox_index, inter_task_timing - ); - previous_trace_commit_end = get_sys_cnt_aicore(); - inter_task_start_cycles = previous_trace_commit_end; - } else if (commit_task_timing) { - commit_task_timing_trace(scheduler_state_base, context, record.task_id, kernel_start, kernel_end); + inter_task_start_cycles = get_sys_cnt_aicore(); } else if (trace_enabled) { inter_task_start_cycles = get_sys_cnt_aicore(); } @@ -632,7 +621,13 @@ __aicore__ bool run_ready_dispatch_loop( local_backoff(backoff_iterations); uint64_t backoff_end = get_sys_cnt_aicore(); stats->backoff_cycles += backoff_end - backoff_start; - if (trace_enabled) inter_task_timing.backoff_cycles += backoff_end - backoff_start; + if (trace_enabled) { + inter_task_timing.backoff_cycles += backoff_end - backoff_start; + if (scheduler_worker && !idle_active) { + idle_start_cycles = idle_candidate_start; + idle_active = true; + } + } if (backoff_iterations < kMaximumBackoffIterations) backoff_iterations <<= 1; } return true; @@ -759,11 +754,18 @@ __aicore__ __attribute__((weak)) void aicore_execute(__gm__ Runtime *runtime, in if (trace_enabled) stats.exit_observed_cycles = get_sys_cnt_aicore(); } else { uint64_t register_release_cycles = trace_enabled ? get_sys_cnt_aicore() : 0; + if (trace_enabled) { + context->trace_aicore_entry_cycles = aicore_entry_cycles; + context->trace_handshake_publish_cycles = handshake_publish_cycles; + context->trace_register_release_cycles = register_release_cycles; + context->trace_descriptor_cache_observed_cycles = descriptor_cache_observed_cycles; + scheduler_publish_cache_line(&context->trace_aicore_entry_cycles); + scheduler_publish_cache_line(&context->trace_register_release_cycles); + } write_reg(RegId::COND, AICORE_IDLE_VALUE); if (context->active != 0) { (void)run_ready_dispatch_loop( - graph, scheduler_state_base, context, run_control, &stats, trace_enabled, aicore_entry_cycles, - handshake_publish_cycles, register_release_cycles, descriptor_cache_observed_cycles, &deferred_aiv + graph, scheduler_state_base, context, run_control, &stats, trace_enabled, &deferred_aiv ); } } diff --git a/src/a5/runtime/host_build_graph/aicpu/aicore_lifecycle.cpp b/src/a5/runtime/host_build_graph/aicpu/aicore_lifecycle.cpp index 0f85302c1a..9f1a735afa 100644 --- a/src/a5/runtime/host_build_graph/aicpu/aicore_lifecycle.cpp +++ b/src/a5/runtime/host_build_graph/aicpu/aicore_lifecycle.cpp @@ -69,10 +69,9 @@ int32_t AicoreLifecycle::pre_handshake_init(Runtime *runtime, int32_t aicpu_thre handshake_failed_.store(false, std::memory_order_release); const bool chip_swimlane_enabled = is_chip_swimlane_enabled(); - if (chip_swimlane_enabled || is_pmu_enabled() || is_dump_args_enabled()) { + if (is_pmu_enabled() || is_dump_args_enabled()) { LOG_WARN( - "A5 HBG AICore Scheduler diagnostics are best-effort: artifacts may be absent or incomplete and do not " - "yet describe Scheduler scheduling" + "A5 HBG AICore Scheduler PMU/argument diagnostics are best-effort: artifacts may be absent or incomplete" ); } if (chip_swimlane_enabled) chip_swimlane_aicpu_init(core_count_); diff --git a/src/a5/runtime/host_build_graph/docs/profiling_levels.md b/src/a5/runtime/host_build_graph/docs/profiling_levels.md index 3afd5471ae..18c93063d5 100644 --- a/src/a5/runtime/host_build_graph/docs/profiling_levels.md +++ b/src/a5/runtime/host_build_graph/docs/profiling_levels.md @@ -8,11 +8,9 @@ The runtime uses a hierarchical profiling system with compile-time macros to con > **A5 HBG scheduler selection.** Diagnostic flags never select the scheduler. > Ordinary DAGs remain on the A5 HBG AICore Scheduler, while Graph replay -> remains on its explicit legacy compatibility path. Until AICore Scheduler -> profiling lands, chip-swimlane, PMU, and argument-dump collection for -> ordinary DAGs is best-effort; artifacts may be absent or incomplete and must -> not be used as evidence of AICore Scheduler behavior or as a profiling-on -> performance baseline. +> remains on its explicit AICPU compatibility path. Both producers export the +> same `scheduler_records` schema; stream metadata identifies `producer` so +> tools never apply AICPU scheduling assumptions to AICore intervals. > **host_build_graph (host-orch) note.** The profiling **macros** below > (`SIMPLER_DFX`, `SIMPLER_ORCH_PROFILING`, …) are shared with > `tensormap_and_ringbuffer`. But the orchestrator-timing **device-log lines** @@ -173,7 +171,7 @@ Thread X: Scheduler summary: total_time=XXXus, loops=XXX, tasks_scheduled=XXX ``` Per-thread fanout / fanin edge counts and ready-queue pop hit / miss -stats live in `aicpu_scheduler_phases[]` (in `chip_swimlane_records.json` +stats live in `scheduler_records.streams[]` (in `chip_swimlane_records.json` captured at chip_swimlane_level >= 3) and `deps.json`; consume them via `simpler_setup/tools/sched_overhead_analysis.py`. @@ -423,6 +421,23 @@ header just like on onboard. | 3 | + Scheduler phases (`SCHED_*`) | | 4 | + Orchestrator phases (full) | +The A5 HBG AICore Scheduler records the same per-task timing contract as the +AICPU Scheduler: `dispatch_time` is the end of dispatch publication and +`finish_time` is when the Scheduler starts processing the completion. The raw +`scheduler_tasks.producer` field identifies which Scheduler produced these +timestamps. At level 2 and above, A5 HBG also exports AICPU lifecycle timestamps +for handshake, topology/configuration, context publication, bootstrap wait, +register release, and exit; these are supplemental control-plane records. + +At level 3 and above, A5 HBG AICore Scheduler task intervals reuse the per-task +trace. Consecutive taskless scheduler-loop iterations are coalesced into one +`idle` interval and stored in one fixed-capacity, no-wrap buffer per Scheduler; +overflow increments `capture.dropped` and sets `capture.truncated`. Coalescing +keeps capture size dependent on idle-to-active transitions instead of Host CPU +speed in simulation. The buffer is not allocated below level 3. Interval +endpoints are captured at operation entry and exit; no interval is synthesized +from aggregate durations. + At level 1 the AICore record carries the full `task_token_raw` (a `TaskId::raw`; see `src/common/host_build_graph/task_id.h`), read straight from `LocalContext.async_ctx.task_token.raw` inside the AICore helper — diff --git a/src/a5/runtime/host_build_graph/host/runtime_maker.cpp b/src/a5/runtime/host_build_graph/host/runtime_maker.cpp index 1b8c22da37..aa4cc976c4 100644 --- a/src/a5/runtime/host_build_graph/host/runtime_maker.cpp +++ b/src/a5/runtime/host_build_graph/host/runtime_maker.cpp @@ -49,6 +49,7 @@ #include #include #include +#include #include #include #include @@ -74,6 +75,7 @@ #include "../../../../common/task_interface/call_config.h" #include "../../../../common/worker/runtime_c_api.h" #include "callable.h" +#include "common/chip_swimlane_profiling.h" #include "common/host_log_binding.h" #include "common/host_phase_kind.h" #include "common/platform_config.h" @@ -360,11 +362,285 @@ struct SchedulerStateOwner { void *state_base; uint64_t allocation_size; AicoreSchedulerLayout layout; + const HostApi *api; }; std::mutex scheduler_state_owners_mutex; std::unordered_map scheduler_state_owners; +struct SchedulerJsonRecord { + uint64_t start_cycles; + uint64_t end_cycles; + uint64_t loop_iter; + const char *kind; + uint64_t tasks_processed; + uint64_t task_id; + bool has_task; +}; + +const char *scheduler_core_type_name(int32_t core_type) { + return core_type == static_cast(CoreType::AIC) ? "aic" : "aiv"; +} + +void append_scheduler_record( + std::vector *records, uint64_t start_cycles, uint64_t end_cycles, uint64_t loop_iter, + const char *kind, uint64_t tasks_processed, uint64_t task_id = 0, bool has_task = true +) { + if (records == nullptr || start_cycles == 0 || end_cycles < start_cycles) return; + records->push_back({start_cycles, end_cycles, loop_iter, kind, tasks_processed, task_id, has_task}); +} + +bool publish_aicore_scheduler_profiling(Runtime *runtime, const HostApi *api) { + const uint32_t level = api->chip_swimlane_level(); + if (level == 0) return true; + + SchedulerStateOwner owner{}; + { + std::scoped_lock lock(scheduler_state_owners_mutex); + auto it = scheduler_state_owners.find(runtime); + if (it == scheduler_state_owners.end()) return true; + owner = it->second; + } + + std::vector storage(static_cast(owner.layout.total_size + SCHEDULER_STATE_ALIGNMENT - 1)); + const uintptr_t aligned_address = (reinterpret_cast(storage.data()) + SCHEDULER_STATE_ALIGNMENT - 1) & + ~(static_cast(SCHEDULER_STATE_ALIGNMENT) - 1); + void *host_base = reinterpret_cast(aligned_address); + if (api->copy_from_device(host_base, owner.state_base, static_cast(owner.layout.total_size)) != 0) { + LOG_WARN("A5 HBG: failed to copy AICore Scheduler profiling state"); + return false; + } + + const auto *contexts = scheduler_state_at(host_base, owner.layout.worker_contexts_offset); + const auto *traces = scheduler_state_at(host_base, owner.layout.trace_cells_offset); + const auto *controls = scheduler_state_at(host_base, owner.layout.task_controls_offset); + + std::ostringstream tasks_json; + tasks_json << "["; + bool first_task = true; + for (uint64_t task_id = 0; task_id < owner.layout.task_count; ++task_id) { + const SchedulerTaskTrace &trace = traces[task_id]; + if (trace.valid == 0 || trace.kernel_start_cycles == 0 || trace.kernel_end_cycles < trace.kernel_start_cycles || + trace.worker_id >= SCHEDULER_WORKER_CAPACITY) + continue; + const uint64_t receive_to_start = + trace.ready_observe_cycles != 0 && trace.kernel_start_cycles >= trace.ready_observe_cycles ? + trace.kernel_start_cycles - trace.ready_observe_cycles : + 0; + if (!first_task) tasks_json << ","; + tasks_json << "\n [" << trace.worker_id << ", " << task_id << ", " << task_id << ", " + << trace.kernel_start_cycles << ", " << trace.kernel_end_cycles << ", " << receive_to_start << "]"; + first_task = false; + } + if (!first_task) tasks_json << "\n "; + tasks_json << "]"; + const std::string task_payload = tasks_json.str(); + if (!api->publish_chip_swimlane_extension( + ChipSwimlaneExtensionSection::AicoreTasks, task_payload.c_str(), task_payload.size() + )) { + LOG_WARN("A5 HBG: failed to publish AICore task records"); + return false; + } + + if (level >= static_cast(ChipSwimlaneLevel::SCHEDULE_TIMING)) { + std::ostringstream scheduler_tasks_json; + scheduler_tasks_json << "{\n \"schema_version\": 1,\n \"producer\": \"aicore\",\n \"records\": ["; + bool first_scheduler_task = true; + for (uint64_t task_id = 0; task_id < owner.layout.task_count; ++task_id) { + const SchedulerTaskTrace &trace = traces[task_id]; + if (trace.valid == 0 || trace.kernel_start_cycles == 0 || + trace.kernel_end_cycles < trace.kernel_start_cycles || trace.worker_id >= SCHEDULER_WORKER_CAPACITY) + continue; + if (trace.dispatch_end_cycles == 0 || trace.complete_start_cycles < trace.kernel_end_cycles) { + LOG_WARN("A5 HBG: incomplete Scheduler task timing for task id=%" PRIu64, task_id); + return false; + } + if (!first_scheduler_task) scheduler_tasks_json << ","; + scheduler_tasks_json << "\n [" << trace.worker_id << ", " << task_id << ", " + << trace.dispatch_end_cycles << ", " << trace.complete_start_cycles << "]"; + first_scheduler_task = false; + } + if (!first_scheduler_task) scheduler_tasks_json << "\n "; + scheduler_tasks_json << "]\n }"; + const std::string scheduler_tasks_payload = scheduler_tasks_json.str(); + if (!api->publish_chip_swimlane_extension( + ChipSwimlaneExtensionSection::SchedulerTasks, scheduler_tasks_payload.c_str(), + scheduler_tasks_payload.size() + )) { + LOG_WARN("A5 HBG: failed to publish AICore Scheduler task timing"); + return false; + } + + const auto *lifecycle = + scheduler_state_at(host_base, owner.layout.aicpu_lifecycle_traces_offset); + std::ostringstream lifecycle_json; + lifecycle_json << "["; + bool first = true; + for (uint64_t worker = 0; worker < SCHEDULER_WORKER_CAPACITY; ++worker) { + const AicpuCoreLifecycleTrace &trace = lifecycle[worker]; + if (trace.handshake_observed_cycles == 0) continue; + if (!first) lifecycle_json << ","; + lifecycle_json << "\n {\"worker_id\": " << trace.worker_id + << ", \"aicpu_thread_id\": " << trace.aicpu_thread_id << ", \"core_type\": \"" + << scheduler_core_type_name(static_cast(trace.core_type)) + << "\", \"physical_core_id\": " << trace.physical_core_id + << ", \"handshake_observed_cycles\": " << trace.handshake_observed_cycles + << ", \"handshake_partition_complete_cycles\": " << trace.handshake_partition_complete_cycles + << ", \"config_start_cycles\": " << trace.config_start_cycles + << ", \"topology_complete_cycles\": " << trace.topology_complete_cycles + << ", \"context_publish_complete_cycles\": " << trace.context_publish_complete_cycles + << ", \"bootstrap_wait_start_cycles\": " << trace.bootstrap_wait_start_cycles + << ", \"bootstrap_complete_cycles\": " << trace.bootstrap_complete_cycles + << ", \"register_release_cycles\": " << trace.register_release_cycles + << ", \"exit_signal_cycles\": " << trace.exit_signal_cycles + << ", \"exit_ack_cycles\": " << trace.exit_ack_cycles << "}"; + first = false; + } + if (!first) lifecycle_json << "\n "; + lifecycle_json << "]"; + const std::string lifecycle_payload = lifecycle_json.str(); + if (!api->publish_chip_swimlane_extension( + ChipSwimlaneExtensionSection::AicpuLifecycleRecords, lifecycle_payload.c_str(), lifecycle_payload.size() + )) { + LOG_WARN("A5 HBG: failed to publish AICPU lifecycle records"); + return false; + } + } + + if (level < static_cast(ChipSwimlaneLevel::SCHED_PHASES)) return true; + + std::vector> records(SCHEDULER_WORKER_CAPACITY); + for (uint64_t worker = 0; worker < SCHEDULER_WORKER_CAPACITY; ++worker) { + const SchedulerWorkerContext &context = contexts[worker]; + if (context.is_scheduler == 0 || context.worker_index >= SCHEDULER_WORKER_CAPACITY) continue; + append_scheduler_record( + &records[context.worker_index], context.bootstrap_start_cycles, context.bootstrap_end_cycles, 0, + "bootstrap", context.bootstrap_task_count, 0, false + ); + } + for (uint64_t task_id = 0; task_id < owner.layout.task_count; ++task_id) { + const SchedulerTaskTrace &trace = traces[task_id]; + if (trace.fanin_scheduler_worker_id < SCHEDULER_WORKER_CAPACITY) { + append_scheduler_record( + &records[trace.fanin_scheduler_worker_id], trace.fanin_start_cycles, trace.fanin_end_cycles, + trace.fanin_loop_iter, "fanin", 1, task_id + ); + } + if (trace.claim_worker_id < SCHEDULER_WORKER_CAPACITY) { + append_scheduler_record( + &records[trace.claim_worker_id], trace.claim_start_cycles, trace.claim_end_cycles, + trace.claim_loop_iter, + trace.ready_source == static_cast(SchedulerReadySource::STOLEN) ? "ready_steal" : + "ready_claim", + 1, task_id + ); + } + if (trace.dispatch_scheduler_worker_id < SCHEDULER_WORKER_CAPACITY) { + append_scheduler_record( + &records[trace.dispatch_scheduler_worker_id], trace.dispatch_start_cycles, trace.dispatch_end_cycles, + trace.dispatch_loop_iter, "dispatch", 1, task_id + ); + } + if (trace.complete_scheduler_worker_id < SCHEDULER_WORKER_CAPACITY) { + append_scheduler_record( + &records[trace.complete_scheduler_worker_id], trace.complete_start_cycles, trace.complete_end_cycles, + trace.complete_loop_iter, "complete", 1, task_id + ); + } + if (trace.refill_scheduler_worker_id < SCHEDULER_WORKER_CAPACITY) { + append_scheduler_record( + &records[trace.refill_scheduler_worker_id], trace.refill_start_cycles, trace.refill_end_cycles, + trace.refill_loop_iter, "direct_refill", 1, trace.refill_task_id + ); + } + const SchedulerTaskControl &control = controls[task_id]; + if (control.scheduler_worker_id < SCHEDULER_WORKER_CAPACITY) { + append_scheduler_record( + &records[control.scheduler_worker_id], control.completion_resolve_start_cycles, + control.completion_resolve_end_cycles, control.completion_resolve_loop_iter, "resolve", 1, task_id + ); + } + } + + const SchedulerActivityBuffer *activity = nullptr; + if (owner.layout.activity_buffers_offset != 0) { + activity = scheduler_state_at(host_base, owner.layout.activity_buffers_offset); + for (uint64_t worker = 0; worker < SCHEDULER_WORKER_CAPACITY; ++worker) { + const uint32_t committed = + std::min(static_cast(activity[worker].committed), activity[worker].capacity); + for (uint32_t index = 0; index < committed; ++index) { + const AicoreSchedulerRecord &record = activity[worker].records[index]; + append_scheduler_record( + &records[worker], record.start_time, record.end_time, record.loop_iter, "idle", + record.tasks_processed, 0, false + ); + } + } + } + + std::ostringstream scheduler_json; + scheduler_json << "{\n \"schema_version\": 1,\n \"streams\": ["; + bool first_stream = true; + for (uint64_t worker = 0; worker < SCHEDULER_WORKER_CAPACITY; ++worker) { + const SchedulerWorkerContext &context = contexts[worker]; + const uint32_t dropped = activity == nullptr ? 0 : activity[worker].dropped; + if (context.is_scheduler == 0 || (records[worker].empty() && dropped == 0)) continue; + std::sort(records[worker].begin(), records[worker].end(), [](const auto &lhs, const auto &rhs) { + if (lhs.start_cycles != rhs.start_cycles) return lhs.start_cycles < rhs.start_cycles; + if (lhs.end_cycles != rhs.end_cycles) return lhs.end_cycles < rhs.end_cycles; + return std::strcmp(lhs.kind, rhs.kind) < 0; + }); + if (!first_stream) scheduler_json << ","; + scheduler_json << "\n {\"platform\": \"a5\", \"runtime\": \"host_build_graph\", " + "\"producer\": \"aicore\", \"scheduler_id\": " + << context.scheduler_index << ", \"worker_id\": " << worker << ", \"core_type\": \"" + << scheduler_core_type_name(context.core_type) + << "\", \"physical_core_id\": " << context.physical_core_id + << ", \"capture\": {\"committed\": " << records[worker].size() << ", \"dropped\": " << dropped + << ", \"truncated\": " << (dropped == 0 ? "false" : "true") << "}, \"records\": ["; + for (size_t index = 0; index < records[worker].size(); ++index) { + const SchedulerJsonRecord &record = records[worker][index]; + if (index != 0) scheduler_json << ","; + scheduler_json << "\n {\"start_cycles\": " << record.start_cycles + << ", \"end_cycles\": " << record.end_cycles << ", \"loop_iter\": " << record.loop_iter + << ", \"kind\": \"" << record.kind << "\", \"tasks_processed\": " << record.tasks_processed + << ", \"task_id\": "; + if (record.has_task) scheduler_json << record.task_id; + else scheduler_json << "null"; + scheduler_json << "}"; + } + if (!records[worker].empty()) scheduler_json << "\n "; + scheduler_json << "], \"metrics\": []}"; + first_stream = false; + } + if (!first_stream) scheduler_json << "\n "; + scheduler_json << "]\n }"; + const std::string scheduler_payload = scheduler_json.str(); + if (!api->publish_chip_swimlane_extension( + ChipSwimlaneExtensionSection::SchedulerRecords, scheduler_payload.c_str(), scheduler_payload.size() + )) { + LOG_WARN("A5 HBG: failed to publish AICore Scheduler records"); + return false; + } + return true; +} + +extern "C" bool publish_runtime_chip_swimlane_extensions(Runtime *runtime) noexcept { + try { + if (runtime == nullptr) return true; + const HostApi *api = nullptr; + { + std::scoped_lock lock(scheduler_state_owners_mutex); + auto it = scheduler_state_owners.find(runtime); + if (it == scheduler_state_owners.end()) return true; + api = it->second.api; + } + return api != nullptr && publish_aicore_scheduler_profiling(runtime, api); + } catch (...) { + return false; + } +} + // host_build_graph is host-orchestration-first: the HOST dlopens the // orchestration .so and runs it to completion. Every cross-task reference the // shared memory and arena carry is an offset or an index from its own block, so @@ -804,7 +1080,10 @@ bool create_scheduler_state( } AicoreSchedulerLayout layout{}; - if (!scheduler_plan_layout(static_cast(total_tasks), aic_task_count, aiv_task_count, &layout) || + if (!scheduler_plan_layout( + static_cast(total_tasks), aic_task_count, aiv_task_count, &layout, + api->chip_swimlane_level() >= static_cast(ChipSwimlaneLevel::SCHED_PHASES) + ) || layout.total_size > std::numeric_limits::max() - (SCHEDULER_STATE_ALIGNMENT - 1)) { LOG_ERROR("A5 HBG AICore scheduler: scheduler state layout overflow"); return false; @@ -931,7 +1210,8 @@ bool create_scheduler_state( { std::scoped_lock lock(scheduler_state_owners_mutex); scheduler_state_owners.emplace( - runtime, SchedulerStateOwner{allocation, reinterpret_cast(aligned_address), allocation_size, layout} + runtime, + SchedulerStateOwner{allocation, reinterpret_cast(aligned_address), allocation_size, layout, api} ); } LOG_INFO("A5 HBG: selected AICore Scheduler for %d tasks", total_tasks); diff --git a/src/a5/runtime/host_build_graph/runtime/scheduler/scheduler_completion.h b/src/a5/runtime/host_build_graph/runtime/scheduler/scheduler_completion.h index dddc6e6c58..fa85d2aea4 100644 --- a/src/a5/runtime/host_build_graph/runtime/scheduler/scheduler_completion.h +++ b/src/a5/runtime/host_build_graph/runtime/scheduler/scheduler_completion.h @@ -45,10 +45,14 @@ inline __aicore__ bool scheduler_service_cluster_completion_slot( return false; } - const bool record_timeline = timing != nullptr; + const bool record_timeline = trace_enabled; uint64_t operation_start = record_timeline ? scheduler_cycles() : 0; scheduler_observe_cache_line(slot); const int64_t task_id = slot->task_id; + if (task_id < 0 || static_cast(task_id) >= graph.task_count) { + scheduler_record_error(run_control, task_id, SchedulerGraphResult::INVALID_TASK_ID, &graph, scheduler); + return false; + } if (slot->gang != 0) { scheduler_record_error( run_control, task_id, SchedulerGraphResult::UNSUPPORTED_SHAPE, &graph, scheduler, @@ -56,6 +60,56 @@ inline __aicore__ bool scheduler_service_cluster_completion_slot( ); return false; } + __gm__ SchedulerTaskMetadata *metadata = scheduler_task_metadata_at(scheduler_state_base, scheduler, task_id); + scheduler_observe_cache_line(metadata); + const bool task_timing_enabled = + metadata->timing_slot >= 0 && metadata->timing_slot < SCHEDULER_TASK_TIMING_SLOT_COUNT; + __gm__ SchedulerExecutorTaskTrace *executor_trace = &slot->executor_trace; + if (trace_enabled || task_timing_enabled) { + if (scheduler_gm_query(executor_trace->generation) != completed_generation) { + scheduler_record_error( + run_control, task_id, SchedulerGraphResult::INVALID_ARGUMENTS, &graph, scheduler, + SchedulerErrorSite::COMPLETION_GENERATION_MISMATCH + ); + return false; + } + scheduler_observe_cache_line(executor_trace); + scheduler_observe_cache_line(&executor_trace->completion_inbox_index); + } + __gm__ SchedulerTaskTrace *completed_trace = nullptr; + if (trace_enabled || task_timing_enabled) { + __gm__ SchedulerTaskTrace *traces = + scheduler_state_at(scheduler_state_base, scheduler->trace_cells_offset); + completed_trace = &traces[task_id]; + } + if (trace_enabled) { + scheduler_observe_cache_line(completed_trace); + scheduler_observe_cache_line(&completed_trace->kernel_start_cycles); + scheduler_observe_cache_line(&completed_trace->ready_transition_cycles); + scheduler_observe_cache_line(&completed_trace->dispatch_start_cycles); + scheduler_observe_cache_line(&completed_trace->refill_scheduler_worker_id); + scheduler_observe_cache_line(&completed_trace->descriptor_cache_observed_cycles); + completed_trace->kernel_start_cycles = executor_trace->kernel_start_cycles; + completed_trace->kernel_end_cycles = executor_trace->kernel_end_cycles; + completed_trace->completion_end_cycles = executor_trace->completion_end_cycles; + completed_trace->ready_scan_start_cycles = executor_trace->ready_scan_start_cycles; + completed_trace->ready_observe_cycles = executor_trace->ready_observe_cycles; + completed_trace->completion_bookkeeping_end_cycles = executor_trace->completion_bookkeeping_end_cycles; + completed_trace->completion_id = executor_trace->completion_id; + completed_trace->completion_inbox_index = executor_trace->completion_inbox_index; + scheduler_observe_cache_line(&target->trace_aicore_entry_cycles); + scheduler_observe_cache_line(&target->trace_register_release_cycles); + completed_trace->descriptor_cache_observed_cycles = target->trace_descriptor_cache_observed_cycles; + completed_trace->aicore_entry_cycles = target->trace_aicore_entry_cycles; + completed_trace->handshake_publish_cycles = target->trace_handshake_publish_cycles; + completed_trace->register_release_cycles = target->trace_register_release_cycles; + completed_trace->complete_start_cycles = operation_start; + completed_trace->complete_scheduler_worker_id = scheduler->worker_index; + completed_trace->complete_loop_iter = scheduler->profiling_loop_iter; + } else if (completed_trace != nullptr) { + completed_trace->kernel_start_cycles = executor_trace->kernel_start_cycles; + completed_trace->kernel_end_cycles = executor_trace->kernel_end_cycles; + } const uint8_t completed_subtask_slot = slot->subtask_slot; scheduler_gm_store(completion_line->completed_generations[pending_slot], UINT32_C(0)); uint64_t operation_end = record_timeline ? scheduler_cycles() : 0; @@ -75,12 +129,6 @@ inline __aicore__ bool scheduler_service_cluster_completion_slot( )) return false; if (timing != nullptr) timing->ready_publish_cycles += ready_publish_cycles; - uint64_t resolved_count_start = timing == nullptr ? 0 : scheduler_cycles(); - scheduler_gm_fetch_add(run_control->resolved_task_count, UINT64_C(1)); - if (timing != nullptr) { - finalize_cycles = scheduler_cycles() - resolved_count_start; - timing->finalize_cycles += finalize_cycles; - } refill_start_cycles = record_timeline ? scheduler_cycles() : 0; SchedulerReadyClaim ready{}; bool ready_available = replacement_ready != nullptr; @@ -126,6 +174,36 @@ inline __aicore__ bool scheduler_service_cluster_completion_slot( } const uint64_t completion_end = record_timeline ? scheduler_cycles() : 0; if (timing != nullptr) timing->finalize_cycles += completion_end - operation_start; + if (trace_enabled) { + completed_trace->complete_end_cycles = completion_end; + if (refilled) { + completed_trace->refill_scheduler_worker_id = scheduler->worker_index; + completed_trace->refill_start_cycles = refill_start_cycles; + completed_trace->refill_end_cycles = refill_end_cycles; + completed_trace->refill_task_id = static_cast(ready.task_id); + completed_trace->refill_loop_iter = scheduler->profiling_loop_iter; + } + scheduler_writeback_cache_line(completed_trace); + scheduler_writeback_cache_line(&completed_trace->kernel_start_cycles); + scheduler_writeback_cache_line(&completed_trace->ready_transition_cycles); + scheduler_writeback_cache_line(&completed_trace->dispatch_start_cycles); + scheduler_writeback_cache_line(&completed_trace->refill_scheduler_worker_id); + scheduler_writeback_cache_line(&completed_trace->descriptor_cache_observed_cycles); + scheduler_cache_barrier(); + scheduler_gm_publish(completed_trace->valid, UINT64_C(1)); + // AICPU treats resolved_task_count as the graph-completion token. Keep + // valid globally ordered before that token so host collection cannot + // race the final trace publication. + scheduler_cache_barrier(); + } else if (completed_trace != nullptr) { + scheduler_publish_cache_line(&completed_trace->kernel_start_cycles); + } + const uint64_t resolved_count_start = timing == nullptr ? 0 : scheduler_cycles(); + scheduler_gm_fetch_add(run_control->resolved_task_count, UINT64_C(1)); + if (timing != nullptr) { + finalize_cycles = scheduler_cycles() - resolved_count_start; + timing->finalize_cycles += finalize_cycles; + } if (direct_refilled != nullptr) *direct_refilled = refilled; return true; } diff --git a/src/a5/runtime/host_build_graph/runtime/scheduler/scheduler_layout.h b/src/a5/runtime/host_build_graph/runtime/scheduler/scheduler_layout.h index 3f46fb9cb2..fbf2840892 100644 --- a/src/a5/runtime/host_build_graph/runtime/scheduler/scheduler_layout.h +++ b/src/a5/runtime/host_build_graph/runtime/scheduler/scheduler_layout.h @@ -39,6 +39,8 @@ struct AicoreSchedulerLayout { uint64_t ready_owner_states_offset; uint64_t ready_directory_offset; uint64_t trace_cells_offset; + uint64_t activity_buffers_offset; + uint64_t activity_buffer_capacity; uint64_t gang_coordinator_offset; uint64_t gang_cohorts_offset; uint64_t gang_participants_offset; diff --git a/src/a5/runtime/host_build_graph/runtime/scheduler/scheduler_ready.h b/src/a5/runtime/host_build_graph/runtime/scheduler/scheduler_ready.h index 264e51fc4f..771c951da9 100644 --- a/src/a5/runtime/host_build_graph/runtime/scheduler/scheduler_ready.h +++ b/src/a5/runtime/host_build_graph/runtime/scheduler/scheduler_ready.h @@ -123,7 +123,7 @@ struct SchedulerDispatchFillTiming { }; inline __aicore__ uint64_t scheduler_cycles() { -#if defined(__CCE_AICORE__) +#if defined(__CCE_AICORE__) || defined(__CPU_SIM) return get_sys_cnt_aicore(); #else return 0; @@ -276,6 +276,41 @@ inline __aicore__ __gm__ SchedulerWorkerContext *scheduler_worker_context_at( ); } +inline __aicore__ __gm__ SchedulerActivityBuffer * +scheduler_activity_buffer_at(__gm__ void *scheduler_state_base, __gm__ const SchedulerWorkerContext *context) { + if (context->activity_buffers_offset == 0 || context->worker_index >= SCHEDULER_WORKER_CAPACITY) return nullptr; + return scheduler_state_at( + scheduler_state_base, context->activity_buffers_offset + context->worker_index * sizeof(SchedulerActivityBuffer) + ); +} + +inline __aicore__ void scheduler_append_activity( + __gm__ void *scheduler_state_base, __gm__ SchedulerWorkerContext *context, AicoreSchedulerKind kind, + uint64_t start_cycles, uint64_t end_cycles, uint32_t tasks_processed = 0 +) { + __gm__ SchedulerActivityBuffer *buffer = scheduler_activity_buffer_at(scheduler_state_base, context); + if (buffer == nullptr || end_cycles < start_cycles) return; + const uint64_t capture_counts = scheduler_gm_query_u32_pair(&buffer->committed); + const uint32_t committed = static_cast(capture_counts); + const uint32_t capacity = buffer->capacity; + if (committed >= capacity) { + scheduler_gm_store(buffer->dropped, static_cast(capture_counts >> 32) + 1); + return; + } + __gm__ AicoreSchedulerRecord *record = &buffer->records[committed]; + record->start_time = start_cycles; + record->end_time = end_cycles; + record->task_id = UINT64_MAX; + record->loop_iter = static_cast(context->profiling_loop_iter); + record->kind = kind; + record->tasks_processed = tasks_processed; + record->reserved = 0; + scheduler_writeback_cache_line(record); + scheduler_writeback_cache_line(&record->reserved); + scheduler_cache_barrier(); + scheduler_gm_store(buffer->committed, committed + 1); +} + inline __aicore__ __gm__ SchedulerDispatchSlot *scheduler_dispatch_slot_at( __gm__ void *scheduler_state_base, __gm__ const SchedulerWorkerContext *context, uint64_t worker_id, uint32_t slot ) { @@ -905,6 +940,7 @@ inline __aicore__ bool scheduler_fill_dispatch_slot( slot_claim.slot_index >= SCHEDULER_PENDING_SLOT_COUNT) return false; const bool record_timeline = timing != nullptr; + const uint64_t dispatch_start_cycles = trace_enabled ? scheduler_cycles() : 0; uint64_t operation_start = record_timeline ? scheduler_cycles() : 0; __gm__ SchedulerTaskMetadata *metadata_source = scheduler_task_metadata_at(scheduler_state_base, scheduler, ready_claim.task_id); @@ -1018,6 +1054,24 @@ inline __aicore__ bool scheduler_fill_dispatch_slot( } uint64_t publish_end = record_timeline ? scheduler_cycles() : 0; if (timing != nullptr) timing->publish_cycles += publish_end - materialize_end; + if (trace_enabled) { + __gm__ SchedulerTaskTrace *traces = + scheduler_state_at(scheduler_state_base, scheduler->trace_cells_offset); + __gm__ SchedulerTaskTrace *trace = &traces[ready_claim.task_id]; + trace->ready_source = static_cast(ready_claim.source); + trace->worker_id = slot_claim.worker_id; + trace->task_id = static_cast(ready_claim.task_id); + trace->claim_worker_id = scheduler->worker_index; + trace->claim_start_cycles = ready_claim.claim_start_cycles; + trace->claim_end_cycles = ready_claim.claim_end_cycles; + trace->claim_loop_iter = scheduler->profiling_loop_iter; + trace->dispatch_start_cycles = dispatch_start_cycles; + trace->dispatch_end_cycles = scheduler_cycles(); + trace->dispatch_scheduler_worker_id = scheduler->worker_index; + trace->dispatch_loop_iter = scheduler->profiling_loop_iter; + scheduler_publish_cache_line(trace); + scheduler_publish_cache_line(&trace->dispatch_start_cycles); + } scheduler_gm_publish( slot->publication, scheduler_dispatch_publication(generation, SchedulerDispatchSlotState::READY) ); @@ -1045,6 +1099,7 @@ inline __aicore__ bool scheduler_resolve_completion( scheduler_observe_cache_line(&control->next_waiter); control->completion_resolve_start_cycles = resolve_start; control->scheduler_worker_id = context->worker_index; + control->completion_resolve_loop_iter = context->profiling_loop_iter; } int64_t waiter = scheduler_gm_exchange(control->wake_list_head, SCHEDULER_WAKE_LIST_CLOSED); if (waiter == SCHEDULER_WAKE_LIST_CLOSED) { diff --git a/src/a5/runtime/host_build_graph/runtime/scheduler/scheduler_types.h b/src/a5/runtime/host_build_graph/runtime/scheduler/scheduler_types.h index eb78eb7f6b..8047857012 100644 --- a/src/a5/runtime/host_build_graph/runtime/scheduler/scheduler_types.h +++ b/src/a5/runtime/host_build_graph/runtime/scheduler/scheduler_types.h @@ -627,6 +627,7 @@ inline constexpr uint32_t SCHEDULER_CORE_TYPE_COUNT = 2; inline constexpr uint32_t SCHEDULER_CLUSTER_CAPACITY = SCHEDULER_WORKER_CAPACITY / 3; inline constexpr uint32_t SCHEDULER_CAPACITY = SCHEDULER_CLUSTER_CAPACITY; inline constexpr uint32_t SCHEDULER_GANG_COHORT_COUNT = 2; +inline constexpr uint32_t SCHEDULER_ACTIVITY_CAPACITY = 1024; inline constexpr uint32_t SCHEDULER_READY_DIRECTORY_OWNERS_PER_SHARD = 7; inline constexpr uint32_t SCHEDULER_READY_DIRECTORY_SHARD_COUNT = (SCHEDULER_CAPACITY + SCHEDULER_READY_DIRECTORY_OWNERS_PER_SHARD - 1) / SCHEDULER_READY_DIRECTORY_OWNERS_PER_SHARD; @@ -648,6 +649,38 @@ enum class SchedulerReadySource : uint8_t { STOLEN = 1, }; +enum class AicoreSchedulerKind : uint32_t { + Complete = 0, + Dispatch = 1, + Resolve = 6, + Bootstrap = 32, + Fanin = 33, + ReadyClaim = 34, + ReadySteal = 35, + DirectRefill = 36, + Idle = 37, +}; + +struct AicoreSchedulerRecord { + uint64_t start_time; + uint64_t end_time; + uint64_t task_id; + uint32_t loop_iter; + AicoreSchedulerKind kind; + uint32_t tasks_processed; + uint32_t reserved; +}; +static_assert(sizeof(AicoreSchedulerRecord) == 40, "AICore scheduler record layout changed"); + +struct alignas(64) SchedulerActivityBuffer { + volatile uint32_t committed; + volatile uint32_t dropped; + uint32_t capacity; + uint32_t reserved; + AicoreSchedulerRecord records[SCHEDULER_ACTIVITY_CAPACITY]; +}; +static_assert(sizeof(SchedulerActivityBuffer) % 64 == 0, "scheduler activity buffer must be cache aligned"); + enum class SchedulerDispatchSlotState : uint8_t { EMPTY = 0, FREE = 1, @@ -740,7 +773,8 @@ struct alignas(128) SchedulerTaskControl { uint64_t completion_resolve_end_cycles; uint64_t ready_publish_cycles; uint64_t scheduler_worker_id; - uint8_t scheduler_line_padding[16]; + uint64_t completion_resolve_loop_iter; + uint8_t scheduler_line_padding[8]; }; struct alignas(64) SchedulerCompletionInbox { @@ -858,8 +892,25 @@ struct alignas(128) SchedulerReadyDirectory { volatile uint64_t bootstrap_ready_types[SCHEDULER_WORKER_CAPACITY]; }; +// The Executor publishes this per-slot payload before the completion generation. +// The generation is the release/acquire hand-off to the Scheduler; neither side +// writes the final per-task trace concurrently. +struct alignas(128) SchedulerExecutorTaskTrace { + volatile uint64_t generation; + uint64_t kernel_start_cycles; + uint64_t kernel_end_cycles; + uint64_t ready_scan_start_cycles; + uint64_t ready_observe_cycles; + uint64_t completion_end_cycles; + uint64_t completion_bookkeeping_end_cycles; + uint64_t completion_id; + + uint64_t completion_inbox_index; + uint64_t reserved[7]; +}; + // Scheduler-owned metadata occupies the first line. The Executor polls only -// publication in the second line. +// publication in the second line and owns the trailing trace payload. struct alignas(128) SchedulerDispatchSlot { int64_t task_id; uint64_t ready_inbox_index; @@ -881,6 +932,8 @@ struct alignas(128) SchedulerDispatchSlot { volatile uint64_t publication; uint8_t publication_padding[56]; + + SchedulerExecutorTaskTrace executor_trace; }; // Stable device-side localization for the first scheduler failure. These values @@ -1036,7 +1089,7 @@ struct alignas(128) SchedulerWorkerContext { volatile uint64_t task_metadata_offset; volatile uint64_t ready_inboxes_offset; volatile uint64_t ready_directory_offset; - uint64_t scheduling_reserved; + volatile uint64_t activity_buffers_offset; volatile uint64_t worker_contexts_offset; volatile uint64_t dispatch_slots_offset; volatile uint64_t callable_addresses_offset; @@ -1061,7 +1114,8 @@ struct alignas(128) SchedulerWorkerContext { volatile uint64_t scheduler_worker_id; volatile uint64_t is_scheduler; volatile uint64_t cluster_worker_ids[3]; - uint64_t topology_reserved[3]; + volatile uint64_t profiling_loop_iter; + uint64_t topology_reserved[2]; uint64_t bootstrap_task_count; uint64_t ready_enqueue_count; @@ -1084,7 +1138,11 @@ struct alignas(128) SchedulerWorkerContext { uint64_t wake_close_count; uint64_t completion_enqueue_count; uint64_t completion_resolve_count; - uint64_t completion_stats_reserved[6]; + uint64_t trace_aicore_entry_cycles; + uint64_t trace_handshake_publish_cycles; + uint64_t trace_register_release_cycles; + uint64_t trace_descriptor_cache_observed_cycles; + uint64_t completion_stats_reserved[2]; uint64_t ready_to_kernel_cycles; uint64_t ready_to_kernel_max_cycles; uint64_t payload_cycles; @@ -1108,6 +1166,8 @@ struct alignas(128) SchedulerWorkerContext { }; struct alignas(128) SchedulerTaskTrace { + // Dispatch publishes this line before READY; completion publishes valid. + // Bootstrap owns only the fanin line and must not dirty this cache line. volatile uint64_t valid; uint64_t ready_source; uint64_t worker_id; @@ -1115,7 +1175,7 @@ struct alignas(128) SchedulerTaskTrace { uint64_t claim_worker_id; uint64_t claim_start_cycles; uint64_t claim_end_cycles; - uint64_t previous_trace_commit_end_cycles; + uint64_t claim_loop_iter; uint64_t kernel_start_cycles; uint64_t kernel_end_cycles; @@ -1127,34 +1187,33 @@ struct alignas(128) SchedulerTaskTrace { uint64_t completion_inbox_index; uint64_t ready_transition_cycles; - uint64_t inter_task_completion_service_cycles; - uint64_t inter_task_dispatch_aic_cycles; - uint64_t inter_task_dispatch_aiv_cycles; - uint64_t inter_task_ready_poll_cycles; - uint64_t inter_task_backoff_cycles; + uint64_t fanin_start_cycles; + uint64_t fanin_end_cycles; + uint64_t fanin_scheduler_worker_id; + uint64_t fanin_loop_iter; uint64_t aicore_entry_cycles; uint64_t handshake_publish_cycles; - uint64_t register_release_cycles; - uint64_t descriptor_cache_observed_cycles; - uint64_t completion_prepare_start_cycles; + + // The dispatching Scheduler owns this cache line through completion. + uint64_t dispatch_start_cycles; + uint64_t dispatch_end_cycles; + uint64_t dispatch_scheduler_worker_id; + uint64_t dispatch_loop_iter; + uint64_t complete_start_cycles; + uint64_t complete_end_cycles; + uint64_t complete_scheduler_worker_id; + uint64_t complete_loop_iter; uint64_t refill_scheduler_worker_id; uint64_t refill_start_cycles; uint64_t refill_end_cycles; uint64_t refill_task_id; - uint64_t inter_task_completion_refill_cycles; - - uint64_t inter_task_completion_scan_cycles; - uint64_t inter_task_completion_consume_cycles; - uint64_t inter_task_completion_resolve_cycles; - uint64_t inter_task_completion_ready_publish_cycles; - uint64_t inter_task_completion_finalize_cycles; - uint64_t inter_task_gang_service_cycles; - uint64_t inter_task_dispatch_probe_cycles[SCHEDULER_CORE_TYPE_COUNT]; - uint64_t inter_task_dispatch_claim_cycles[SCHEDULER_CORE_TYPE_COUNT]; - uint64_t inter_task_dispatch_prepare_cycles[SCHEDULER_CORE_TYPE_COUNT]; - uint64_t inter_task_dispatch_materialize_cycles[SCHEDULER_CORE_TYPE_COUNT]; - uint64_t inter_task_dispatch_publish_cycles[SCHEDULER_CORE_TYPE_COUNT]; + uint64_t refill_loop_iter; + uint64_t completion_reserved[3]; + + // The completion Scheduler consolidates the Executor's staged timing here. + uint64_t descriptor_cache_observed_cycles; + uint64_t executor_reserved[7]; }; static_assert(sizeof(SchedulerTaskMetadata) == 16, "task metadata layout changed"); @@ -1209,9 +1268,17 @@ static_assert( 128 * 128), "ready directory layout changed" ); -static_assert(sizeof(SchedulerDispatchSlot) == 128, "dispatch slot must occupy two cache lines"); +static_assert(sizeof(SchedulerExecutorTaskTrace) == 128, "executor trace must occupy two cache lines"); +static_assert(alignof(SchedulerExecutorTaskTrace) == 128, "executor trace alignment changed"); +static_assert(offsetof(SchedulerExecutorTaskTrace, generation) == 0, "executor trace generation must lead payload"); +static_assert( + offsetof(SchedulerExecutorTaskTrace, completion_inbox_index) == 64, + "executor trace lifecycle must start on its second cache line" +); +static_assert(sizeof(SchedulerDispatchSlot) == 256, "dispatch slot layout changed"); static_assert(alignof(SchedulerDispatchSlot) == 128, "dispatch slot alignment changed"); static_assert(offsetof(SchedulerDispatchSlot, publication) == 64, "dispatch publication needs its own line"); +static_assert(offsetof(SchedulerDispatchSlot, executor_trace) == 128, "executor trace needs exclusive cache lines"); static_assert(sizeof(SchedulerRunControl) == 384, "run control layout changed"); static_assert(alignof(SchedulerRunControl) == 128, "run control alignment changed"); static_assert(offsetof(SchedulerRunControl, executed_task_count) == 128, "lifecycle atomics need their own line"); @@ -1228,6 +1295,22 @@ static_assert(offsetof(SchedulerWorkerContext, wake_cas_retry_count) == 512, "wa static_assert(offsetof(SchedulerWorkerContext, completion_enqueue_cycles) == 640, "termination stats offset changed"); static_assert(offsetof(SchedulerWorkerContext, scheduler_tail_trace) == 768, "scheduler tail trace offset changed"); static_assert(sizeof(SchedulerTaskTrace) == 384, "task trace layout changed"); +static_assert( + offsetof(SchedulerTaskTrace, dispatch_start_cycles) % 64 == 0, + "Scheduler-owned dispatch and completion fields must begin on a cache-line boundary" +); +static_assert( + offsetof(SchedulerTaskTrace, complete_loop_iter) / 64 == offsetof(SchedulerTaskTrace, dispatch_start_cycles) / 64, + "dispatch and completion fields must share their Scheduler-owned cache line" +); +static_assert( + offsetof(SchedulerTaskTrace, refill_scheduler_worker_id) % 64 == 0, + "Scheduler-owned refill fields must begin on a cache-line boundary" +); +static_assert( + offsetof(SchedulerTaskTrace, descriptor_cache_observed_cycles) % 64 == 0, + "consolidated descriptor timing must begin on a cache-line boundary" +); template inline __aicore__ __gm__ T *scheduler_state_at(__gm__ void *base, uint64_t offset) { @@ -1237,6 +1320,10 @@ inline __aicore__ __gm__ T *scheduler_state_at(__gm__ void *base, uint64_t offse #if !defined(__CCE_AICORE__) #include static_assert(std::is_standard_layout_v && std::is_trivially_copyable_v); +static_assert(std::is_standard_layout_v && std::is_trivially_copyable_v); +static_assert( + std::is_standard_layout_v && std::is_trivially_copyable_v +); static_assert(std::is_standard_layout_v && std::is_trivially_copyable_v); static_assert(std::is_standard_layout_v && std::is_trivially_copyable_v); static_assert( @@ -1263,6 +1350,7 @@ static_assert( std::is_standard_layout_v && std::is_trivially_copyable_v ); static_assert(std::is_standard_layout_v && std::is_trivially_copyable_v); +static_assert(std::is_standard_layout_v && std::is_trivially_copyable_v); inline bool scheduler_layout_checked_add(uint64_t lhs, uint64_t rhs, uint64_t *out) { if (out == nullptr || rhs > UINT64_MAX - lhs) return false; @@ -1296,7 +1384,8 @@ inline bool scheduler_layout_reserve(uint64_t *cursor, uint64_t size, uint64_t a } inline bool scheduler_plan_layout( - uint64_t task_count, uint64_t aic_task_count, uint64_t aiv_task_count, AicoreSchedulerLayout *layout + uint64_t task_count, uint64_t aic_task_count, uint64_t aiv_task_count, AicoreSchedulerLayout *layout, + bool enable_activity_profiling = false ) { if (layout == nullptr || aic_task_count > task_count || aiv_task_count > task_count) return false; AicoreSchedulerLayout next{}; @@ -1308,42 +1397,44 @@ inline bool scheduler_plan_layout( #define SCHEDULER_RESERVE_ARRAY(count, type, field) \ (scheduler_layout_checked_mul((count), sizeof(type), &bytes) && \ scheduler_layout_reserve(&cursor, bytes, alignof(type), &next.field)) - if (!scheduler_layout_reserve( + bool valid = + scheduler_layout_reserve( &cursor, sizeof(SchedulerRunControl), alignof(SchedulerRunControl), &next.run_control_offset - ) || - !SCHEDULER_RESERVE_ARRAY(SCHEDULER_WORKER_CAPACITY, AicpuCoreLifecycleTrace, aicpu_lifecycle_traces_offset) || - !SCHEDULER_RESERVE_ARRAY(SCHEDULER_WORKER_CAPACITY, SchedulerWorkerContext, worker_contexts_offset) || - !SCHEDULER_RESERVE_ARRAY( + ) && + SCHEDULER_RESERVE_ARRAY(SCHEDULER_WORKER_CAPACITY, AicpuCoreLifecycleTrace, aicpu_lifecycle_traces_offset) && + SCHEDULER_RESERVE_ARRAY(SCHEDULER_WORKER_CAPACITY, SchedulerWorkerContext, worker_contexts_offset) && + SCHEDULER_RESERVE_ARRAY( SCHEDULER_WORKER_CAPACITY * SCHEDULER_PENDING_SLOT_COUNT, DispatchPayload, dispatch_payloads_offset - ) || - !SCHEDULER_RESERVE_ARRAY( + ) && + SCHEDULER_RESERVE_ARRAY( SCHEDULER_WORKER_CAPACITY * SCHEDULER_PENDING_SLOT_COUNT, SchedulerDispatchSlot, dispatch_slots_offset - ) || - !SCHEDULER_RESERVE_ARRAY(SCHEDULER_CALLABLE_CAPACITY, uint64_t, callable_addresses_offset) || - !SCHEDULER_RESERVE_ARRAY(task_count, SchedulerTaskMetadata, task_metadata_offset) || - !SCHEDULER_RESERVE_ARRAY(task_count, SchedulerTaskControl, task_controls_offset) || - !SCHEDULER_RESERVE_ARRAY(SCHEDULER_WORKER_CAPACITY, SchedulerCompletionInbox, completion_inboxes_offset) || - !SCHEDULER_RESERVE_ARRAY( + ) && + SCHEDULER_RESERVE_ARRAY(SCHEDULER_CALLABLE_CAPACITY, uint64_t, callable_addresses_offset) && + SCHEDULER_RESERVE_ARRAY(task_count, SchedulerTaskMetadata, task_metadata_offset) && + SCHEDULER_RESERVE_ARRAY(task_count, SchedulerTaskControl, task_controls_offset) && + SCHEDULER_RESERVE_ARRAY(SCHEDULER_WORKER_CAPACITY, SchedulerCompletionInbox, completion_inboxes_offset) && + SCHEDULER_RESERVE_ARRAY( SCHEDULER_CORE_TYPE_COUNT * SCHEDULER_WORKER_CAPACITY, SchedulerReadyInbox, ready_inboxes_offset - ) || - !SCHEDULER_RESERVE_ARRAY(SCHEDULER_CAPACITY, SchedulerReadyOwnerState, ready_owner_states_offset) || - !scheduler_layout_reserve( + ) && + SCHEDULER_RESERVE_ARRAY(SCHEDULER_CAPACITY, SchedulerReadyOwnerState, ready_owner_states_offset) && + scheduler_layout_reserve( &cursor, sizeof(SchedulerReadyDirectory), alignof(SchedulerReadyDirectory), &next.ready_directory_offset - ) || - !scheduler_layout_reserve( + ) && + scheduler_layout_reserve( &cursor, sizeof(SchedulerGangCoordinator), alignof(SchedulerGangCoordinator), &next.gang_coordinator_offset - ) || - !SCHEDULER_RESERVE_ARRAY(SCHEDULER_GANG_COHORT_COUNT, SchedulerGangCohort, gang_cohorts_offset) || - !SCHEDULER_RESERVE_ARRAY( + ) && + SCHEDULER_RESERVE_ARRAY(SCHEDULER_GANG_COHORT_COUNT, SchedulerGangCohort, gang_cohorts_offset) && + SCHEDULER_RESERVE_ARRAY( SCHEDULER_GANG_COHORT_COUNT * SCHEDULER_CLUSTER_CAPACITY, SchedulerGangParticipant, gang_participants_offset - ) || - !SCHEDULER_RESERVE_ARRAY(SCHEDULER_CLUSTER_CAPACITY, SchedulerGangCommand, gang_commands_offset) || - !SCHEDULER_RESERVE_ARRAY(task_count, SchedulerTaskTrace, trace_cells_offset) || - !scheduler_layout_checked_align(cursor, SCHEDULER_STATE_ALIGNMENT, &next.total_size)) { -#undef SCHEDULER_RESERVE_ARRAY - return false; - } + ) && + SCHEDULER_RESERVE_ARRAY(SCHEDULER_CLUSTER_CAPACITY, SchedulerGangCommand, gang_commands_offset) && + SCHEDULER_RESERVE_ARRAY(task_count, SchedulerTaskTrace, trace_cells_offset); + if (valid && enable_activity_profiling) + valid = SCHEDULER_RESERVE_ARRAY(SCHEDULER_WORKER_CAPACITY, SchedulerActivityBuffer, activity_buffers_offset); + next.activity_buffer_capacity = enable_activity_profiling ? SCHEDULER_ACTIVITY_CAPACITY : 0; + if (valid) valid = scheduler_layout_checked_align(cursor, SCHEDULER_STATE_ALIGNMENT, &next.total_size); #undef SCHEDULER_RESERVE_ARRAY + if (!valid) return false; *layout = next; return true; } @@ -1377,10 +1468,16 @@ inline bool scheduler_init_data_from_layout(void *base, const AicoreSchedulerLay contexts[worker].cluster_index = UINT64_MAX; contexts[worker].scheduler_index = UINT64_MAX; contexts[worker].scheduler_worker_id = UINT64_MAX; + contexts[worker].activity_buffers_offset = layout.activity_buffers_offset; contexts[worker].cluster_worker_ids[0] = UINT64_MAX; contexts[worker].cluster_worker_ids[1] = UINT64_MAX; contexts[worker].cluster_worker_ids[2] = UINT64_MAX; } + if (layout.activity_buffers_offset != 0) { + auto *buffers = scheduler_state_at(base, layout.activity_buffers_offset); + for (uint64_t worker = 0; worker < SCHEDULER_WORKER_CAPACITY; ++worker) + buffers[worker].capacity = SCHEDULER_ACTIVITY_CAPACITY; + } auto *coordinator = scheduler_state_at(base, layout.gang_coordinator_offset); coordinator->active_dispatch_cohort = UINT64_MAX; coordinator->cohort_count = SCHEDULER_GANG_COHORT_COUNT; diff --git a/tests/st/a5/host_build_graph/dfx/chip_swimlane/kernels/aiv/kernel_empty.cpp b/tests/st/a5/host_build_graph/dfx/chip_swimlane/kernels/aiv/kernel_empty.cpp new file mode 100644 index 0000000000..6a73f725c4 --- /dev/null +++ b/tests/st/a5/host_build_graph/dfx/chip_swimlane/kernels/aiv/kernel_empty.cpp @@ -0,0 +1,23 @@ +/* + * Copyright (c) PyPTO Contributors. + * This program is free software, you can redistribute it and/or modify it under the terms and conditions of + * CANN Open Software License Agreement Version 2.0 (the "License"). + * Please refer to the License for details. You may not use this file except in compliance with the License. + * THIS SOFTWARE IS PROVIDED ON AN "AS IS" BASIS, WITHOUT WARRANTIES OF ANY KIND, EITHER EXPRESS OR IMPLIED, + * INCLUDING BUT NOT LIMITED TO NON-INFRINGEMENT, MERCHANTABILITY, OR FITNESS FOR A PARTICULAR PURPOSE. + * See LICENSE in the root of the software repository for the full text of the License. + * ----------------------------------------------------------------------------------------------------------- + */ + +#include +#include + +#ifndef __gm__ +#define __gm__ +#endif + +#ifndef __aicore__ +#define __aicore__ [aicore] +#endif + +extern "C" __aicore__ void kernel_entry(__gm__ int64_t *args) { (void)args; } diff --git a/tests/st/a5/host_build_graph/dfx/chip_swimlane/kernels/orchestration/scheduler_phases_orch.cpp b/tests/st/a5/host_build_graph/dfx/chip_swimlane/kernels/orchestration/scheduler_phases_orch.cpp index 1a95d8d9bf..02b74d5e63 100644 --- a/tests/st/a5/host_build_graph/dfx/chip_swimlane/kernels/orchestration/scheduler_phases_orch.cpp +++ b/tests/st/a5/host_build_graph/dfx/chip_swimlane/kernels/orchestration/scheduler_phases_orch.cpp @@ -15,7 +15,9 @@ namespace { -constexpr int kNoopKernel = 0; +constexpr int kWriteKernel = 0; +constexpr int kEmptyKernel = 1; +constexpr int kFanout = 32; } // namespace @@ -29,13 +31,26 @@ __attribute__((visibility("default"))) OrchestrationConfig aicpu_orchestration_c __attribute__((visibility("default"))) void aicpu_orchestration_entry(const ChipTaskArgs &args) { const simpler::hbg::Tensor &input = args.tensor(0).ref(); - CoreTaskArgs normal_args; - normal_args.add_inout(input); - normal_args.launch_spec.set_block_num(1); - const TaskId normal_task = rt_submit_aiv_task(kNoopKernel, normal_args).task_id(); + CoreTaskArgs root_args; + root_args.launch_spec.set_block_num(1); + const TaskId root = rt_submit_aiv_task(kEmptyKernel, root_args).task_id(); + + TaskId children[kFanout]; + for (int child = 0; child < kFanout; ++child) { + CoreTaskArgs child_args; + child_args.set_dependencies(&root, 1); + child_args.launch_spec.set_block_num(1); + children[child] = rt_submit_aiv_task(kEmptyKernel, child_args).task_id(); + } + + CoreTaskArgs final_args; + final_args.add_inout(input); + final_args.set_dependencies(children, kFanout); + final_args.launch_spec.set_block_num(1); + const TaskId final_task = rt_submit_aiv_task(kWriteKernel, final_args).task_id(); CoreTaskArgs dummy_args; - dummy_args.set_dependencies(&normal_task, 1); + dummy_args.set_dependencies(&final_task, 1); rt_submit_dummy_task(dummy_args); } diff --git a/tests/st/a5/host_build_graph/dfx/chip_swimlane/test_scheduler_phases.py b/tests/st/a5/host_build_graph/dfx/chip_swimlane/test_scheduler_phases.py index 63be463304..b91cadc8b2 100644 --- a/tests/st/a5/host_build_graph/dfx/chip_swimlane/test_scheduler_phases.py +++ b/tests/st/a5/host_build_graph/dfx/chip_swimlane/test_scheduler_phases.py @@ -10,10 +10,13 @@ from __future__ import annotations +import json + import torch from simpler.task_interface import ArgDirection as D from simpler_setup import SceneTestCase, TaskArgsBuilder, TensorArg, scene_test +from simpler_setup.scene_test import _sanitize_for_filename @scene_test(level=2, runtime="host_build_graph") @@ -31,6 +34,12 @@ class TestSchedulerPhases(SceneTestCase): "core_type": "aiv", "signature": [D.INOUT], }, + { + "func_id": 1, + "source": "kernels/aiv/kernel_empty.cpp", + "core_type": "aiv", + "signature": [], + }, ], } @@ -51,6 +60,44 @@ def generate_args(self, params): def compute_golden(self, args, params): args.input[0] = 1 + def test_run(self, st_platform, st_worker, request): + super().test_run(st_platform, st_worker, request) + level = self._effective_enable_chip_swimlane(request) + if level == 0: + return + + for case in self._matching_cases(st_platform, request): + case_label = _sanitize_for_filename(f"TestSchedulerPhases_{case['name']}") + output_prefix = self._diagnostic_output_prefixes.get(case["name"]) + assert output_prefix is not None, f"no output directory created for {case_label}" + raw = json.loads((output_prefix / "chip_swimlane_records.json").read_text()) + aicore_rows = raw["aicore_tasks"] + assert len(aicore_rows) == 35, "task timing does not cover the fanout/fanin DAG and terminal dummy" + + if level >= 2: + scheduler_tasks = raw["scheduler_tasks"] + assert scheduler_tasks["schema_version"] == 1 + assert scheduler_tasks["producer"] == "aicore" + scheduler_rows = scheduler_tasks["records"] + assert len(scheduler_rows) == len(aicore_rows) + aicore_by_key = {(int(row[0]), int(row[2])): row for row in aicore_rows} + assert {(int(row[0]), int(row[1])) for row in scheduler_rows} == set(aicore_by_key) + for core_id, reg_task_id, dispatch_cycles, finish_cycles in scheduler_rows: + aicore_row = aicore_by_key[(int(core_id), int(reg_task_id))] + assert 0 < dispatch_cycles <= aicore_row[3] <= aicore_row[4] <= finish_cycles + assert raw["aicpu_lifecycle_records"], "AICPU lifecycle records are missing" + + if level >= 3: + streams = raw["scheduler_records"]["streams"] + assert streams, "A5 HBG AICore Scheduler records are missing" + assert all(stream["producer"] == "aicore" for stream in streams) + assert all(stream["capture"]["dropped"] == 0 for stream in streams) + emitted_kinds = {record["kind"] for stream in streams for record in stream["records"]} + required_kinds = {"bootstrap", "fanin", "dispatch", "complete", "resolve", "idle"} + assert required_kinds <= emitted_kinds, ( + f"missing Scheduler kinds: {sorted(required_kinds - emitted_kinds)}" + ) + if __name__ == "__main__": SceneTestCase.run_module(__name__) diff --git a/tests/st/a5/host_build_graph/single_core_dag/test_single_core_dag.py b/tests/st/a5/host_build_graph/single_core_dag/test_single_core_dag.py index 4c96921d3b..690a73be33 100644 --- a/tests/st/a5/host_build_graph/single_core_dag/test_single_core_dag.py +++ b/tests/st/a5/host_build_graph/single_core_dag/test_single_core_dag.py @@ -10,11 +10,13 @@ """Correctness gates for homogeneous and mixed AIC/AIV dependency graphs.""" import ctypes +import json import torch from simpler.task_interface import ArgDirection as D from simpler_setup import Scalar, SceneTestCase, TaskArgsBuilder, TensorArg, scene_test +from simpler_setup.scene_test import _sanitize_for_filename GRAPH_CASES = { "chain_64": (0, 64), @@ -86,6 +88,56 @@ def compute_golden(self, args, params): count = params["task_count"] args.task_state[: count * 8 : 8] = torch.arange(1, count + 1, dtype=torch.int64) + def test_run(self, st_platform, st_worker, request): + super().test_run(st_platform, st_worker, request) + output_prefixes = self._diagnostic_output_prefixes + level = self._effective_enable_chip_swimlane(request) + if level == 0: + return + + record_fields = {"start_cycles", "end_cycles", "loop_iter", "kind", "tasks_processed", "task_id"} + for case in self._matching_cases(st_platform, request): + case_label = _sanitize_for_filename(f"TestHbgSingleCoreDag_{case['name']}") + output_prefix = output_prefixes.get(case["name"]) + assert output_prefix is not None, f"no output directory created for {case_label}" + perf_path = output_prefix / "chip_swimlane_records.json" + raw = json.loads(perf_path.read_text()) + aicore_rows = raw["aicore_tasks"] + assert aicore_rows, "AICore task records are missing" + if level >= 2: + scheduler_tasks = raw["scheduler_tasks"] + assert scheduler_tasks["schema_version"] == 1 + assert scheduler_tasks["producer"] == "aicore" + scheduler_rows = scheduler_tasks["records"] + aicore_by_key = {(int(row[0]), int(row[2])): row for row in aicore_rows} + assert {(int(row[0]), int(row[1])) for row in scheduler_rows} == set(aicore_by_key) + for core_id, reg_task_id, dispatch_cycles, finish_cycles in scheduler_rows: + aicore_row = aicore_by_key[(int(core_id), int(reg_task_id))] + assert 0 < dispatch_cycles <= aicore_row[3] <= aicore_row[4] <= finish_cycles + assert raw["aicpu_lifecycle_records"], "AICPU lifecycle records are missing" + if level < 3: + continue + streams = raw["scheduler_records"]["streams"] + assert streams, "A5 HBG AICore Scheduler records are missing" + assert all(stream["producer"] == "aicore" for stream in streams) + assert all(stream["platform"] == "a5" and stream["runtime"] == "host_build_graph" for stream in streams) + records = [record for stream in streams for record in stream["records"]] + assert all(set(record) == record_fields for record in records) + assert all(0 < record["start_cycles"] <= record["end_cycles"] for record in records) + required_kinds = {"bootstrap", "dispatch", "complete", "resolve", "idle"} + if case["params"]["graph_case"] != GRAPH_CASES["multi_root_64"][0]: + required_kinds.add("fanin") + emitted_kinds = {record["kind"] for record in records} + assert required_kinds <= emitted_kinds, f"missing Scheduler kinds: {sorted(required_kinds - emitted_kinds)}" + profiled_task_ids = {int(row[1]) for row in raw["aicore_tasks"]} + for kind in ("dispatch", "complete"): + recorded_task_ids = {int(record["task_id"]) for record in records if record["kind"] == kind} + assert recorded_task_ids == profiled_task_ids, ( + f"{kind} records do not cover every profiled task: " + f"missing={sorted(profiled_task_ids - recorded_task_ids)} " + f"unexpected={sorted(recorded_task_ids - profiled_task_ids)}" + ) + if __name__ == "__main__": SceneTestCase.run_module(__name__) diff --git a/tests/ut/cpp/a5/test_hbg_scheduler_contracts.cpp b/tests/ut/cpp/a5/test_hbg_scheduler_contracts.cpp index 49e4b2d96d..d923ce50c2 100644 --- a/tests/ut/cpp/a5/test_hbg_scheduler_contracts.cpp +++ b/tests/ut/cpp/a5/test_hbg_scheduler_contracts.cpp @@ -208,16 +208,29 @@ TEST(SchedulerState, PreservesCacheLineAlignmentAndArrayStride) { EXPECT_EQ(alignof(SchedulerDispatchSlot), 128u); EXPECT_EQ(alignof(SchedulerRunControl), 128u); EXPECT_EQ(alignof(SchedulerWorkerContext), 128u); + EXPECT_EQ(alignof(SchedulerTaskTrace), 128u); std::array controls{}; std::array dispatch_slots{}; std::array contexts{}; EXPECT_EQ(reinterpret_cast(&controls[1]) - reinterpret_cast(&controls[0]), 128u); - EXPECT_EQ(reinterpret_cast(&dispatch_slots[1]) - reinterpret_cast(&dispatch_slots[0]), 128u); + EXPECT_EQ(reinterpret_cast(&dispatch_slots[1]) - reinterpret_cast(&dispatch_slots[0]), 256u); EXPECT_EQ(reinterpret_cast(&contexts[1]) - reinterpret_cast(&contexts[0]), 1024u); EXPECT_EQ(offsetof(SchedulerTaskControl, state) / 64, offsetof(SchedulerTaskControl, wake_list_head) / 64); EXPECT_NE(offsetof(SchedulerTaskControl, state) / 64, offsetof(SchedulerTaskControl, next_waiter) / 64); EXPECT_NE(offsetof(SchedulerDispatchSlot, task_id) / 64, offsetof(SchedulerDispatchSlot, publication) / 64); + EXPECT_EQ(offsetof(SchedulerDispatchSlot, executor_trace), 128u); + EXPECT_EQ( + offsetof(SchedulerTaskTrace, dispatch_start_cycles) / 64, offsetof(SchedulerTaskTrace, complete_loop_iter) / 64 + ); + EXPECT_NE( + offsetof(SchedulerTaskTrace, dispatch_start_cycles) / 64, + offsetof(SchedulerTaskTrace, descriptor_cache_observed_cycles) / 64 + ); + EXPECT_NE( + offsetof(SchedulerTaskTrace, refill_scheduler_worker_id) / 64, + offsetof(SchedulerTaskTrace, descriptor_cache_observed_cycles) / 64 + ); } TEST(SchedulerMetadata, ProjectsExistingSubmitTypesWithoutChangingTheirSemantics) { diff --git a/tests/ut/cpp/a5/test_hbg_scheduler_dispatch.cpp b/tests/ut/cpp/a5/test_hbg_scheduler_dispatch.cpp index f2c221a65b..4519ed76ac 100644 --- a/tests/ut/cpp/a5/test_hbg_scheduler_dispatch.cpp +++ b/tests/ut/cpp/a5/test_hbg_scheduler_dispatch.cpp @@ -147,6 +147,7 @@ struct FixtureStorage { metadata[task].logical_block_num = 1; metadata[task].total_required_subtasks = 1; metadata[task].flags = SCHEDULER_TASK_EXECUTABLE; + metadata[task].timing_slot = -1; } } @@ -242,6 +243,10 @@ TEST(SchedulerClusterCompletion, SpscGenerationCompletesNormalTask) { scheduler_initialize_free_slot(slot); slot->task_id = 0; slot->gang = 0; + slot->executor_trace.generation = slot->generation; + slot->executor_trace.kernel_start_cycles = 100; + slot->executor_trace.kernel_end_cycles = 200; + storage.metadata[0].timing_slot = 0; scheduler_gm_store( slot->publication, scheduler_dispatch_publication(slot->generation, SchedulerDispatchSlotState::READY) ); @@ -261,6 +266,11 @@ TEST(SchedulerClusterCompletion, SpscGenerationCompletesNormalTask) { EXPECT_EQ(control->state, static_cast(SchedulerTaskState::DONE)); EXPECT_EQ(control->wake_list_head, SCHEDULER_WAKE_LIST_CLOSED); EXPECT_EQ(storage.run_control->resolved_task_count, 1u); + auto *traces = + scheduler_state_at(storage.scheduler_state->base(), storage.layout.trace_cells_offset); + EXPECT_EQ(traces[0].kernel_start_cycles, 100u); + EXPECT_EQ(traces[0].kernel_end_cycles, 200u); + EXPECT_EQ(traces[0].valid, 0u); } TEST(SchedulerClusterCompletion, RejectsStaleCompletionGenerationAtNamedSite) { @@ -342,6 +352,9 @@ TEST(SchedulerClusterCompletion, PropagatesTraceToCompletionAndWokenTask) { auto *slot = scheduler_dispatch_slot_at(storage.scheduler_state->base(), &scheduler, 0, 0); scheduler_initialize_free_slot(slot); slot->task_id = 0; + slot->executor_trace.generation = slot->generation; + slot->executor_trace.kernel_start_cycles = 100; + slot->executor_trace.kernel_end_cycles = 200; scheduler_gm_store( slot->publication, scheduler_dispatch_publication(slot->generation, SchedulerDispatchSlotState::READY) ); @@ -364,6 +377,9 @@ TEST(SchedulerClusterCompletion, PropagatesTraceToCompletionAndWokenTask) { EXPECT_EQ(producer->completion_resolve_end_cycles, 0u); EXPECT_EQ(producer->scheduler_worker_id, scheduler.worker_index); EXPECT_EQ(traces[1].ready_transition_cycles, 0u); + EXPECT_EQ(traces[0].valid, 1u); + EXPECT_EQ(traces[0].kernel_start_cycles, 100u); + EXPECT_EQ(traces[0].kernel_end_cycles, 200u); auto *waiter = scheduler_task_control_at(storage.scheduler_state->base(), &scheduler, 1); EXPECT_EQ(waiter->state, static_cast(SchedulerTaskState::READY)); } diff --git a/tests/ut/cpp/a5/test_hbg_scheduler_ready.cpp b/tests/ut/cpp/a5/test_hbg_scheduler_ready.cpp index b696b846d8..192a0481f8 100644 --- a/tests/ut/cpp/a5/test_hbg_scheduler_ready.cpp +++ b/tests/ut/cpp/a5/test_hbg_scheduler_ready.cpp @@ -173,6 +173,36 @@ struct FixtureStorage { uint64_t *callable_addresses{nullptr}; }; +TEST(SchedulerActivityBuffer, IsAllocatedOnlyWhenRequestedAndNeverWraps) { + AicoreSchedulerLayout disabled{}; + ASSERT_TRUE(scheduler_plan_layout(1, 1, 0, &disabled)); + EXPECT_EQ(disabled.activity_buffers_offset, 0u); + EXPECT_EQ(disabled.activity_buffer_capacity, 0u); + + AicoreSchedulerLayout enabled{}; + ASSERT_TRUE(scheduler_plan_layout(1, 1, 0, &enabled, true)); + ASSERT_NE(enabled.activity_buffers_offset, 0u); + EXPECT_EQ(enabled.activity_buffer_capacity, SCHEDULER_ACTIVITY_CAPACITY); + SchedulerStateBuffer storage(enabled); + auto *contexts = scheduler_state_at(storage.base(), enabled.worker_contexts_offset); + auto *buffers = scheduler_state_at(storage.base(), enabled.activity_buffers_offset); + contexts[0].worker_index = 0; + contexts[0].profiling_loop_iter = 17; + buffers[0].committed = SCHEDULER_ACTIVITY_CAPACITY - 1; + + scheduler_append_activity(storage.base(), &contexts[0], AicoreSchedulerKind::Idle, 10, 20); + scheduler_append_activity(storage.base(), &contexts[0], AicoreSchedulerKind::Idle, 30, 40); + + EXPECT_EQ(buffers[0].committed, SCHEDULER_ACTIVITY_CAPACITY); + EXPECT_EQ(buffers[0].dropped, 1u); + const AicoreSchedulerRecord &last = buffers[0].records[SCHEDULER_ACTIVITY_CAPACITY - 1]; + EXPECT_EQ(last.start_time, 10u); + EXPECT_EQ(last.end_time, 20u); + EXPECT_EQ(last.loop_iter, 17u); + EXPECT_EQ(last.kind, AicoreSchedulerKind::Idle); + EXPECT_EQ(last.task_id, UINT64_MAX); +} + TEST(SchedulerBootstrap, RegistersOnlyOnFirstExecutableProducer) { FixtureStorage storage(4, 2); GraphBuffer graph(4); diff --git a/tests/ut/py/test_scene_test_cli_contract.py b/tests/ut/py/test_scene_test_cli_contract.py index e2f412f245..47864d80a3 100644 --- a/tests/ut/py/test_scene_test_cli_contract.py +++ b/tests/ut/py/test_scene_test_cli_contract.py @@ -237,7 +237,7 @@ def _run_and_validate(self, *_args, **kwargs): monkeypatch.setattr(scene_test_module, "build_output_prefix", lambda _case_label: output_prefix) - run_class_cases( + prefixes = run_class_cases( object(), FakeScene(), [{"name": "overhead"}], @@ -254,6 +254,19 @@ def _run_and_validate(self, *_args, **kwargs): ) assert captured["output_prefix"] == str(output_prefix) + assert prefixes == {"overhead": output_prefix} + + +def test_diagnostic_output_prefix_is_unique_per_invocation(monkeypatch, tmp_path) -> None: + scene_test_module = importlib.import_module("simpler_setup.scene_test") + monkeypatch.setattr(scene_test_module, "_outputs_dir", lambda: tmp_path) + + first = scene_test_module.build_output_prefix("same_case") + second = scene_test_module.build_output_prefix("same_case") + + assert first != second + assert first.is_dir() + assert second.is_dir() def test_run_class_cases_reports_the_failing_case_name() -> None: