Docs / Guides / Profiling an inference

Profiling an inferencev0.2.0

SynapticOS ships a built-in profiler that breaks an inference into stages — preprocess, NPU execution, postprocess — and records peak arena memory, all using the Zephyr cycle counter. This guide shows the workflow: enable it in Kconfig, drive it from the syn shell, and read the numbers.

Note · Phase 2 status

In v0.1.0 the profiler's internal marks (syn_prof_mark_start() and friends) existed but were not wired into any inference path, so syn prof last always reported No profiling data available. As of v0.2.0 the pipeline executor fires the marks at every stage boundary, and anything that runs through the scheduler — syn_infer_run_sync(), submitted jobs, the syn infer run shell command — produces a real result. This is verified live on the FRDM-MCXN947 (2026-07-12): on the board, syn prof last after a syn infer run reports 1069 µs total / 1 µs preprocess / 1068 µs NPU / 1 µs postprocess, peak 1792 bytes (stub NPU backend). The example numbers below are QEMU icount measurements against the same stub backend.

Step 1 — Enable profiling at build time

Profiling is gated by CONFIG_SYNAPTIC_PROFILING (default y when DEBUG is set, zero overhead when disabled). You will also want the shell commands:

prj.conf

CONFIG_SYNAPTIC=y
CONFIG_SYNAPTIC_PROFILING=y
CONFIG_SYNAPTIC_SHELL=y
CONFIG_SHELL=y
CONFIG_LOG=y

Step 2 — Drive it from the shell

Over the serial console (115200 baud on the FRDM board), turn the profiler on, run an inference, then query the last result:

uart

uart:~$ syn prof last
Last inference:
  Total:       1010 us
  Preprocess:  4 us
  NPU:         1003 us
  Postprocess: 5 us
  Memory peak: 896 bytes

The numbers above are the profile of the hello_inference boot inference in v0.2.0 on QEMU (stub NPU); that run measured 1361 µs of wall time around syn_infer_run_sync(). The gap between the wall time and the 1010 µs profiled total is scheduler overhead outside the marked region (job submission, the scheduler thread wakeup, and completion signaling). The same pattern holds on hardware: the FRDM board measures 1130 µs wall against a 1069 µs profiled total — about 92 µs of scheduler path over the 1038 µs Phase 1 direct-HAL baseline. To trigger a fresh inference without rebooting, use the Phase 2 shell command syn infer run <model-name> — it runs a scheduler-driven inference on any registered model, prints the top class and elapsed time, and points you back at syn prof last.

Step 3 — Interpret the result

Each field of syn_prof_result_t (from include/synaptic/syn_prof.h) is derived from cycle-counter deltas between the stage marks:

Field	Meaning
`total_us`	Wall time from inference start to end.
`preprocess_us`	Time from start mark to the preprocess-done mark (input normalization, layout conversion).
`npu_us`	Time the NPU spent executing the model, measured between the preprocess-done and NPU-done marks.
`postprocess_us`	Time from NPU-done to the end mark (softmax, argmax, decoding).
`ipc_overhead_us`	Reserved for inter-core dispatch overhead in dual-core operation (Phase 3).
`mem_peak_bytes`	Peak tensor-arena usage captured from `syn_mem_get_stats()` at the end mark.
`npu_utilization_pct`	`npu_us * 100 / total_us` — how much of the inference was spent on the accelerator. A low value means pre/postprocessing on the CPU dominates.

A healthy pipeline pushes npu_utilization_pct up: if preprocess dominates, that is the signal to move normalization onto the DSP or DMA the input in place. mem_peak_bytes tells you how far you can shrink CONFIG_SYNAPTIC_TENSOR_ARENA_SIZE before allocations fail.

Programmatic access

The same data is available in C. syn_prof_get_last() returns -ENOENT while no result has been captured, and syn_prof_print_summary() logs either the full stage breakdown or No profiling data available:

#include <synaptic/syn_prof.h>

syn_prof_enable();
/* ... run inference ... */
syn_prof_result_t r;
if (syn_prof_get_last(&r) == 0) {
        printk("NPU: %u us (%u%% of %u us)\n",
               r.npu_us, r.npu_utilization_pct, r.total_us);
}
syn_prof_print_summary();

Note · Per-layer tracing

syn_prof_enable_layer_trace() and syn_prof_get_layer_time() are declared in the header but still return -ENOTSUP as of Phase 2. Per-layer timing needs real per-layer NPU callbacks, which arrive with the Neutron SDK integration and the later preemption work.

Wall-clock bracketing remains useful alongside the profiler: hello_inference still wraps its syn_infer_run_sync() call in k_cycle_get_32() / k_cyc_to_us_ceil32(), which is how the 1361 µs QEMU and 1130 µs FRDM wall figures were measured. The published Phase 1 hardware numbers — 1038 us end-to-end on the FRDM-MCXN947 versus 781 us on QEMU, direct-HAL path — were measured the same way and stand unchanged.

← PreviousThe samples Next →Running the test suite