diff --git a/docs/dfx/l2-swimlane-profiling.md b/docs/dfx/l2-swimlane-profiling.md index b42ad6382e..6f1dfe6801 100644 --- a/docs/dfx/l2-swimlane-profiling.md +++ b/docs/dfx/l2-swimlane-profiling.md @@ -43,7 +43,7 @@ available. Enable in one line: ```bash -python tests/st//test_.py -p a2a3 -d 0 --enable-l2-swimlane +python tests/st//test_.py -p -d 0 --enable-l2-swimlane ``` ## 3. How to Use @@ -62,31 +62,23 @@ backward-compatible with the old boolean behavior). | 3 | + Scheduler phases (`SCHED_*`) | Skips orchestrator phases | | 4 | + Orchestrator phases | Full collection | -> **Platform scope.** The tiered perf_level is currently -> implemented on **a2a3 only**. The a5 backend (both `a5` onboard -> and `a5sim`) has not been updated and still interprets -> `--enable-l2-swimlane` as a plain boolean: bare flag = on, -> absent = off. Passing an integer to a5 is silently treated as -> "on" regardless of value. - ```bash -# Standalone runner — full collection (level 4) -python tests/st//test_.py -p a2a3 -d 0 --enable-l2-swimlane - -# Standalone runner — AICore timing only (level 1) -python tests/st//test_.py -p a2a3 -d 0 --enable-l2-swimlane 1 +# Standalone runner +python tests/st//test_.py -p -d 0 --enable-l2-swimlane [PERF_LEVEL] -# Standalone runner — per-task with dispatch/fanout (level 2) -python tests/st//test_.py -p a2a3 -d 0 --enable-l2-swimlane 2 +# pytest — same flag shape +pytest tests/st/ --platform -d 0 --enable-l2-swimlane [PERF_LEVEL] -# pytest — scheduler phases (level 3) -pytest tests/st/ --platform a2a3 -d 0 --enable-l2-swimlane 3 - -# a5 onboard / a5sim — boolean only (perf_level integer not honored on a5 yet) -python tests/st//test_.py -p a5 -d 0 --enable-l2-swimlane -python tests/st//test_.py -p a5sim --enable-l2-swimlane +# Bare flag (no integer) — shorthand for level 4 (full collection) +python tests/st//test_.py -p -d 0 --enable-l2-swimlane ``` +- `` — one of `a2a3` / `a2a3sim` / `a5` / `a5sim`; the + integer perf_level interface is identical across them. +- `[PERF_LEVEL]` — optional integer 0–4 (see table above). Omit the + argument entirely (bare `--enable-l2-swimlane`) for the level-4 + shorthand; omit the flag entirely for level 0 (disabled). + The flag sets `CallConfig::enable_l2_swimlane` to the chosen level. The host then allocates the per-core / per-thread shared region and publishes its base address through diff --git a/docs/task-flow.md b/docs/task-flow.md index 8c4bfad749..c9bfe61ce9 100644 --- a/docs/task-flow.md +++ b/docs/task-flow.md @@ -171,9 +171,11 @@ View does **not** own memory. Valid for the duration of a single struct CallConfig { int32_t block_dim = 0; // 0 = auto (DeviceRunner resolves to stream max at run() time) int32_t aicpu_thread_num = 3; - bool enable_l2_swimlane = false; - bool enable_dump_tensor = false; - int32_t enable_pmu = 0; + int32_t enable_l2_swimlane = 0; // perf_level 0–4 (0=off, 4=full) + int32_t enable_dump_tensor = 0; + int32_t enable_pmu = 0; // 0 = disabled; >0 selects PMU event type + int32_t enable_dep_gen = 0; + char output_prefix[1024] = {}; // future fields here - same POD used at all levels }; ``` diff --git a/docs/testing.md b/docs/testing.md index 3cd4c96e7d..f5cd0f9a60 100644 --- a/docs/testing.md +++ b/docs/testing.md @@ -109,7 +109,7 @@ python test_xxx.py -p a2a3sim --log-level debug # verbose C++ l | `--case SEL` | | (all) | Case selector, repeatable: `Foo`, `ClassA::Foo`, `ClassA::` | | `--manual` | | `exclude` | `exclude`/`include`/`only` for manual cases | | `--skip-golden` | | false | Skip golden comparison (for benchmarking) | -| `--enable-l2-swimlane [PERF_LEVEL]` | | `0` | Enable L2 swimlane collection on first round only. On a2a3 the flag takes an integer perf_level 0–4 (bare = 4); see [docs/dfx/l2-swimlane-profiling.md](dfx/l2-swimlane-profiling.md#31-enable-l2-swimlane) for the level table. On a5 (both `a5` onboard and `a5sim`) the perf_level integer is not honored yet — the flag is treated as boolean (bare = on). Each test case gets its own `outputs/_/` directory under which `l2_perf_records.json` lands; parallel runs never collide. | +| `--enable-l2-swimlane [PERF_LEVEL]` | | `0` | Enable L2 swimlane collection on first round only. The flag takes an integer perf_level 0–4 (bare = 4); see [docs/dfx/l2-swimlane-profiling.md](dfx/l2-swimlane-profiling.md#31-enable-l2-swimlane) for the level table. Each test case gets its own `outputs/_/` directory under which `l2_perf_records.json` lands; parallel runs never collide. | | `--dump-tensor` | | false | Dump per-task tensor I/O during runtime execution | | `--enable-pmu [EVENT_TYPE]` | | `0` | Enable a2a3 PMU CSV collection. Bare flag selects `PIPE_UTILIZATION` (`2`); pass an event type such as `4` for `MEMORY`. | | `--build` | | false | Compile runtime from source (not pre-built) | diff --git a/src/a5/platform/include/aicpu/l2_perf_collector_aicpu.h b/src/a5/platform/include/aicpu/l2_perf_collector_aicpu.h index 0c202cca59..fac7a691ce 100644 --- a/src/a5/platform/include/aicpu/l2_perf_collector_aicpu.h +++ b/src/a5/platform/include/aicpu/l2_perf_collector_aicpu.h @@ -33,12 +33,24 @@ * L2 perf platform setters — called by the host (sim) or the AICPU kernel * entry (onboard) before `l2_perf_aicpu_init()` so AICPU code can read perf * state without reaching into the generic `Runtime` struct. + * + * Two-channel level transport (mirrors the PMU pattern): + * - binary on/off — `enable_profiling_flag` bit1 → `set_l2_swimlane_enabled(bool)` + * at kernel entry; queried via `is_l2_swimlane_enabled()`. + * - granular L2PerfLevel — `L2PerfDataHeader::l2_perf_level` (shared memory); + * read in `l2_perf_aicpu_init` and cached, then queried via + * `get_l2_perf_level()` for `>= AICPU_TIMING / SCHED_PHASES / ORCH_PHASES` gates. */ extern "C" void set_platform_l2_perf_base(uint64_t l2_perf_data_base); extern "C" uint64_t get_platform_l2_perf_base(); extern "C" void set_l2_swimlane_enabled(bool enable); extern "C" bool is_l2_swimlane_enabled(); +// Typed getter for the granular perf_level (promoted from the shared-memory +// header inside l2_perf_aicpu_init). Gate sites should use this so the +// comparison RHS is a named L2PerfLevel constant. +L2PerfLevel get_l2_perf_level(); + /** * Initialize performance profiling for `worker_count` cores. * @@ -63,6 +75,7 @@ void l2_perf_aicpu_init(int worker_count); * runtime linked-list types). * * @param core_id Core ID owning the destination buffer (resolved via s_perf_buffer_states) + * @param thread_idx Owning AICPU thread (used when rotating records buffer) * @param expected_reg_task_id Register dispatch token (low 32 bits) to validate * @param task_id Task identifier to write (PTO2 encoding or plain id) * @param func_id Kernel function identifier @@ -77,7 +90,7 @@ void l2_perf_aicpu_init(int worker_count); * (they take the dropped path). Same shape as a2a3. */ int l2_perf_aicpu_complete_record( - int core_id, uint32_t expected_reg_task_id, uint64_t task_id, uint32_t func_id, CoreType core_type, + int core_id, int thread_idx, uint32_t expected_reg_task_id, uint64_t task_id, uint32_t func_id, CoreType core_type, uint64_t dispatch_time, uint64_t finish_time, const uint64_t *fanout, int32_t fanout_count ); diff --git a/src/a5/platform/include/common/l2_perf_profiling.h b/src/a5/platform/include/common/l2_perf_profiling.h index aa7d636b42..e4ede5d0f1 100644 --- a/src/a5/platform/include/common/l2_perf_profiling.h +++ b/src/a5/platform/include/common/l2_perf_profiling.h @@ -65,6 +65,28 @@ #define RUNTIME_MAX_FANOUT 128 #endif +// ============================================================================= +// L2 perf_level — granularity ladder for the L2 swimlane profiler. +// +// Each level is a strict superset of the previous: higher levels add the data +// described by their name on top of all lower-level data. Naming describes +// what is NEWLY captured at that level (incremental view), so gate sites read +// naturally — e.g. `if (level >= SCHED_PHASES)` means "this section runs when +// scheduler phase records are being collected (or any higher tier)". +// +// Transported via `L2PerfDataHeader::l2_perf_level` (host → AICPU, +// shared memory) and `CallConfig::enable_l2_swimlane` (Python → C). The wire +// representation stays integer (uint32_t / int32_t) for ABI stability; this +// enum is the canonical in-code type used for comparisons. +// ============================================================================= +enum class L2PerfLevel : uint32_t { + DISABLED = 0, // No collection at all + AICORE_TIMING = 1, // AICore per-task start/end timestamps + task record buffer + AICPU_TIMING = 2, // + AICPU dispatch/finish timestamps + fanout dependency list + SCHED_PHASES = 3, // + scheduler main-loop phase records (SCHED_COMPLETE/DISPATCH/IDLE_WAIT) + ORCH_PHASES = 4, // + orchestrator phase records +}; + // ============================================================================= // L2PerfRecord - Single Task Execution Record // ============================================================================= @@ -265,7 +287,10 @@ struct L2PerfDataHeader { volatile uint32_t queue_tails[PLATFORM_MAX_AICPU_THREADS]; // Producer write positions (AICPU modifies) // Metadata (Host initializes, Device read-only) - uint32_t num_cores; // Actual number of cores launched + uint32_t num_cores; // Actual number of cores launched + uint32_t l2_perf_level; // 0=off, 1=AICore timing, 2=+dispatch/fanout, + // 3=+sched phases, 4=+orch phases. Host writes + // at init; AICPU reads in l2_perf_aicpu_init. } __attribute__((aligned(64))); // ============================================================================= diff --git a/src/a5/platform/include/host/l2_perf_collector.h b/src/a5/platform/include/host/l2_perf_collector.h index 49c79ed7dd..2218f09522 100644 --- a/src/a5/platform/include/host/l2_perf_collector.h +++ b/src/a5/platform/include/host/l2_perf_collector.h @@ -223,6 +223,13 @@ class L2PerfCollector : public profiling_common::ProfilerBase/l2_perf_records.json. diff --git a/src/a5/platform/onboard/host/device_runner.cpp b/src/a5/platform/onboard/host/device_runner.cpp index 1b44e5c421..4d6f4f6779 100644 --- a/src/a5/platform/onboard/host/device_runner.cpp +++ b/src/a5/platform/onboard/host/device_runner.cpp @@ -1169,7 +1169,7 @@ void DeviceRunner::finalize_collectors() { int DeviceRunner::init_l2_perf(int num_aicore, int device_id) { int rc = l2_perf_collector_.initialize( - num_aicore, device_id, prof_alloc_cb, /*register_cb=*/nullptr, prof_free_cb, output_prefix_ + num_aicore, device_id, l2_perf_level_, prof_alloc_cb, /*register_cb=*/nullptr, prof_free_cb, output_prefix_ ); if (rc == 0) { kernel_args_.args.l2_perf_data_base = diff --git a/src/a5/platform/onboard/host/device_runner.h b/src/a5/platform/onboard/host/device_runner.h index 8bdc0d89e4..cab1c2d8c4 100644 --- a/src/a5/platform/onboard/host/device_runner.h +++ b/src/a5/platform/onboard/host/device_runner.h @@ -285,7 +285,10 @@ class DeviceRunner { * corresponding `enable_*_` members directly. Moved off the generic * Runtime struct / run() arg list so all three travel the same way. */ - void set_l2_swimlane_enabled(bool enable) { enable_l2_swimlane_ = enable; } + void set_l2_swimlane_enabled(int level) { + l2_perf_level_ = static_cast(level); + enable_l2_swimlane_ = (l2_perf_level_ != L2PerfLevel::DISABLED); + } void set_dump_tensor_enabled(bool enable) { enable_dump_tensor_ = enable; } void set_pmu_enabled(int enable_pmu) { enable_pmu_ = (enable_pmu > 0); @@ -666,6 +669,7 @@ class DeviceRunner { bool enable_l2_swimlane_{false}; bool enable_dump_tensor_{false}; bool enable_pmu_{false}; + L2PerfLevel l2_perf_level_{L2PerfLevel::DISABLED}; // resolved from set_l2_swimlane_enabled() PmuEventType pmu_event_type_{PmuEventType::PIPE_UTILIZATION}; // resolved from set_pmu_enabled() std::string output_prefix_{}; // diagnostic artifact root directory diff --git a/src/a5/platform/onboard/host/pto_runtime_c_api.cpp b/src/a5/platform/onboard/host/pto_runtime_c_api.cpp index 593c856a93..21f919fd09 100644 --- a/src/a5/platform/onboard/host/pto_runtime_c_api.cpp +++ b/src/a5/platform/onboard/host/pto_runtime_c_api.cpp @@ -445,7 +445,7 @@ int run_prepared( return rc; } - runner->set_l2_swimlane_enabled(enable_l2_swimlane != 0); + runner->set_l2_swimlane_enabled(enable_l2_swimlane); runner->set_dump_tensor_enabled(enable_dump_tensor != 0); runner->set_pmu_enabled(enable_pmu); runner->set_output_prefix(output_prefix); diff --git a/src/a5/platform/sim/host/device_runner.cpp b/src/a5/platform/sim/host/device_runner.cpp index 2d02dc2790..ab9adcb732 100644 --- a/src/a5/platform/sim/host/device_runner.cpp +++ b/src/a5/platform/sim/host/device_runner.cpp @@ -1068,7 +1068,7 @@ void DeviceRunner::finalize_collectors() { int DeviceRunner::init_l2_perf(int num_aicore, int device_id) { int rc = l2_perf_collector_.initialize( - num_aicore, device_id, prof_alloc_cb, /*register_cb=*/nullptr, prof_free_cb, output_prefix_ + num_aicore, device_id, l2_perf_level_, prof_alloc_cb, /*register_cb=*/nullptr, prof_free_cb, output_prefix_ ); if (rc == 0) { kernel_args_.l2_perf_data_base = reinterpret_cast(l2_perf_collector_.get_l2_perf_setup_device_ptr()); diff --git a/src/a5/platform/sim/host/device_runner.h b/src/a5/platform/sim/host/device_runner.h index 58c6129b2e..0aa6e6fa10 100644 --- a/src/a5/platform/sim/host/device_runner.h +++ b/src/a5/platform/sim/host/device_runner.h @@ -173,7 +173,10 @@ class DeviceRunner { * corresponding `enable_*_` members directly. Moved off the generic * Runtime struct / run() arg list so all three travel the same way. */ - void set_l2_swimlane_enabled(bool enable) { enable_l2_swimlane_ = enable; } + void set_l2_swimlane_enabled(int level) { + l2_perf_level_ = static_cast(level); + enable_l2_swimlane_ = (l2_perf_level_ != L2PerfLevel::DISABLED); + } void set_dump_tensor_enabled(bool enable) { enable_dump_tensor_ = enable; } void set_pmu_enabled(int enable_pmu) { enable_pmu_ = (enable_pmu > 0); @@ -413,6 +416,7 @@ class DeviceRunner { bool enable_l2_swimlane_{false}; bool enable_dump_tensor_{false}; bool enable_pmu_{false}; + L2PerfLevel l2_perf_level_{L2PerfLevel::DISABLED}; // resolved from set_l2_swimlane_enabled() PmuEventType pmu_event_type_{PmuEventType::PIPE_UTILIZATION}; // resolved from set_pmu_enabled() std::string output_prefix_{}; // diagnostic artifact root directory diff --git a/src/a5/platform/sim/host/pto_runtime_c_api.cpp b/src/a5/platform/sim/host/pto_runtime_c_api.cpp index 5ae942d144..debf09f750 100644 --- a/src/a5/platform/sim/host/pto_runtime_c_api.cpp +++ b/src/a5/platform/sim/host/pto_runtime_c_api.cpp @@ -345,7 +345,7 @@ int run_prepared( return rc; } - runner->set_l2_swimlane_enabled(enable_l2_swimlane != 0); + runner->set_l2_swimlane_enabled(enable_l2_swimlane); runner->set_dump_tensor_enabled(enable_dump_tensor != 0); runner->set_pmu_enabled(enable_pmu); runner->set_output_prefix(output_prefix); diff --git a/src/a5/platform/src/aicpu/l2_perf_collector_aicpu.cpp b/src/a5/platform/src/aicpu/l2_perf_collector_aicpu.cpp index fb4782503e..fdf16986c7 100644 --- a/src/a5/platform/src/aicpu/l2_perf_collector_aicpu.cpp +++ b/src/a5/platform/src/aicpu/l2_perf_collector_aicpu.cpp @@ -16,12 +16,6 @@ * Uses per-core L2PerfBufferState with SPSC free queues for O(1) buffer switching. * Host memory manager dynamically allocates replacement buffers and pushes * them into the free_queue. Device pops from free_queue when switching. - * - * AICore writes timing into a per-core stable L2PerfAicoreRing - * (state.aicore_ring_ptr); AICPU reads the slot in complete_record and - * commits into records[]. The ring address is set once by the host at init - * and never reassigned, so AICore's write address is decoupled from the - * AICPU rotating L2PerfBuffer. */ #include "aicpu/l2_perf_collector_aicpu.h" @@ -41,13 +35,14 @@ static L2PerfDataHeader *s_l2_perf_header = nullptr; // Per-core L2PerfBufferState cache static L2PerfBufferState *s_perf_buffer_states[PLATFORM_MAX_CORES] = {}; -// Per-core stable AICore staging ring pointer cache. Populated by -// l2_perf_aicpu_init() from state->aicore_ring_ptr (host-published at SHM -// init time); read by complete_record. Never reassigned during the run, so -// no synchronization is needed for concurrent readers. AICPU sees these -// addresses as plain pointers (no __gm__ on AICPU). +// Per-core L2PerfAicoreRing cache (stable for the run; AICPU reads, AICore writes) static L2PerfAicoreRing *s_perf_aicore_rings[PLATFORM_MAX_CORES] = {}; +// Per-core cached current-records-buffer pointer. Written by AICPU when +// rotating buffers from inside `complete_record`; AICPU never publishes this +// to AICore (AICore only sees the stable ring). +static L2PerfBuffer *s_perf_records_buffers[PLATFORM_MAX_CORES] = {}; + // Per-thread PhaseBufferState cache static PhaseBufferState *s_phase_buffer_states[PLATFORM_MAX_AICPU_THREADS] = {}; static PhaseBuffer *s_current_phase_buf[PLATFORM_MAX_AICPU_THREADS] = {}; @@ -57,14 +52,20 @@ static int s_orch_thread_idx = -1; // L2 perf platform state. Published by the host (via dlsym'd setters on sim) // or by the AICPU kernel entry (onboard) before perf init runs, so downstream // perf code can discover enablement + device-base without reading the generic -// Runtime struct. +// Runtime struct. Two channels (mirrors PMU): +// - g_enable_l2_swimlane (bool) — set at kernel entry from the bitmask bit +// - g_l2_perf_level (L2PerfLevel) — promoted in l2_perf_aicpu_init from the +// shared-memory header so `>= AICPU_TIMING / SCHED_PHASES / ORCH_PHASES` +// gates have the granular value (exposed via get_l2_perf_level()). static uint64_t g_platform_l2_perf_base = 0; static bool g_enable_l2_swimlane = false; +static L2PerfLevel g_l2_perf_level = L2PerfLevel::DISABLED; extern "C" void set_platform_l2_perf_base(uint64_t l2_perf_data_base) { g_platform_l2_perf_base = l2_perf_data_base; } extern "C" uint64_t get_platform_l2_perf_base() { return g_platform_l2_perf_base; } extern "C" void set_l2_swimlane_enabled(bool enable) { g_enable_l2_swimlane = enable; } extern "C" bool is_l2_swimlane_enabled() { return g_enable_l2_swimlane; } +L2PerfLevel get_l2_perf_level() { return g_l2_perf_level; } /** * Enqueue ready buffer to per-thread queue @@ -109,7 +110,15 @@ void l2_perf_aicpu_init(int worker_count) { s_l2_perf_header = get_l2_perf_header(l2_perf_base); - LOG_INFO_V0("Initializing performance profiling for %d cores (memcpy-based)", worker_count); + // Read the granular perf_level from the shared-memory header (host wrote + // it in L2PerfCollector::initialize). The kernel-entry setter only seeded + // the binary g_enable_l2_swimlane via the bitmask bit. + g_l2_perf_level = static_cast(s_l2_perf_header->l2_perf_level); + + LOG_INFO_V0( + "Initializing performance profiling for %d cores (memcpy-based), l2_perf_level=%u", worker_count, + static_cast(g_l2_perf_level) + ); // Pop first buffer from free_queue for each core, and cache the stable // AICore staging ring pointer so complete_record can read it without @@ -135,11 +144,13 @@ void l2_perf_aicpu_init(int worker_count) { L2PerfBuffer *buf = reinterpret_cast(buf_ptr); buf->count = 0; + s_perf_records_buffers[i] = buf; LOG_DEBUG("Core %d: popped initial buffer (addr=0x%lx)", i, buf_ptr); } else { LOG_ERROR("Core %d: free_queue is empty during init!", i); state->current_buf_ptr = 0; + s_perf_records_buffers[i] = nullptr; } } @@ -149,24 +160,18 @@ void l2_perf_aicpu_init(int worker_count) { } /** - * Switch performance buffer when the current buffer is full. - * - * Internal-only: complete_record calls this when records[count] is at - * capacity. Enqueues the full buffer to the per-thread ready_queue and - * pops a fresh one from the free_queue. Failure paths bump - * dropped_record_count so reconcile sees a consistent device state. - * - * The AICore staging ring (state->aicore_ring_ptr / s_perf_aicore_rings[]) - * is **never** touched here: AICore's write address is the same for the - * entire run. + * Internal records-buffer rotation. Called from `l2_perf_aicpu_complete_record` + * after a record is committed and the buffer hits capacity. Only swaps an + * AICPU-private records pointer — AICore reads from a stable ring and is + * unaffected by this call. */ -static void switch_buffer(int core_id, int thread_idx) { +static void switch_records_buffer(int core_id, int thread_idx) { L2PerfBufferState *state = s_perf_buffer_states[core_id]; if (state == nullptr) { return; } - L2PerfBuffer *full_buf = reinterpret_cast(state->current_buf_ptr); + L2PerfBuffer *full_buf = s_perf_records_buffers[core_id]; if (full_buf == nullptr) { return; } @@ -192,6 +197,7 @@ static void switch_buffer(int core_id, int thread_idx) { int rc = enqueue_ready_buffer(s_l2_perf_header, thread_idx, core_id, state->current_buf_ptr, seq, 0); if (rc != 0) { LOG_ERROR("Thread %d: Core %d failed to enqueue buffer (queue full), data lost!", thread_idx, core_id); + // Revert: discard data and keep writing state->dropped_record_count += full_buf->count; full_buf->count = 0; wmb(); @@ -208,84 +214,65 @@ static void switch_buffer(int core_id, int thread_idx) { L2PerfBuffer *new_buf = reinterpret_cast(new_buf_ptr); new_buf->count = 0; - wmb(); + s_perf_records_buffers[core_id] = new_buf; LOG_INFO_V0("Thread %d: Core %d switched to new buffer (addr=0x%lx)", thread_idx, core_id, new_buf_ptr); } int l2_perf_aicpu_complete_record( - int core_id, uint32_t expected_reg_task_id, uint64_t task_id, uint32_t func_id, CoreType core_type, + int core_id, int thread_idx, uint32_t expected_reg_task_id, uint64_t task_id, uint32_t func_id, CoreType core_type, uint64_t dispatch_time, uint64_t finish_time, const uint64_t *fanout, int32_t fanout_count ) { - if (core_id < 0 || core_id >= PLATFORM_MAX_CORES) return -1; - + if (core_id < 0 || core_id >= PLATFORM_MAX_CORES) { + return -1; + } L2PerfBufferState *state = s_perf_buffer_states[core_id]; - if (state == nullptr) return -1; + if (state == nullptr) { + return -1; + } + L2PerfAicoreRing *ring = s_perf_aicore_rings[core_id]; + if (ring == nullptr) { + return -1; + } - // Account every commit attempt before any drop path so reconcile equation - // (collected + dropped + mismatch == total) holds. + // Account every commit attempt up front so host can detect silent loss as + // `device_total - (collected + dropped + mismatch)`. state->total_record_count += 1; - // Read AICore-published timing from the per-core stable staging ring. - L2PerfAicoreRing *ring = s_perf_aicore_rings[core_id]; - if (ring == nullptr) { + L2PerfBuffer *l2_perf_buf = s_perf_records_buffers[core_id]; + if (l2_perf_buf == nullptr) { + // No active records buffer (init ran out of free buffers); count as drop + // so host reconciliation stays consistent. state->dropped_record_count += 1; - wmb(); return -1; } + uint32_t count = l2_perf_buf->count; + if (count >= PLATFORM_PROF_BUFFER_SIZE) { + // Defensive: should not happen because we rotate at end of every commit. + state->dropped_record_count += 1; + return -1; + } + + // Read AICore-published timing from the per-core staging ring. L2PerfRecord *slot = &ring->dual_issue_slots[expected_reg_task_id % PLATFORM_L2_AICORE_RING_SIZE]; + // One PoC cache line: matches AICore l2_perf_aicore_record_task() dcci(..., SINGLE_CACHE_LINE, ...) + // and aicpu/cache_ops.cpp step size; timing fields live in the first line. cache_invalidate_range(slot, 64); if (static_cast(slot->task_id) != expected_reg_task_id) { - // AICore hasn't published this slot yet — count separately from - // capacity drops (mismatch is a hard invariant violation). + // Hard error: the runtime's completion-before-dispatch invariant + // guarantees AICore must have published this slot before AICPU sees + // FIN. A mismatch means the invariant is broken (e.g. in-flight + // depth exceeded PLATFORM_L2_AICORE_RING_SIZE, or AICore failed to + // dcci before signaling). Surface separately from capacity drops. state->mismatch_record_count += 1; - wmb(); - return -1; - } - - rmb(); - uint64_t cur_ptr = state->current_buf_ptr; - if (cur_ptr == 0) { - // Buffer was flushed/cleared — late FIN after flush. Count as dropped - // so the buffer doesn't get re-populated post-stop(). - state->dropped_record_count += 1; - wmb(); + LOG_ERROR( + "L2Perf invariant violated: core %d slot task_id=0x%x expected=0x%x " + "(completion-before-dispatch broken or ring undersized)", + core_id, static_cast(slot->task_id), expected_reg_task_id + ); return -1; } - L2PerfBuffer *l2_perf_buf = reinterpret_cast(cur_ptr); - uint32_t count = l2_perf_buf->count; - if (count >= PLATFORM_PROF_BUFFER_SIZE) { - // Flip to a fresh buffer when full. Caller doesn't need a thread_idx - // routed to switch_buffer, so derive it from the AicpuPhaseHeader's - // core→thread map (filled at init by the runtime). Until phase - // metadata is populated, fall back to thread 0 — the per-thread - // ready_queue is only used for collector throughput, so a temporary - // single-thread serialization is harmless. - int thread_idx = 0; - if (s_phase_header != nullptr && core_id >= 0 && core_id < PLATFORM_MAX_CORES) { - int8_t mapped = s_phase_header->core_to_thread[core_id]; - if (mapped >= 0 && mapped < PLATFORM_MAX_AICPU_THREADS) { - thread_idx = static_cast(static_cast(mapped)); - } - } - switch_buffer(core_id, thread_idx); - rmb(); - cur_ptr = state->current_buf_ptr; - if (cur_ptr == 0) { - state->dropped_record_count += 1; - wmb(); - return -1; - } - l2_perf_buf = reinterpret_cast(cur_ptr); - count = l2_perf_buf->count; - if (count >= PLATFORM_PROF_BUFFER_SIZE) { - state->dropped_record_count += 1; - wmb(); - return -1; - } - } - // Copy AICore timing to committed record slot L2PerfRecord *record = &l2_perf_buf->records[count]; record->start_time = slot->start_time; @@ -295,21 +282,36 @@ int l2_perf_aicpu_complete_record( record->task_id = task_id; record->func_id = func_id; record->core_type = core_type; - record->dispatch_time = dispatch_time; - record->finish_time = finish_time; - if (fanout != nullptr && fanout_count > 0) { - int32_t n = (fanout_count > RUNTIME_MAX_FANOUT) ? RUNTIME_MAX_FANOUT : fanout_count; - for (int32_t i = 0; i < n; i++) { - record->fanout[i] = fanout[i]; + // AICPU_TIMING and above: dispatch/finish timing and fanout dependency info + if (g_l2_perf_level >= L2PerfLevel::AICPU_TIMING) { + record->dispatch_time = dispatch_time; + record->finish_time = finish_time; + if (fanout != nullptr && fanout_count > 0) { + int32_t n = (fanout_count > RUNTIME_MAX_FANOUT) ? RUNTIME_MAX_FANOUT : fanout_count; + for (int32_t i = 0; i < n; i++) { + record->fanout[i] = fanout[i]; + } + record->fanout_count = n; + } else { + record->fanout_count = 0; } - record->fanout_count = n; } else { + record->dispatch_time = 0; + record->finish_time = 0; record->fanout_count = 0; } - l2_perf_buf->count = count + 1; + uint32_t new_count = count + 1; + l2_perf_buf->count = new_count; wmb(); + + // Rotate after the write so the just-committed record is preserved. + // The ring is stable, so AICore is unaffected by this swap. + if (new_count >= PLATFORM_PROF_BUFFER_SIZE) { + switch_records_buffer(core_id, thread_idx); + } + return 0; } @@ -347,6 +349,7 @@ void l2_perf_aicpu_flush_buffers(int thread_idx, const int *cur_thread_cores, in LOG_INFO_V0("Thread %d: Core %d flushed buffer with %u records", thread_idx, core_id, buf->count); flushed_count++; state->current_buf_ptr = 0; + s_perf_records_buffers[core_id] = nullptr; wmb(); } else { // ready_queue full at end-of-run: account the loss and clear the @@ -359,6 +362,7 @@ void l2_perf_aicpu_flush_buffers(int thread_idx, const int *cur_thread_cores, in state->dropped_record_count += buf->count; buf->count = 0; state->current_buf_ptr = 0; + s_perf_records_buffers[core_id] = nullptr; wmb(); } } @@ -501,11 +505,12 @@ void l2_perf_aicpu_record_phase( } PhaseBufferState *state = s_phase_buffer_states[thread_idx]; - if (state == nullptr) return; + if (state == nullptr) { + return; + } - // Account every commit attempt before any drop path so reconcile - // (collected + dropped + mismatch == total) holds. PHASE has no - // ring/AICore staging path so mismatch stays 0 here. + // Account every commit attempt up front so host can detect silent loss + // as `device_total - (collected + dropped)` (mirrors PERF accounting). state->total_record_count += 1; PhaseBuffer *buf = s_current_phase_buf[thread_idx]; @@ -532,8 +537,7 @@ void l2_perf_aicpu_record_phase( } if (buf == nullptr) { state->dropped_record_count += 1; - wmb(); - return; // Still no buffer available + return; } } @@ -545,14 +549,12 @@ void l2_perf_aicpu_record_phase( buf = s_current_phase_buf[thread_idx]; if (buf == nullptr) { state->dropped_record_count += 1; - wmb(); - return; // No buffer available + return; } idx = buf->count; if (idx >= PLATFORM_PHASE_RECORDS_PER_THREAD) { state->dropped_record_count += 1; - wmb(); - return; // Switch failed; drop this record + return; } } @@ -566,7 +568,6 @@ void l2_perf_aicpu_record_phase( record->extra2 = extra2; buf->count = idx + 1; - wmb(); } void l2_perf_aicpu_set_orch_thread_idx(int thread_idx) { s_orch_thread_idx = thread_idx; } diff --git a/src/a5/platform/src/host/l2_perf_collector.cpp b/src/a5/platform/src/host/l2_perf_collector.cpp index 2054d6c243..93bb9f83d3 100644 --- a/src/a5/platform/src/host/l2_perf_collector.cpp +++ b/src/a5/platform/src/host/l2_perf_collector.cpp @@ -99,8 +99,8 @@ void *L2PerfCollector::alloc_single_buffer(size_t size, void **host_ptr_out) { } int L2PerfCollector::initialize( - int num_aicore, int device_id, const L2PerfAllocCallback &alloc_cb, L2PerfRegisterCallback register_cb, - const L2PerfFreeCallback &free_cb, const std::string &output_prefix + int num_aicore, int device_id, L2PerfLevel l2_perf_level, const L2PerfAllocCallback &alloc_cb, + L2PerfRegisterCallback register_cb, const L2PerfFreeCallback &free_cb, const std::string &output_prefix ) { if (shm_host_ != nullptr) { LOG_ERROR("L2PerfCollector already initialized"); @@ -115,6 +115,7 @@ int L2PerfCollector::initialize( } num_aicore_ = num_aicore; + l2_perf_level_ = l2_perf_level; output_prefix_ = output_prefix; total_perf_collected_ = 0; total_phase_collected_ = 0; @@ -156,11 +157,13 @@ int L2PerfCollector::initialize( header->queue_tails[t] = 0; } header->num_cores = num_aicore; + header->l2_perf_level = static_cast(l2_perf_level_); LOG_DEBUG("Initialized L2PerfDataHeader:"); - LOG_DEBUG(" num_cores: %d", header->num_cores); - LOG_DEBUG(" buffer_capacity: %d", PLATFORM_PROF_BUFFER_SIZE); - LOG_DEBUG(" queue capacity: %d", PLATFORM_PROF_READYQUEUE_SIZE); + LOG_DEBUG(" num_cores: %d", header->num_cores); + LOG_DEBUG(" l2_perf_level: %u", header->l2_perf_level); + LOG_DEBUG(" buffer_capacity: %d", PLATFORM_PROF_BUFFER_SIZE); + LOG_DEBUG(" queue capacity: %d", PLATFORM_PROF_READYQUEUE_SIZE); // Step 4: Allocate per-core stable L2PerfAicoreRings + the address-table // buffer. Rings are allocated once and never rotated; AICore writes into @@ -576,7 +579,7 @@ int L2PerfCollector::export_swimlane_json() { return -1; } - int version = has_phase_data_ ? 2 : 1; + int version = static_cast(l2_perf_level_); outfile << "{\n"; outfile << " \"version\": " << version << ",\n"; outfile << " \"tasks\": [\n"; @@ -623,7 +626,8 @@ int L2PerfCollector::export_swimlane_json() { } outfile << " ]"; - if (has_phase_data_) { + // Step: Write phase profiling data (level >= 3) + if (l2_perf_level_ >= L2PerfLevel::SCHED_PHASES) { auto sched_phase_name = [](AicpuPhaseId id) -> const char * { switch (id) { case AicpuPhaseId::SCHED_COMPLETE: @@ -693,20 +697,23 @@ int L2PerfCollector::export_swimlane_json() { } outfile << " ]"; + // Per-task orchestrator phase records (level >= 4, filtered from unified collected_phase_records_) // Orchestrator timing is no longer emitted as a separate aggregate // block. Per-event AicpuPhaseRecord[] entries (emitted as // aicpu_orchestrator_phases below) are the single source of truth; // the run-window envelope is still visible in the device-side // LOG_INFO_V9 "Thread N: orch_start=… orch_end=… orch_cost=…" line. bool has_orch_phases = false; - for (const auto &v : collected_phase_records_) { - for (const auto &r : v) { - if (!is_scheduler_phase(r.phase_id)) { - has_orch_phases = true; - break; + if (l2_perf_level_ >= L2PerfLevel::ORCH_PHASES) { + for (const auto &v : collected_phase_records_) { + for (const auto &r : v) { + if (!is_scheduler_phase(r.phase_id)) { + has_orch_phases = true; + break; + } } + if (has_orch_phases) break; } - if (has_orch_phases) break; } if (has_orch_phases) { outfile << ",\n \"aicpu_orchestrator_phases\": [\n"; diff --git a/src/a5/runtime/host_build_graph/aicpu/aicpu_executor.cpp b/src/a5/runtime/host_build_graph/aicpu/aicpu_executor.cpp index 3341c556de..d354f6ae2b 100644 --- a/src/a5/runtime/host_build_graph/aicpu/aicpu_executor.cpp +++ b/src/a5/runtime/host_build_graph/aicpu/aicpu_executor.cpp @@ -286,7 +286,7 @@ inline bool AicpuExecutor::try_dispatch_task( pending_task_ids_[core_id] = task_id; // Record the real AICPU dispatch point for this core. - if (l2_perf_enabled) { + if (l2_perf_enabled && get_l2_perf_level() >= L2PerfLevel::AICPU_TIMING) { dispatch_timestamps_[core_id] = get_sys_cnt_aicpu(); } @@ -677,6 +677,7 @@ int AicpuExecutor::resolve_and_dispatch(Runtime &runtime, int thread_idx, const int verification_warning_count = 0; const int MAX_VERIFICATION_WARNINGS = 10; bool l2_perf_enabled = is_l2_swimlane_enabled(); + L2PerfLevel l2_perf_level = get_l2_perf_level(); // Extract array pointers as local variables for better readability and performance int *cur_ready_queue_aic = cur_ready_queue_aic_[thread_idx]; @@ -697,11 +698,13 @@ int AicpuExecutor::resolve_and_dispatch(Runtime &runtime, int thread_idx, const "Thread %d: Initial state - local queue: %d AIC, %d AIV", thread_idx, cur_aic_ready_count, cur_aiv_ready_count ); - // Initialize dispatch timestamps for all cores - uint64_t dispatch_start_time = get_sys_cnt_aicpu(); - for (int i = 0; i < core_num; i++) { - int core_id = cur_thread_cores[i]; - dispatch_timestamps_[core_id] = dispatch_start_time; + // Initialize dispatch timestamps for all cores (only needed at level >= 2) + if (l2_perf_level >= L2PerfLevel::AICPU_TIMING) { + uint64_t dispatch_start_time = get_sys_cnt_aicpu(); + for (int i = 0; i < core_num; i++) { + int core_id = cur_thread_cores[i]; + dispatch_timestamps_[core_id] = dispatch_start_time; + } } // Main execution loop with unified scheduling @@ -729,43 +732,55 @@ int AicpuExecutor::resolve_and_dispatch(Runtime &runtime, int thread_idx, const // written to wip[id & 1] first, so complete it BEFORE the // pending task's record to maintain buffer ordering. if (l2_perf_enabled) { - uint64_t finish_ts = get_sys_cnt_aicpu(); + uint64_t finish_ts = (l2_perf_level >= L2PerfLevel::AICPU_TIMING) ? get_sys_cnt_aicpu() : 0; if (prev_running_id != AICPU_TASK_INVALID) { Task *prev_task = &runtime.tasks[prev_running_id]; uint64_t fanout_arr[RUNTIME_MAX_FANOUT]; - for (int i = 0; i < prev_task->fanout_count; i++) { - fanout_arr[i] = static_cast(prev_task->fanout[i]); + int fanout_count = 0; + if (l2_perf_level >= L2PerfLevel::AICPU_TIMING) { + for (int i = 0; i < prev_task->fanout_count; i++) { + fanout_arr[i] = static_cast(prev_task->fanout[i]); + } + fanout_count = prev_task->fanout_count; } if (l2_perf_aicpu_complete_record( - core_id, static_cast(prev_running_id), static_cast(prev_running_id), - prev_task->func_id, h->core_type, dispatch_timestamps_[core_id], finish_ts, fanout_arr, - prev_task->fanout_count + core_id, thread_idx, static_cast(prev_running_id), + static_cast(prev_running_id), prev_task->func_id, h->core_type, + dispatch_timestamps_[core_id], finish_ts, fanout_arr, fanout_count ) != 0) { LOG_ERROR( "Core %d: l2_perf_aicpu_complete_record failed for implicit task %d", core_id, prev_running_id ); } - dispatch_timestamps_[core_id] = get_sys_cnt_aicpu(); + if (l2_perf_level >= L2PerfLevel::AICPU_TIMING) { + dispatch_timestamps_[core_id] = get_sys_cnt_aicpu(); + } } - finish_ts = get_sys_cnt_aicpu(); + finish_ts = (l2_perf_level >= L2PerfLevel::AICPU_TIMING) ? get_sys_cnt_aicpu() : 0; Task *task = &runtime.tasks[completed_task_id]; uint64_t fanout_arr[RUNTIME_MAX_FANOUT]; - for (int i = 0; i < task->fanout_count; i++) { - fanout_arr[i] = static_cast(task->fanout[i]); + int fanout_count = 0; + if (l2_perf_level >= L2PerfLevel::AICPU_TIMING) { + for (int i = 0; i < task->fanout_count; i++) { + fanout_arr[i] = static_cast(task->fanout[i]); + } + fanout_count = task->fanout_count; } if (l2_perf_aicpu_complete_record( - core_id, static_cast(completed_task_id), static_cast(completed_task_id), - task->func_id, h->core_type, dispatch_timestamps_[core_id], finish_ts, fanout_arr, - task->fanout_count + core_id, thread_idx, static_cast(completed_task_id), + static_cast(completed_task_id), task->func_id, h->core_type, + dispatch_timestamps_[core_id], finish_ts, fanout_arr, fanout_count ) != 0) { LOG_ERROR( "Core %d: l2_perf_aicpu_complete_record failed for task %d", core_id, completed_task_id ); } - dispatch_timestamps_[core_id] = get_sys_cnt_aicpu(); + if (l2_perf_level >= L2PerfLevel::AICPU_TIMING) { + dispatch_timestamps_[core_id] = get_sys_cnt_aicpu(); + } } cur_thread_completed++; @@ -817,7 +832,7 @@ int AicpuExecutor::resolve_and_dispatch(Runtime &runtime, int thread_idx, const made_progress = true; // Update timestamp if didn't dispatch (try_dispatch_task updates it if dispatched) - if (!dispatched && l2_perf_enabled) { + if (!dispatched && l2_perf_enabled && l2_perf_level >= L2PerfLevel::AICPU_TIMING) { dispatch_timestamps_[core_id] = get_sys_cnt_aicpu(); } } else if (reg_task_id == pending_task_ids_[core_id] && reg_state == TASK_ACK_STATE) { @@ -840,23 +855,29 @@ int AicpuExecutor::resolve_and_dispatch(Runtime &runtime, int thread_idx, const if (prev_running_id != AICPU_TASK_INVALID) { // Profiling: complete the implicit task's AICore record if (l2_perf_enabled) { - uint64_t finish_ts = get_sys_cnt_aicpu(); + uint64_t finish_ts = (l2_perf_level >= L2PerfLevel::AICPU_TIMING) ? get_sys_cnt_aicpu() : 0; Task *prev_task = &runtime.tasks[prev_running_id]; uint64_t fanout_arr[RUNTIME_MAX_FANOUT]; - for (int i = 0; i < prev_task->fanout_count; i++) { - fanout_arr[i] = static_cast(prev_task->fanout[i]); + int fanout_count = 0; + if (l2_perf_level >= L2PerfLevel::AICPU_TIMING) { + for (int i = 0; i < prev_task->fanout_count; i++) { + fanout_arr[i] = static_cast(prev_task->fanout[i]); + } + fanout_count = prev_task->fanout_count; } if (l2_perf_aicpu_complete_record( - core_id, static_cast(prev_running_id), static_cast(prev_running_id), - prev_task->func_id, h->core_type, dispatch_timestamps_[core_id], finish_ts, fanout_arr, - prev_task->fanout_count + core_id, thread_idx, static_cast(prev_running_id), + static_cast(prev_running_id), prev_task->func_id, h->core_type, + dispatch_timestamps_[core_id], finish_ts, fanout_arr, fanout_count ) != 0) { LOG_ERROR( "Core %d: l2_perf_aicpu_complete_record failed for implicit task %d", core_id, prev_running_id ); } - dispatch_timestamps_[core_id] = get_sys_cnt_aicpu(); + if (l2_perf_level >= L2PerfLevel::AICPU_TIMING) { + dispatch_timestamps_[core_id] = get_sys_cnt_aicpu(); + } } cur_thread_completed++; @@ -885,22 +906,28 @@ int AicpuExecutor::resolve_and_dispatch(Runtime &runtime, int thread_idx, const int completed_task_id = running_task_ids_[core_id]; if (l2_perf_enabled) { - uint64_t finish_ts = get_sys_cnt_aicpu(); + uint64_t finish_ts = (l2_perf_level >= L2PerfLevel::AICPU_TIMING) ? get_sys_cnt_aicpu() : 0; Task *task = &runtime.tasks[completed_task_id]; uint64_t fanout_arr[RUNTIME_MAX_FANOUT]; - for (int i = 0; i < task->fanout_count; i++) { - fanout_arr[i] = static_cast(task->fanout[i]); + int fanout_count = 0; + if (l2_perf_level >= L2PerfLevel::AICPU_TIMING) { + for (int i = 0; i < task->fanout_count; i++) { + fanout_arr[i] = static_cast(task->fanout[i]); + } + fanout_count = task->fanout_count; } if (l2_perf_aicpu_complete_record( - core_id, static_cast(completed_task_id), static_cast(completed_task_id), - task->func_id, h->core_type, dispatch_timestamps_[core_id], finish_ts, fanout_arr, - task->fanout_count + core_id, thread_idx, static_cast(completed_task_id), + static_cast(completed_task_id), task->func_id, h->core_type, + dispatch_timestamps_[core_id], finish_ts, fanout_arr, fanout_count ) != 0) { LOG_ERROR( "Core %d: l2_perf_aicpu_complete_record failed for task %d", core_id, completed_task_id ); } - dispatch_timestamps_[core_id] = get_sys_cnt_aicpu(); + if (l2_perf_level >= L2PerfLevel::AICPU_TIMING) { + dispatch_timestamps_[core_id] = get_sys_cnt_aicpu(); + } } cur_thread_completed++; @@ -932,7 +959,7 @@ int AicpuExecutor::resolve_and_dispatch(Runtime &runtime, int thread_idx, const made_progress = true; // Update timestamp if didn't dispatch (try_dispatch_task updates it if dispatched) - if (!dispatched && l2_perf_enabled) { + if (!dispatched && l2_perf_enabled && l2_perf_level >= L2PerfLevel::AICPU_TIMING) { dispatch_timestamps_[core_id] = get_sys_cnt_aicpu(); } } diff --git a/src/a5/runtime/tensormap_and_ringbuffer/aicpu/aicpu_executor.cpp b/src/a5/runtime/tensormap_and_ringbuffer/aicpu/aicpu_executor.cpp index 33ebea118e..217a5781ef 100644 --- a/src/a5/runtime/tensormap_and_ringbuffer/aicpu/aicpu_executor.cpp +++ b/src/a5/runtime/tensormap_and_ringbuffer/aicpu/aicpu_executor.cpp @@ -480,7 +480,7 @@ int32_t AicpuExecutor::run(Runtime *runtime) { } #if PTO2_PROFILING - rt->orchestrator.enable_l2_swimlane = is_l2_swimlane_enabled(); + rt->orchestrator.l2_perf_level = get_l2_perf_level(); #endif // Total core counts = aic_count_ / aiv_count_ (set once at runtime init). @@ -502,7 +502,7 @@ int32_t AicpuExecutor::run(Runtime *runtime) { sched_ctx_.wait_init_complete(); #if PTO2_PROFILING - if (is_l2_swimlane_enabled()) { + if (get_l2_perf_level() >= L2PerfLevel::ORCH_PHASES) { l2_perf_aicpu_set_orch_thread_idx(thread_idx); } #endif diff --git a/src/a5/runtime/tensormap_and_ringbuffer/docs/profiling_levels.md b/src/a5/runtime/tensormap_and_ringbuffer/docs/profiling_levels.md index 7dc6d5b02e..34e17cc86b 100644 --- a/src/a5/runtime/tensormap_and_ringbuffer/docs/profiling_levels.md +++ b/src/a5/runtime/tensormap_and_ringbuffer/docs/profiling_levels.md @@ -4,22 +4,7 @@ This document describes the profiling macro hierarchy and logging control in the ## Overview -PTO Runtime2 uses a hierarchical profiling system with compile-time macros to control profiling code compilation and log output. The `enable_l2_swimlane` runtime flag controls data collection (performance buffers, shared memory writes) but does NOT control log output. - -### CI coverage - -The default CI build leaves `PTO2_PROFILING=1` (base) and the three sub-flags (`PTO2_ORCH_PROFILING`, `PTO2_SCHED_PROFILING`, `PTO2_TENSORMAP_PROFILING`) at `0`. The `profiling-flags-smoke` job in `.github/workflows/ci.yml` exercises the non-default combinations and runs the smallest full-pipeline example (`examples//tensormap_and_ringbuffer/vector_example/`) against the rebuilt binaries: - -| Combo | `CXX` defines | -| ----- | ------------- | -| `pto2-off` | `-DPTO2_PROFILING=0` | -| `orch` | `-DPTO2_ORCH_PROFILING=1` | -| `orch-tensormap` | `-DPTO2_ORCH_PROFILING=1 -DPTO2_TENSORMAP_PROFILING=1` | -| `sched` | `-DPTO2_SCHED_PROFILING=1` | -| `orch-sched` | `-DPTO2_ORCH_PROFILING=1 -DPTO2_SCHED_PROFILING=1` | -| `all-on` | `-DPTO2_ORCH_PROFILING=1 -DPTO2_SCHED_PROFILING=1 -DPTO2_TENSORMAP_PROFILING=1` | - -Each combo runs sequentially on both `a2a3sim` and `a5sim` inside a single CI job (12 iterations total in one bash loop, not a matrix — apt/python/pip setup is paid once instead of 12 times). Failures across iterations are accumulated and reported together at the end. Compile failures, format-string mismatches, runtime crashes, or output-shape regressions in any individually gated code path show up there with the failing leg attributing the specific switch. +PTO Runtime2 uses a hierarchical profiling system with compile-time macros to control profiling code compilation and log output. The `enable_l2_swimlane` runtime flag (integer perf_level 0–4) controls data collection granularity (performance buffers, shared memory writes) but does NOT control log output. ## Profiling Macro Hierarchy @@ -28,7 +13,7 @@ PTO2_PROFILING (base level, default=1) ├── PTO2_ORCH_PROFILING (orchestrator, default=0, requires PTO2_PROFILING=1) | └──PTO2_TENSORMAP_PROFILING (tensormap, default=0, requires PTO2_ORCH_PROFILING=1) ├── PTO2_SCHED_PROFILING (scheduler, default=0, requires PTO2_PROFILING=1) -└── --enable-l2-swimlane (Dump profiling merged swimlane json file for visualization, requires PTO2_PROFILING=1) +└── --enable-l2-swimlane [PERF_LEVEL] (L2 swimlane data collection, 0-4, bare=4, requires PTO2_PROFILING=1) ``` @@ -246,36 +231,75 @@ Thread X: overlap checks : XXX, hits=XXX (XX.X%) --- -## Runtime Flag: enable_l2_swimlane +## Runtime Flag: enable_l2_swimlane (perf_level) -L2 swimlane enablement is published through the handshake -`enable_profiling_flag` bitmask (bit1 = `PROFILING_FLAG_L2_SWIMLANE`). -AICPU code reads it via `is_l2_swimlane_enabled()` (set at launch time -by the platform from `kernel_args.l2_perf_data_base` + the bitmask). It -controls **data collection**, NOT log output. +`--enable-l2-swimlane` accepts an integer perf_level (0–4). Transport +mirrors the PMU pattern — two independent channels (one binary, one int): -### When enable_l2_swimlane=true +- **Binary on/off** — `KernelArgs::enable_profiling_flag` bit1 + (`PROFILING_FLAG_L2_SWIMLANE`). Set by the host whenever level > 0; read + by AICore (which only needs on/off to decide whether to write timing) and + by AICPU kernel entry via `set_l2_swimlane_enabled(bool)`. +- **Granular level (0–4)** — `L2PerfDataHeader::l2_perf_level` + (shared memory). Host writes it in `L2PerfCollector::initialize`; AICPU + promotes it from the header in `l2_perf_aicpu_init` and exposes it via + `get_l2_perf_level()` (typed `L2PerfLevel`) for + `>= AICPU_TIMING / SCHED_PHASES / ORCH_PHASES` gates. -- Performance buffers are allocated and written -- Per-task timing data is collected -- Phase profiling data is recorded -- Orchestrator summary is written to shared memory +On sim, the binary on/off travels via the dlsym'd `set_l2_swimlane_enabled` +entry point; the granular level still goes through the shared-memory +header just like on onboard. -### When enable_l2_swimlane=false +| Level | Collects | +| ----- | -------- | +| 0 | Nothing (disabled) | +| 1 | AICore timing only (start/end/task_id/func_id/core_type) | +| 2 | + dispatch_time, finish_time, fanout | +| 3 | + Scheduler phases (`SCHED_*`) | +| 4 | + Orchestrator phases (full) | -- No performance data collection -- No shared memory writes -- Logs still print (controlled by macros only) +Bare `--enable-l2-swimlane` = level 4 (backward compatible). -### Usage +### Level gating in AICPU code + +Use the strongly-typed `L2PerfLevel` enum so each gate names the +content it depends on instead of relying on magic numbers: ```cpp -// AICPU path — read enablement from the platform accessor, not the Runtime struct. -if (is_l2_swimlane_enabled()) { - // ... perf-collection code ... -} +// Any level > 0: AICPU task record buffer init / flush. +// Cheap binary check, available immediately after kernel entry. +if (is_l2_swimlane_enabled()) { ... } + +// AICPU dispatch/finish timestamps + fanout. +// Granular checks below require l2_perf_aicpu_init to have already run +// (so the level has been promoted from the shared-memory header). +if (get_l2_perf_level() >= L2PerfLevel::AICPU_TIMING) { ... } + +// Scheduler main-loop phase records (SCHED_*) +if (get_l2_perf_level() >= L2PerfLevel::SCHED_PHASES) { ... } + +// Orchestrator phase records +if (get_l2_perf_level() >= L2PerfLevel::ORCH_PHASES) { ... } ``` +`L2PerfLevel` is defined in `common/l2_perf_profiling.h` with +underlying type `uint32_t` (matches the `L2PerfDataHeader::l2_perf_level` +shared-memory field and mirrors `PmuEventType : uint32_t`): + +| Enumerator | Underlying value | +| ---------- | ---------------- | +| `DISABLED` | 0 | +| `AICORE_TIMING` | 1 | +| `AICPU_TIMING` | 2 | +| `SCHED_PHASES` | 3 | +| `ORCH_PHASES` | 4 | + +### When enable_l2_swimlane=0 + +- No performance data collection +- No shared memory writes +- Logs still print (controlled by macros only) + --- ## Common Profiling Configurations @@ -381,8 +405,8 @@ add_definitions(-DPTO2_ORCH_PROFILING=1) ### Code Locations - Macro definitions: `src/a2a3/runtime/tensormap_and_ringbuffer/runtime/pto_runtime2_types.h` -- Scheduler profiling: `src/a5/runtime/tensormap_and_ringbuffer/runtime/scheduler/scheduler_dispatch.cpp` and `scheduler_cold_path.cpp` -- Orchestrator profiling: `src/a5/runtime/tensormap_and_ringbuffer/aicpu/aicpu_executor.cpp` +- Scheduler profiling: `src/a2a3/runtime/tensormap_and_ringbuffer/runtime/scheduler/scheduler_dispatch.cpp` and `scheduler_cold_path.cpp` +- Orchestrator profiling: `src/a2a3/runtime/tensormap_and_ringbuffer/aicpu/aicpu_executor.cpp` - TensorMap profiling: `src/a2a3/runtime/tensormap_and_ringbuffer/runtime/pto_tensormap.h` --- @@ -398,7 +422,7 @@ add_definitions(-DPTO2_ORCH_PROFILING=1) ### Runtime overhead - Logging: Negligible (device logs are asynchronous) -- Data collection (`enable_l2_swimlane=true`): Low to moderate +- Data collection (`enable_l2_swimlane>0`): Low to moderate - Performance buffer writes - Shared memory updates - Per-task timing measurements diff --git a/src/a5/runtime/tensormap_and_ringbuffer/runtime/pto_orchestrator.cpp b/src/a5/runtime/tensormap_and_ringbuffer/runtime/pto_orchestrator.cpp index 8b72f60f6d..d57006f78d 100644 --- a/src/a5/runtime/tensormap_and_ringbuffer/runtime/pto_orchestrator.cpp +++ b/src/a5/runtime/tensormap_and_ringbuffer/runtime/pto_orchestrator.cpp @@ -94,8 +94,8 @@ __attribute__((weak, visibility("hidden"))) void l2_perf_aicpu_record_orch_phase(AicpuPhaseId, uint64_t, uint64_t, uint32_t, uint64_t) {} // submit_idx needed for swimlane task_id tagging (no cycle accumulation at this level) static uint32_t g_orch_submit_idx = 0; -#define CYCLE_COUNT_START() \ - bool _prof_active = orch->enable_l2_swimlane; \ +#define CYCLE_COUNT_START() \ + bool _prof_active = (orch->l2_perf_level >= L2PerfLevel::ORCH_PHASES); \ uint64_t _t0 = _prof_active ? get_sys_cnt_aicpu() : 0, _t1 = 0 #define CYCLE_COUNT_LAP(acc) \ do { \ diff --git a/src/a5/runtime/tensormap_and_ringbuffer/runtime/pto_orchestrator.h b/src/a5/runtime/tensormap_and_ringbuffer/runtime/pto_orchestrator.h index 731a2d61a8..e24b85b4e8 100644 --- a/src/a5/runtime/tensormap_and_ringbuffer/runtime/pto_orchestrator.h +++ b/src/a5/runtime/tensormap_and_ringbuffer/runtime/pto_orchestrator.h @@ -28,6 +28,7 @@ #pragma once #include "device_arena.h" +#include "common/l2_perf_profiling.h" #include "pto_ring_buffer.h" #include "pto_runtime2_types.h" #include "pto_submit_types.h" @@ -91,8 +92,8 @@ struct PTO2OrchestratorState { int32_t total_cluster_count{0}; // AIC cores = MIX clusters int32_t total_aiv_count{0}; // AIV cores (= 2 × clusters on standard hardware) #if PTO2_PROFILING - // Runtime profiling switch copied from Runtime::enable_l2_swimlane. - bool enable_l2_swimlane; + // L2 perf_level copied from get_l2_perf_level(). + L2PerfLevel l2_perf_level{L2PerfLevel::DISABLED}; #endif // === GM HEAP (for output buffers) === diff --git a/src/a5/runtime/tensormap_and_ringbuffer/runtime/scheduler/scheduler_cold_path.cpp b/src/a5/runtime/tensormap_and_ringbuffer/runtime/scheduler/scheduler_cold_path.cpp index 16ead69a1f..13ad5c962b 100644 --- a/src/a5/runtime/tensormap_and_ringbuffer/runtime/scheduler/scheduler_cold_path.cpp +++ b/src/a5/runtime/tensormap_and_ringbuffer/runtime/scheduler/scheduler_cold_path.cpp @@ -805,6 +805,23 @@ int32_t SchedulerContext::init( orch_to_sched_ = orch_to_sched; regs_ = regs_base; +#if PTO2_PROFILING + // l2_perf_aicpu_init promotes g_l2_perf_level from the shared-memory + // header — must be called BEFORE the orchestrator thread caches the level + // via rt->orchestrator.l2_perf_level = get_l2_perf_level() in + // AicpuExecutor::run(). Otherwise the cached value would still be DISABLED + // (only the binary enable bit has been seeded by kernel.cpp at this point), + // and the CYCLE_COUNT_START() gate in pto_orchestrator.cpp would suppress + // all ORCH_PHASES records. + if (is_l2_swimlane_enabled()) { + l2_perf_aicpu_init(runtime->worker_count); + l2_perf_level_ = get_l2_perf_level(); + if (l2_perf_level_ >= L2PerfLevel::SCHED_PHASES) { + l2_perf_aicpu_init_phase(runtime->worker_count, sched_thread_num_); + } + } +#endif + // Discover cores and assign to scheduler threads. int32_t rc = handshake_all_cores(runtime); if (rc != 0) { @@ -925,7 +942,7 @@ void SchedulerContext::on_orchestration_done( Runtime *runtime, PTO2Runtime *rt, int32_t thread_idx, int32_t total_tasks ) { #if PTO2_PROFILING - if (is_l2_swimlane_enabled()) { + if (l2_perf_level_ >= L2PerfLevel::SCHED_PHASES) { // Flush orchestrator's phase record buffer l2_perf_aicpu_flush_phase_buffers(thread_idx); } @@ -980,7 +997,7 @@ void SchedulerContext::on_orchestration_done( // Write core-to-thread mapping AFTER reassignment so the profiling data // reflects the final distribution (all active_sched_threads_, including // former orchestrator threads when orch_to_sched_ is enabled). - if (is_l2_swimlane_enabled()) { + if (l2_perf_level_ >= L2PerfLevel::SCHED_PHASES) { l2_perf_aicpu_init_core_assignments(cores_total_num_); for (int32_t t = 0; t < active_sched_threads_; t++) { l2_perf_aicpu_write_core_assignments_for_thread( diff --git a/src/a5/runtime/tensormap_and_ringbuffer/runtime/scheduler/scheduler_completion.cpp b/src/a5/runtime/tensormap_and_ringbuffer/runtime/scheduler/scheduler_completion.cpp index 388a9bbfb0..f61d832be7 100644 --- a/src/a5/runtime/tensormap_and_ringbuffer/runtime/scheduler/scheduler_completion.cpp +++ b/src/a5/runtime/tensormap_and_ringbuffer/runtime/scheduler/scheduler_completion.cpp @@ -154,19 +154,22 @@ void SchedulerContext::complete_slot_task( #if PTO2_SCHED_PROFILING uint64_t t_perf_start = get_sys_cnt_aicpu(); #endif - uint64_t finish_ts = get_sys_cnt_aicpu(); - + uint64_t finish_ts = 0; uint64_t fanout_arr[RUNTIME_MAX_FANOUT]; int32_t fanout_n = 0; - PTO2DepListEntry *cur = slot_state.fanout_head; - while (cur != nullptr && fanout_n < RUNTIME_MAX_FANOUT) { - fanout_arr[fanout_n++] = cur->slot_state->task->task_id.raw; - cur = cur->next; + + if (l2_perf_level_ >= L2PerfLevel::AICPU_TIMING) { + finish_ts = get_sys_cnt_aicpu(); + PTO2DepListEntry *cur = slot_state.fanout_head; + while (cur != nullptr && fanout_n < RUNTIME_MAX_FANOUT) { + fanout_arr[fanout_n++] = cur->slot_state->task->task_id.raw; + cur = cur->next; + } } int32_t perf_slot_idx = static_cast(subslot); if (l2_perf_aicpu_complete_record( - core_id, static_cast(expected_reg_task_id), slot_state.task->task_id.raw, + core_id, thread_idx, static_cast(expected_reg_task_id), slot_state.task->task_id.raw, slot_state.task->kernel_id[perf_slot_idx], hank[core_id].core_type, dispatch_ts, finish_ts, fanout_arr, fanout_n ) != 0) { diff --git a/src/a5/runtime/tensormap_and_ringbuffer/runtime/scheduler/scheduler_context.h b/src/a5/runtime/tensormap_and_ringbuffer/runtime/scheduler/scheduler_context.h index 3d96dd94e6..9920f1f9cc 100644 --- a/src/a5/runtime/tensormap_and_ringbuffer/runtime/scheduler/scheduler_context.h +++ b/src/a5/runtime/tensormap_and_ringbuffer/runtime/scheduler/scheduler_context.h @@ -11,6 +11,7 @@ #ifndef SCHEDULER_CONTEXT_H #define SCHEDULER_CONTEXT_H +#include "common/l2_perf_profiling.h" #include "common/unified_log.h" #include "scheduler_types.h" @@ -134,6 +135,9 @@ class SchedulerContext { #if PTO2_PROFILING SchedL2PerfCounters sched_l2_perf_[MAX_AICPU_THREADS]; + // Cached once at init() from get_l2_perf_level(), AFTER + // l2_perf_aicpu_init has promoted the level from the shared-memory header. + L2PerfLevel l2_perf_level_{L2PerfLevel::DISABLED}; #endif // --- Task-execution tracking --- diff --git a/src/a5/runtime/tensormap_and_ringbuffer/runtime/scheduler/scheduler_dispatch.cpp b/src/a5/runtime/tensormap_and_ringbuffer/runtime/scheduler/scheduler_dispatch.cpp index 4088b989d4..2ec664bfa0 100644 --- a/src/a5/runtime/tensormap_and_ringbuffer/runtime/scheduler/scheduler_dispatch.cpp +++ b/src/a5/runtime/tensormap_and_ringbuffer/runtime/scheduler/scheduler_dispatch.cpp @@ -125,12 +125,7 @@ void SchedulerContext::dispatch_subtask_to_core( ) { CoreTracker &tracker = core_trackers_[thread_idx]; auto core_id = tracker.get_core_id_by_offset(core_offset); -#if PTO2_PROFILING - auto &l2_perf = sched_l2_perf_[thread_idx]; (void)runtime; -#else - (void)runtime; -#endif CoreExecState &core_exec_state = core_exec_states_[core_id]; core_exec_state.dispatch_seq++; uint32_t reg_task_id = core_exec_state.dispatch_seq & TASK_ID_MASK; @@ -155,7 +150,7 @@ void SchedulerContext::dispatch_subtask_to_core( core_exec_state.pending_slot_state = &slot_state; core_exec_state.pending_reg_task_id = static_cast(reg_task_id); #if PTO2_PROFILING - if (l2_perf.l2_perf_enabled) { + if (l2_perf_level_ >= L2PerfLevel::AICPU_TIMING) { core_exec_state.pending_dispatch_timestamp = get_sys_cnt_aicpu(); } #endif @@ -164,7 +159,7 @@ void SchedulerContext::dispatch_subtask_to_core( core_exec_state.running_slot_state = &slot_state; core_exec_state.running_reg_task_id = static_cast(reg_task_id); #if PTO2_PROFILING - if (l2_perf.l2_perf_enabled) { + if (l2_perf_level_ >= L2PerfLevel::AICPU_TIMING) { core_exec_state.running_dispatch_timestamp = get_sys_cnt_aicpu(); } #endif @@ -356,17 +351,15 @@ int32_t SchedulerContext::resolve_and_dispatch(Runtime *runtime, int32_t thread_ static_cast(header->rings[0].task_window_size) ); - // One-time init: assign perf buffers (one thread does it; others wait) + // One-time init: assign perf buffers (one thread does it; others wait). + // l2_perf_aicpu_init / l2_perf_aicpu_init_phase already ran eagerly in + // SchedulerContext::init() so the orchestrator thread can read the + // promoted g_l2_perf_level before caching it on rt->orchestrator. Only + // dump_tensor / pmu init remain dispatch-time because they depend on + // handshake-derived core IDs / counts. if (!init_done_.exchange(true, std::memory_order_acq_rel)) { LOG_INFO_V0("Thread %d: doing one-time init", thread_idx); -#if PTO2_PROFILING - if (is_l2_swimlane_enabled()) { - l2_perf_aicpu_init(runtime->worker_count); - l2_perf_aicpu_init_phase(runtime->worker_count, sched_thread_num_); - l2_perf_aicpu_set_orch_thread_idx(sched_thread_num_); - } -#endif #if PTO2_PROFILING if (is_dump_tensor_enabled()) { dump_tensor_init(orch_to_sched_ ? thread_num_ : sched_thread_num_); @@ -392,7 +385,7 @@ int32_t SchedulerContext::resolve_and_dispatch(Runtime *runtime, int32_t thread_ #if PTO2_PROFILING auto &l2_perf = sched_l2_perf_[thread_idx]; l2_perf.reset(); - l2_perf.l2_perf_enabled = is_l2_swimlane_enabled(); + l2_perf.l2_perf_enabled = (l2_perf_level_ != L2PerfLevel::DISABLED); #endif constexpr int LOCAL_READY_CAP_PER_TYPE = 64; @@ -497,7 +490,7 @@ int32_t SchedulerContext::resolve_and_dispatch(Runtime *runtime, int32_t thread_ CYCLE_COUNT_LAP(l2_perf.sched_idle_cycle); } else { CYCLE_COUNT_LAP(l2_perf.sched_complete_cycle); - if (l2_perf.l2_perf_enabled && l2_perf.phase_complete_count > 0) { + if (l2_perf_level_ >= L2PerfLevel::SCHED_PHASES && l2_perf.phase_complete_count > 0) { l2_perf_aicpu_record_phase( thread_idx, AicpuPhaseId::SCHED_COMPLETE, _t0_phase, _t1, l2_perf.sched_loop_count, l2_perf.phase_complete_count @@ -604,7 +597,7 @@ int32_t SchedulerContext::resolve_and_dispatch(Runtime *runtime, int32_t thread_ CYCLE_COUNT_LAP(l2_perf.sched_idle_cycle); } else { CYCLE_COUNT_LAP(l2_perf.sched_dispatch_cycle); - if (l2_perf.l2_perf_enabled && l2_perf.phase_dispatch_count > 0) { + if (l2_perf_level_ >= L2PerfLevel::SCHED_PHASES && l2_perf.phase_dispatch_count > 0) { // Per-emit pop deltas via snapshot diff; the cumulative // pop_hit / pop_miss stay intact for the cold-path log. uint64_t pop_hit_delta = l2_perf.pop_hit - l2_perf.pop_hit_at_last_emit; @@ -665,7 +658,7 @@ int32_t SchedulerContext::resolve_and_dispatch(Runtime *runtime, int32_t thread_ } #if PTO2_PROFILING CYCLE_COUNT_LAP(l2_perf.sched_idle_cycle); - if (l2_perf.l2_perf_enabled) { + if (l2_perf_level_ >= L2PerfLevel::SCHED_PHASES) { l2_perf_aicpu_record_phase( thread_idx, AicpuPhaseId::SCHED_IDLE_WAIT, _t0_phase, _t1, l2_perf.sched_loop_count, 0 ); @@ -693,7 +686,9 @@ int32_t SchedulerContext::resolve_and_dispatch(Runtime *runtime, int32_t thread_ // dispatch emit (typically the trailing idle loops while waiting for // orchestrator_done_) as a zero-duration synthetic dispatch record so // sum(record.pop_*) reconciles with the run-cumulative counter. - if (l2_perf.l2_perf_enabled) { + // Gate on SCHED_PHASES — at lower levels the phase buffer is never + // flushed (see below), so writing this record would be wasted work. + if (l2_perf_level_ >= L2PerfLevel::SCHED_PHASES) { uint64_t final_pop_hit_delta = l2_perf.pop_hit - l2_perf.pop_hit_at_last_emit; uint64_t final_pop_miss_delta = l2_perf.pop_miss - l2_perf.pop_miss_at_last_emit; debug_assert(final_pop_hit_delta < (1ULL << 32)); @@ -716,7 +711,9 @@ int32_t SchedulerContext::resolve_and_dispatch(Runtime *runtime, int32_t thread_ l2_perf_aicpu_flush_buffers( thread_idx, core_trackers_[thread_idx].core_ids(), core_trackers_[thread_idx].core_num() ); - l2_perf_aicpu_flush_phase_buffers(thread_idx); + if (l2_perf_level_ >= L2PerfLevel::SCHED_PHASES) { + l2_perf_aicpu_flush_phase_buffers(thread_idx); + } } #endif #if PTO2_PROFILING