feat(profiling): flag-gated ISR cycle/CPU-load harness for F051

Inc/profiling.h

@@ -0,0 +1,90 @@
+/*
+ * profiling.h
+ *
+ * Lightweight ISR cycle profiling for the flash-/cycle-constrained F051.
+ *
+ * Cortex-M0 has no DWT->CYCCNT and no ITM/SWO, so the two canonical ways to
+ * measure ISR cost are (a) a GPIO toggled around the ISR, read on a logic
+ * analyzer / scope, and (b) a free-running timer used as a poor-man's cycle
+ * counter. This header does BOTH from one instrumentation point:
+ *
+ *   - GPIO marker: a pin is driven HIGH while any instrumented ISR runs, so the
+ *     wire shows aggregate ISR (CPU) load. Optional; needs a free pad.
+ *   - Cycle counter: TIM17 (otherwise unused on the F051) is repurposed as a
+ *     48 MHz free-running counter -> 1 tick == 1 core cycle. Per-ISR last/max
+ *     cycle counts land in arrays you read over SWD (watch prof_cyc_max[]) or
+ *     stream over telemetry.
+ *
+ * All of this compiles to nothing unless PROFILE_ISR is defined, so production
+ * builds are byte-for-byte identical.
+ *
+ * Caveat: a measured duration includes any higher-priority ISR that preempts
+ * the region. The comparator zero-cross is the highest-priority motor ISR, so
+ * its numbers are clean; lower-priority regions read as wall-clock (which is
+ * usually what you want for a "can it keep up" budget).
+ */
+
+#ifndef PROFILING_H_
+#define PROFILING_H_
+
+/* ---- turn the harness on for a measurement build -------------------------
+ * Define here, per-target in targets.h, or pass -DPROFILE_ISR to make.       */
+// #define PROFILE_ISR
+
+/* ---- optional logic-analyzer marker pin ----------------------------------
+ * Point these at a pad broken out on your board (e.g. the serial-telemetry
+ * pin with telemetry disabled for the run). Leave undefined for counters-only
+ * measurement over SWD.                                                       */
+// #define PROFILE_GPIO_PORT GPIOB
+// #define PROFILE_GPIO_PIN  LL_GPIO_PIN_6
+
+#ifdef PROFILE_ISR
+#include "main.h"
+
+enum {
+    PROF_COMP_ZC = 0, /* ADC1_COMP_IRQHandler -> interruptRoutine (zero-cross) */
+    PROF_20KHZ,       /* TIM6_DAC_IRQHandler  -> tenKhzRoutine    (control)    */
+    PROF_DSHOT,       /* EXTI4_15_IRQHandler  -> processDshot     (decode)     */
+    PROF_TIM14,       /* TIM14_IRQHandler     -> PeriodElapsedCallback         */
+    PROF_N
+};
+
+extern volatile uint16_t prof_cyc_last[PROF_N]; /* last duration, core cycles  */
+extern volatile uint16_t prof_cyc_max[PROF_N];  /* worst case since boot       */
+extern volatile uint32_t prof_cyc_sum[PROF_N];  /* running cycle total (wraps) */
+extern volatile uint32_t prof_calls[PROF_N];    /* invocation count            */
+
+void profiling_init(void); /* repurposes TIM17 as a 48 MHz counter + marker pin */
+
+__attribute__((always_inline)) static inline uint16_t prof_enter(void)
+{
+#ifdef PROFILE_GPIO_PORT
+    PROFILE_GPIO_PORT->BSRR = PROFILE_GPIO_PIN; /* marker high */
+#endif
+    return (uint16_t)TIM17->CNT;
+}
+
+__attribute__((always_inline)) static inline void prof_exit(int i, uint16_t t0)
+{
+    uint16_t d = (uint16_t)((uint16_t)TIM17->CNT - t0);
+#ifdef PROFILE_GPIO_PORT
+    PROFILE_GPIO_PORT->BRR = PROFILE_GPIO_PIN; /* marker low */
+#endif
+    prof_cyc_last[i] = d;
+    if (d > prof_cyc_max[i])
+        prof_cyc_max[i] = d;
+    prof_cyc_sum[i] += d;
+    prof_calls[i]++;
+}
+
+/* Wrap a region: PROF_ENTER(PROF_20KHZ); ...work...; PROF_EXIT(PROF_20KHZ); */
+#define PROF_ENTER(i) uint16_t _pt_##i = prof_enter()
+#define PROF_EXIT(i)  prof_exit((i), _pt_##i)
+
+#else /* !PROFILE_ISR */
+#define profiling_init() ((void)0)
+#define PROF_ENTER(i) ((void)0)
+#define PROF_EXIT(i)  ((void)0)
+#endif
+
+#endif /* PROFILING_H_ */

