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 414fa6bf98..caf4c65de4 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 @@ -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 @@ -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/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/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/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/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_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/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/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/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/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/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/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/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_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: 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.