Mcu/f051/Src/peripherals.c

@@ -12,6 +12,7 @@
 #include "ADC.h"
 #include "serial_telemetry.h"
 #include "targets.h"
+#include "profiling.h"
 
 void initCorePeripherals(void)
 {
@@ -28,6 +29,7 @@ void initCorePeripherals(void)
     MX_TIM6_Init();
     MX_TIM17_Init();
     UN_TIM_Init();
+    profiling_init(); // no-op unless PROFILE_ISR is defined
 #ifdef USE_SERIAL_TELEMETRY
     telem_UART_Init();
 #endif

Mcu/f051/Src/stm32f0xx_it.c

@@ -27,6 +27,7 @@
 #include "ADC.h"
 #include "targets.h"
 #include "common.h"
+#include "profiling.h"
 
 extern void transfercomplete();
 extern void PeriodElapsedCallback();
@@ -44,6 +45,31 @@ extern volatile char armed;
 extern volatile char out_put;
 /* USER CODE END EV */
 
+#ifdef PROFILE_ISR
+volatile uint16_t prof_cyc_last[PROF_N];
+volatile uint16_t prof_cyc_max[PROF_N];
+volatile uint32_t prof_cyc_sum[PROF_N];
+volatile uint32_t prof_calls[PROF_N];
+
+// Repurpose TIM17 (unused on the F051: MX_TIM17_Init never enables its counter
+// and nothing reads it) as a 48 MHz free-running cycle counter, and configure
+// the optional logic-analyzer marker pin.
+void profiling_init(void)
+{
+    LL_APB1_GRP2_EnableClock(LL_APB1_GRP2_PERIPH_TIM17);
+    TIM17->PSC = 0;            // 48 MHz -> 1 tick per core cycle
+    TIM17->ARR = 0xFFFF;
+    TIM17->EGR = TIM_EGR_UG;   // latch the prescaler
+    TIM17->CR1 |= TIM_CR1_CEN; // free-running
+#ifdef PROFILE_GPIO_PORT
+    LL_GPIO_SetPinMode(PROFILE_GPIO_PORT, PROFILE_GPIO_PIN, LL_GPIO_MODE_OUTPUT);
+    LL_GPIO_SetPinOutputType(PROFILE_GPIO_PORT, PROFILE_GPIO_PIN, LL_GPIO_OUTPUT_PUSHPULL);
+    LL_GPIO_SetPinSpeed(PROFILE_GPIO_PORT, PROFILE_GPIO_PIN, LL_GPIO_SPEED_FREQ_HIGH);
+    PROFILE_GPIO_PORT->BRR = PROFILE_GPIO_PIN;
+#endif
+}
+#endif
+
 uint16_t interrupt_time = 0;
 /******************************************************************************/
 /*           Cortex-M0 Processor Interruption and Exception Handlers */
@@ -194,8 +220,10 @@ void ADC1_COMP_IRQHandler(void)
   if (LL_EXTI_IsActiveFlag_0_31(LL_EXTI_LINE_21) != RESET) {
       if((INTERVAL_TIMER->CNT) > ((average_interval>>1))){
        EXTI->PR = EXTI_LINE;
+      PROF_ENTER(PROF_COMP_ZC);
       interruptRoutine();
-  }else{ 
+      PROF_EXIT(PROF_COMP_ZC);
+  }else{
       if (getCompOutputLevel() == rising){
       EXTI->PR = EXTI_LINE;
   }
@@ -210,7 +238,9 @@ void TIM6_DAC_IRQHandler(void)
 {
     if (LL_TIM_IsActiveFlag_UPDATE(TIM6) == 1) {
         LL_TIM_ClearFlag_UPDATE(TIM6);
+        PROF_ENTER(PROF_20KHZ);
         tenKhzRoutine();
+        PROF_EXIT(PROF_20KHZ);
     }
 }
 
@@ -220,7 +250,9 @@ void TIM6_DAC_IRQHandler(void)
 void TIM14_IRQHandler(void)
 {
     LL_TIM_ClearFlag_UPDATE(TIM14);
+    PROF_ENTER(PROF_TIM14);
     PeriodElapsedCallback();
+    PROF_EXIT(PROF_TIM14);
 }
 
 /**
@@ -310,7 +342,9 @@ void TIM1_BRK_UP_TRG_COM_IRQHandler(void)
 void EXTI4_15_IRQHandler(void)
 {
     LL_EXTI_ClearFlag_0_31(LL_EXTI_LINE_15);
+    PROF_ENTER(PROF_DSHOT);
     processDshot();
+    PROF_EXIT(PROF_DSHOT);
 }
 
 /* USER CODE END 1 */

scripts/profile_swd.py

@@ -0,0 +1,152 @@
+#!/usr/bin/env python3
+"""
+profile_swd.py - live readout of the PROFILE_ISR counters over SWD.
+
+The F051 (Cortex-M0) has no DWT/SWO, so the profiling harness (Inc/profiling.h)
+times each hot ISR with TIM17 as a 48 MHz cycle counter and accumulates the
+results into RAM globals. This script reads those globals through a running
+OpenOCD over its Tcl RPC port and turns them into per-ISR CPU load, average and
+worst-case microseconds, and call rate.
+
+Reads go through the debug access port and do NOT halt the core, so it is safe
+to run while the motor is spinning (no commutation glitch, no watchdog reset).
+
+Usage:
+    1. Build with PROFILE_ISR enabled and flash the board.
+    2. Start OpenOCD (its Tcl port 6666 is on by default):
+         openocd -f Mcu/f051/openocd.cfg
+       (or just leave your VS Code / Cortex-Debug session running)
+    3. Run this against the matching ELF:
+         scripts/profile_swd.py obj/AM32_ARK_4IN1_F051_2.20.elf
+
+Options:
+    --host/--port   OpenOCD Tcl RPC endpoint (default 127.0.0.1:6666)
+    --interval      seconds between samples (default 1.0)
+    --cpu-mhz       core clock for cycle->time conversion (default 48)
+    --nm            path to nm (default arm-none-eabi-nm)
+
+Requires OpenOCD >= 0.11 (for the `read_memory` command).
+"""
+import argparse
+import re
+import socket
+import subprocess
+import sys
+import time
+
+# enum order in Inc/profiling.h
+LABELS = ["comp_zc(ADC1_COMP)", "20khz(TIM6)", "dshot(EXTI4_15)", "tim14"]
+U32 = 0xFFFFFFFF
+
+
+class OpenOcdTcl:
+    """Minimal OpenOCD Tcl RPC client (commands terminated by 0x1a)."""
+    SEP = b"\x1a"
+
+    def __init__(self, host, port):
+        self.sock = socket.create_connection((host, port), timeout=5)
+
+    def cmd(self, command):
+        self.sock.sendall(command.encode() + self.SEP)
+        buf = bytearray()
+        while not buf.endswith(self.SEP):
+            chunk = self.sock.recv(4096)
+            if not chunk:
+                raise ConnectionError("OpenOCD closed the connection")
+            buf.extend(chunk)
+        return buf[:-1].decode(errors="replace")
+
+    def read_words(self, addr, width, count):
+        # read_memory returns a space-separated list of decimal values
+        out = self.cmd(f"read_memory 0x{addr:08x} {width} {count}")
+        return [int(tok, 0) for tok in out.split()]
+
+    def close(self):
+        try:
+            self.sock.close()
+        except OSError:
+            pass
+
+
+def resolve_symbols(nm, elf, names):
+    """Return {name: (addr, size_bytes)} via `nm -S`."""
+    try:
+        out = subprocess.check_output([nm, "-S", "--radix=d", elf], text=True)
+    except (OSError, subprocess.CalledProcessError) as e:
+        sys.exit(f"failed to run {nm} on {elf}: {e}")
+    syms = {}
+    for line in out.splitlines():
+        # "<addr> <size> <type> <name>"
+        m = re.match(r"(\d+)\s+(\d+)\s+\S\s+(\S+)", line)
+        if m and m.group(3) in names:
+            syms[m.group(3)] = (int(m.group(1)), int(m.group(2)))
+    missing = [n for n in names if n not in syms]
+    if missing:
+        sys.exit(f"symbols not found in {elf} (build with PROFILE_ISR?): {missing}")
+    return syms
+
+
+def main():
+    ap = argparse.ArgumentParser(description="Live SWD readout of PROFILE_ISR counters.")
+    ap.add_argument("elf", help="ELF built with PROFILE_ISR")
+    ap.add_argument("--host", default="127.0.0.1")
+    ap.add_argument("--port", type=int, default=6666)
+    ap.add_argument("--interval", type=float, default=1.0)
+    ap.add_argument("--cpu-mhz", type=float, default=48.0)
+    ap.add_argument("--nm", default="arm-none-eabi-nm")
+    args = ap.parse_args()
+
+    cyc_per_us = args.cpu_mhz
+    cpu_hz = args.cpu_mhz * 1e6
+
+    syms = resolve_symbols(args.nm, args.elf, ["prof_cyc_max", "prof_cyc_sum", "prof_calls"])
+    count = syms["prof_calls"][1] // 4 or len(LABELS)
+    labels = (LABELS + [f"isr{i}" for i in range(len(LABELS), count)])[:count]
+
+    try:
+        ocd = OpenOcdTcl(args.host, args.port)
+    except OSError as e:
+        sys.exit(f"cannot reach OpenOCD Tcl port {args.host}:{args.port} ({e}); "
+                 f"is OpenOCD running with `-f Mcu/f051/openocd.cfg`?")
+
+    def sample():
+        return (
+            ocd.read_words(syms["prof_cyc_sum"][0], 32, count),
+            ocd.read_words(syms["prof_calls"][0], 32, count),
+            ocd.read_words(syms["prof_cyc_max"][0], 16, count),
+        )
+
+    print(f"# reading {count} ISR counters @ {args.cpu_mhz:g} MHz, every {args.interval:g}s "
+          f"(Ctrl-C to stop)")
+    prev_sum, prev_calls, _ = sample()
+    prev_t = time.monotonic()
+    try:
+        while True:
+            time.sleep(args.interval)
+            cur_sum, cur_calls, cur_max = sample()
+            now = time.monotonic()
+            dt = now - prev_t
+
+            print(f"\n=== dt={dt:.2f}s ===")
+            print(f"{'ISR':22}{'rate(Hz)':>10}{'avg(us)':>9}{'max(us)':>9}{'CPU%':>8}")
+            total = 0.0
+            for i in range(count):
+                dcalls = (cur_calls[i] - prev_calls[i]) & U32
+                dsum = (cur_sum[i] - prev_sum[i]) & U32
+                rate = dcalls / dt
+                load = 100.0 * dsum / (dt * cpu_hz)
+                avg_us = (dsum / dcalls) / cyc_per_us if dcalls else 0.0
+                max_us = cur_max[i] / cyc_per_us
+                total += load
+                print(f"{labels[i]:22}{rate:10.0f}{avg_us:9.2f}{max_us:9.2f}{load:8.1f}")
+            print(f"{'TOTAL (instrumented)':22}{'':>10}{'':>9}{'':>9}{total:8.1f}")
+
+            prev_sum, prev_calls, prev_t = cur_sum, cur_calls, now
+    except KeyboardInterrupt:
+        print("\nstopped")
+    finally:
+        ocd.close()
+
+
+if __name__ == "__main__":
+    main()