From 416a6d9c5fad34b8cebbd1f5e0a2d71b348a5ba3 Mon Sep 17 00:00:00 2001 From: Synte Peng Date: Sat, 25 Jul 2026 02:20:51 +0800 Subject: [PATCH 1/5] Add CONFIG_DEBUG_TRACE and build rules Add CONFIG_DEBUG_TRACE (default off), DEBUG_EVENT_BUFFER_SIZE (256), and DEBUG_EVENT_STRUCT_SIZE (16) to config.h. Wire debug_trace.o into KERNEL_OBJS in Makefile. --- Makefile | 2 +- config.h | 22 ++++++++++++++++++++++ 2 files changed, 23 insertions(+), 1 deletion(-) diff --git a/Makefile b/Makefile index 447c26b7..03713270 100644 --- a/Makefile +++ b/Makefile @@ -29,7 +29,7 @@ include arch/$(ARCH)/build.mk INC_DIRS += -I $(SRC_DIR)/include \ -I $(SRC_DIR)/include/lib -KERNEL_OBJS := timer.o mqueue.o pipe.o semaphore.o mutex.o logger.o error.o syscall.o task.o memprot.o main.o +KERNEL_OBJS := timer.o mqueue.o pipe.o semaphore.o mutex.o logger.o error.o syscall.o task.o memprot.o debug_trace.o main.o KERNEL_OBJS := $(addprefix $(BUILD_KERNEL_DIR)/,$(KERNEL_OBJS)) deps += $(KERNEL_OBJS:%.o=%.o.d) diff --git a/config.h b/config.h index 24547a3b..d7da9a9b 100644 --- a/config.h +++ b/config.h @@ -4,3 +4,25 @@ #ifndef CONFIG_STACK_PROTECTION #define CONFIG_STACK_PROTECTION 1 /* Default: enabled for safety */ #endif + +/* Kernel event tracing configuration */ +#ifndef CONFIG_DEBUG_TRACE +#define CONFIG_DEBUG_TRACE 0 /* default: disabled */ +#endif + +/* + * Ring buffer slot count — power of 2 recommended for O(1) bitmask + * index calc instead of modulo. + */ +#ifndef DEBUG_EVENT_BUFFER_SIZE +#define DEBUG_EVENT_BUFFER_SIZE 256 +#endif + +/* + * Per-event slot stride in bytes — defines the fixed-size slot that + * every event occupies in the ring buffer. Must be a multiple of 4 + * (sizeof(uint32_t)). Power of 2 recommended. + */ +#ifndef DEBUG_EVENT_STRUCT_SIZE +#define DEBUG_EVENT_STRUCT_SIZE 16 +#endif From f102df0f7725178ee8f3d3ed225630166e007500 Mon Sep 17 00:00:00 2001 From: Synte Peng Date: Sat, 25 Jul 2026 02:21:13 +0800 Subject: [PATCH 2/5] Add kernel event tracing subsystem X-macro ring-buffer tracer for lightweight kernel instrumentation. Architecture: - trace_events.h: single-source-of-truth event definitions, included 5 times with varying preprocessor state to generate enums, structs, inline writers, print functions, and a dispatch table. - debug_trace.h: the 5-pass X-macro engine, per-event typed always_inline write functions, and public API with compile-out stubs for CONFIG_DEBUG_TRACE=0. - debug_trace.c: fixed-stride ring buffer with dump/clear/count/ overwrites/get operations. Two interrupt-protection protocols: - SAFE: gates the buffer write with csrrci/csrsi to disable/restore interrupts. For call sites that do not already hold interrupt protection (e.g. NOSCHED sections). - RAW: skips gating. For call sites already executing inside interrupt-disabled sections (e.g. dispatch, CRITICAL_ENTER, or ISR context). Write cost is minimized: class structs use a union projection so only populated fields are stored; unused fields carry stale data from prior slots without per-event zeroing. When CONFIG_DEBUG_TRACE=0, all tracepoints compile to nothing. --- include/sys/debug_trace.h | 268 +++++++++++++++++++++++++++++++++++++ include/sys/trace_events.h | 201 ++++++++++++++++++++++++++++ kernel/debug_trace.c | 216 ++++++++++++++++++++++++++++++ 3 files changed, 685 insertions(+) create mode 100644 include/sys/debug_trace.h create mode 100644 include/sys/trace_events.h create mode 100644 kernel/debug_trace.c diff --git a/include/sys/debug_trace.h b/include/sys/debug_trace.h new file mode 100644 index 00000000..48eee28f --- /dev/null +++ b/include/sys/debug_trace.h @@ -0,0 +1,268 @@ +#pragma once + +#include + +/* + * Tracing system — 5-pass X-macro architecture + * + * trace_events.h is #include'd five times with different macro + * definitions to generate: + * + * Pass 1 -> debug_event_type_t enum + * Pass 2 -> event-class struct definitions + * Pass 3 -> always_inline write functions (_tr_do_EVENT_##name) + * Pass 4 -> per-event print functions (debug_trace.c) + * Pass 5 -> print-function pointer table (debug_trace.c) + * + * Users define events in trace_events.h using: + * + * DEFINE_EVENT_CLASS(name, __field(type, fieldname) ...) + * DEFINE_EVENT(name, class, prot, proto, pairs...) + * + * Pairs: _NO(field) skip, _SET(field,expr) store, TR_TID task id + */ + +#if CONFIG_DEBUG_TRACE + +/* ═══════════════════════════════════════════════════════════════════ * + * Pass 1: enum + * ═══════════════════════════════════════════════════════════════════ */ + +#define DEFINE_EVENT_CLASS(...) /* nothing */ +#define __field(...) /* nothing */ +#define DEFINE_EVENT(name, ...) EVENT_##name, + +typedef enum { +#include + EVENT_TYPE_MAX +} debug_event_type_t; + +#undef DEFINE_EVENT_CLASS +#undef __field +#undef DEFINE_EVENT + +/* + * Reader-side event struct — used by debug_trace_get(). + * Each class has its own packed layout (DEBUG_EVENT_STRUCT_SIZE + * bytes); this struct provides a common projection for reading. + */ +typedef struct { + uint8_t event_type; + uint8_t reserved; + uint16_t task_id; + uint32_t timestamp; + uint32_t param1; + uint32_t param2; +} debug_event_t; +STATIC_ASSERT(sizeof(debug_event_t) == DEBUG_EVENT_STRUCT_SIZE, + "debug_event_t size mismatch"); + +#include +#include + +#define DEBUG_TRACE_EVENT_WORDS ((DEBUG_EVENT_STRUCT_SIZE) / sizeof(uint32_t)) +STATIC_ASSERT((DEBUG_EVENT_STRUCT_SIZE) % 4 == 0, + "DEBUG_EVENT_STRUCT_SIZE must be a multiple of 4"); + +extern uint32_t debug_trace_buffer[DEBUG_EVENT_BUFFER_SIZE * DEBUG_TRACE_EVENT_WORDS]; +extern volatile uint32_t debug_trace_total; + +#if (DEBUG_EVENT_BUFFER_SIZE & (DEBUG_EVENT_BUFFER_SIZE - 1)) == 0 +#define DEBUG_TRACE_BUFFER_INDEX(sequence) \ + ((uint32_t) (sequence) & (DEBUG_EVENT_BUFFER_SIZE - 1U)) +#else +#define DEBUG_TRACE_BUFFER_INDEX(sequence) \ + ((uint32_t) (sequence) % DEBUG_EVENT_BUFFER_SIZE) +#endif + +#define DEBUG_TRACE_CURRENT_TASK_ID() \ + (likely(kcb && kcb->task_current && kcb->task_current->data) \ + ? ((tcb_t *) kcb->task_current->data)->id \ + : 0U) + + +/* ═══════════════════════════════════════════════════════════════════ * + * Pass 2: class struct definitions + * + * STATIC_ASSERT catches wrong field ordering at compile time: + * if fields are not declared in descending-size order (u32→u16→u8) + * the compiler inserts padding → struct exceeds size → compile error. + * aligned(4) ensures native lw/lh/lb access without packed overhead. + * ═══════════════════════════════════════════════════════════════════ */ + +#define DEFINE_EVENT(...) /* nothing */ +#define __field(type, name_) type name_; + +#define DEFINE_EVENT_CLASS(name, ...) \ + struct debug_event_cls_##name { \ + uint8_t event_type; \ + uint8_t reserved; \ + uint16_t task_id; \ + uint32_t timestamp; \ + union { \ + struct { __VA_ARGS__ }; \ + struct { uint32_t _param1; uint32_t _param2; }; \ + }; \ + } __attribute__((aligned(4))); \ + STATIC_ASSERT(sizeof(struct debug_event_cls_##name) == DEBUG_EVENT_STRUCT_SIZE, \ + "event class size mismatch"); + +#include + +#undef DEFINE_EVENT +#undef __field +#undef DEFINE_EVENT_CLASS + +/* ═══════════════════════════════════════════════════════════════════ * + * Interrupt protection helpers + * ═══════════════════════════════════════════════════════════════════ */ + +/* csrrci/csrsi replace hal_interrupt_set — 1 CSR insn + * per direction instead of 3. Saves ~4-5 cycles per SAFE event. */ +#define TR_SAFE_ENTER() \ + uint32_t _tr_s; \ + asm volatile("csrrci %0, mstatus, 8" : "=r"(_tr_s) : : "memory") +#define TR_SAFE_LEAVE() \ + do { \ + if ((_tr_s) & 8) \ + asm volatile("csrsi mstatus, 8" ::: "memory"); \ + } while (0) +#define TR_RAW_ENTER() do {} while (0) +#define TR_RAW_LEAVE() do {} while (0) + +/* ═══════════════════════════════════════════════════════════════════ * + * Pair processing — up to 11 pairs per event + * + * Each pair is a single macro invocation: + * _NO(field) -> skip store + * _SET(field, expr) -> _ev->field = (expr) + * TR_TID -> store current task id (always at _ev->task_id) + * + * _TR_UNPACK_PAIR uses paste to dispatch on the pair token + * (_TR_PROCP_##_NO etc.) so arbitrary _SET expressions work. + * + * Pad‑to‑11 sentinels ensure any event works without counting. + * Extra arguments beyond 11 are silently discarded via the trailing `, ...`. + * ═══════════════════════════════════════════════════════════════════ */ + +#define _TR_SKIP_PAIR _NO(_TR_SKP) + +#define _TR_FOR_EACH_PAIR(...) \ + _TR_FOR_EACH_11(__VA_ARGS__, \ + _TR_SKIP_PAIR, _TR_SKIP_PAIR, _TR_SKIP_PAIR, \ + _TR_SKIP_PAIR, _TR_SKIP_PAIR, _TR_SKIP_PAIR, \ + _TR_SKIP_PAIR, _TR_SKIP_PAIR, _TR_SKIP_PAIR, \ + _TR_SKIP_PAIR, _TR_SKIP_PAIR) + +/* + * With DEBUG_EVENT_STRUCT_SIZE = 16 bytes (4 words): + * 8 B framework fields (event_type, reserved, task_id, timestamp) + * 8 B remaining for user __field entries + * + * The 8 remaining bytes can hold up to 8 __field entries + * (e.g. eight uint8_t). A DEFINE_EVENT invocation then has at most: + * 8 _SET for the __field entries + * 1 _SET for the reserved byte (framework, optional store) + * 1 TR_TID (or _SET(task_id, ...)) (per-event store) + * 1 _PRINT (per-event print format) + * --------- + * 11 pairs total + * + * Extra arguments beyond 11 are silently discarded + * via the trailing `, ...`. + * + * If DEBUG_EVENT_STRUCT_SIZE grows (e.g. to 8 words), + * expand _TR_FOR_EACH_11 to a larger variant. + */ +#define _TR_FOR_EACH_11(p1, p2, p3, p4, p5, p6, p7, p8, p9, p10, p11, ...) \ + _TR_UNPACK_PAIR(p1) _TR_UNPACK_PAIR(p2) _TR_UNPACK_PAIR(p3) \ + _TR_UNPACK_PAIR(p4) _TR_UNPACK_PAIR(p5) _TR_UNPACK_PAIR(p6) \ + _TR_UNPACK_PAIR(p7) _TR_UNPACK_PAIR(p8) _TR_UNPACK_PAIR(p9) \ + _TR_UNPACK_PAIR(p10) _TR_UNPACK_PAIR(p11) + +/* _TR_UNPACK_PAIR(_NO(field)) -> _TR_PROCP_##_NO -> _TR_PROCP__NO(field) */ +#define _TR_UNPACK_PAIR(pair) _TR_PROCP_##pair + +#define _TR_PROCP__NO(f) /* skip */ +#define _TR_PROCP__SET(f, e) _ev->f = (e); +#define _TR_PROCP_TR_TID _ev->task_id = (uint16_t)DEBUG_TRACE_CURRENT_TASK_ID(); +#define _TR_PROCP__PRINT(...) /* ignored in write pass */ + +/* ═══════════════════════════════════════════════════════════════════ * + * Pass 3: per-event static inline write functions + * + * One function per event, always_inline. The proto argument + * provides the typed parameter list so callers pass arguments + * directly — no positional extraction needed. + * ═══════════════════════════════════════════════════════════════════ */ + +#define DEFINE_EVENT_CLASS(...) /* nothing */ +#define __field(...) /* nothing */ + +#define DEFINE_EVENT(name, cls, prot, proto, ...) \ + __attribute__((always_inline)) static inline void \ + _tr_do_EVENT_##name proto \ + { \ + struct debug_event_cls_##cls *_ev; \ + uint32_t _total, _idx; \ + TR_##prot##_ENTER(); \ + _total = debug_trace_total; \ + _idx = DEBUG_TRACE_BUFFER_INDEX(_total); \ + _ev = (void *)&debug_trace_buffer[_idx * DEBUG_TRACE_EVENT_WORDS]; \ + _ev->event_type = (uint8_t)(EVENT_##name); \ + _TR_FOR_EACH_PAIR(__VA_ARGS__) \ + _ev->timestamp = (uint32_t)(likely(kcb) \ + ? kcb->ticks : 0U); \ + debug_trace_total = _total + 1; \ + TR_##prot##_LEAVE(); \ + } + +#include + +#undef DEFINE_EVENT +#undef __field +#undef DEFINE_EVENT_CLASS + +/* ═══════════════════════════════════════════════════════════════════ * + * Public API macro + * + * DEBUG_TRACE_EVENT(EVENT_xxx, args...) + * + * Args are forwarded directly — the per‑event function signature + * provides compile‑time type checking. + * ═══════════════════════════════════════════════════════════════════ */ + +#define DEBUG_TRACE_EVENT(ev, ...) \ + _tr_do_##ev(__VA_ARGS__) + + +void debug_dump_events(void); +void debug_clear_events(void); +uint32_t debug_trace_count(void); +uint32_t debug_trace_overwrites(void); +int32_t debug_trace_get(uint32_t index, debug_event_t *event); + +#else /* !CONFIG_DEBUG_TRACE */ + +#define DEBUG_TRACE_EVENT(...) do {} while (0) + +static inline void debug_dump_events(void) {} + +static inline void debug_clear_events(void) {} + +static inline uint32_t debug_trace_count(void) +{ + return 0U; +} + +static inline uint32_t debug_trace_overwrites(void) +{ + return 0U; +} + +static inline int32_t debug_trace_get(uint32_t index, void *event) +{ + return 0U; +} + +#endif /* CONFIG_DEBUG_TRACE */ diff --git a/include/sys/trace_events.h b/include/sys/trace_events.h new file mode 100644 index 00000000..f683fd06 --- /dev/null +++ b/include/sys/trace_events.h @@ -0,0 +1,201 @@ +/* + * Event definitions — single source of truth for the tracing system. + * + * This file is #include'd *multiple times* by debug_trace.h with + * different preprocessor state. Do NOT add #pragma once. + * + * ── Fixed-size slot layout (configurable via DEBUG_EVENT_STRUCT_SIZE) ── + * + * 0 event_type uint8_t framework (written by framework) + * 1 reserved uint8_t user (_SET / _NO, optional) + * 2-3 task_id uint16_t TR_TID (always at this offset) + * 4-7 timestamp uint32_t framework (written by framework) + * 8+ __field user max (size - 8) bytes — _Static_assert guarded + * + * task_id (offsets 2-3) is always a uint16_t. TR_TID is a + * parameterless pair that stores DEBUG_TRACE_CURRENT_TASK_ID() + * into _ev->task_id at the fixed offset. + * + * ── Event classes ── + * + * DEFINE_EVENT_CLASS(classname, + * __field(type, fieldname) + * ... + * ) + * + * Defines an aligned struct fitting within DEBUG_EVENT_STRUCT_SIZE + * bytes, with implicit event_type (uint8_t), reserved (uint8_t), + * task_id (uint16_t), and timestamp (uint32_t). + * + * ── Events ── + * + * DEFINE_EVENT(name, class, prot, proto, + * pairs... + * ) + * + * name — EVENT_##name enum value + * class — event class defined above (generates struct debug_event_cls_##class) + * prot — SAFE or RAW (interrupt handling around the write) + * proto — param list for the generated always_inline write function, + * e.g. (uint32_t p1, uint32_t p2) or (void) + * + * Pairs: + * _NO(field) — skip this field + * _SET(field, expr) — store _ev->field = (expr) + * TR_TID — store task_id at fixed offset (2-3) + * _PRINT(fmt_and_args...) — printf format, raw paste (use _e->field) + */ + +/* ══════════════════════════════════════════════════════════════════════ * + * Event classes + * ══════════════════════════════════════════════════════════════════════ */ + +DEFINE_EVENT_CLASS(task_cls, + __field(uint32_t, param1) + __field(uint32_t, param2) +) + +DEFINE_EVENT_CLASS(pipe_cls, + __field(uint32_t, len) + __field(uint32_t, addr) +) + +DEFINE_EVENT_CLASS(mqueue_cls, + __field(uint32_t, len) + __field(uint32_t, data) +) + +DEFINE_EVENT_CLASS(sem_cls, + __field(uint32_t, sem_id) +) + +DEFINE_EVENT_CLASS(mutex_cls, + __field(uint32_t, mutex_id) +) + +DEFINE_EVENT_CLASS(isr_cls, + __field(uint8_t, isr_num) +) + +/* ══════════════════════════════════════════════════════════════════════ * + * Events + * ══════════════════════════════════════════════════════════════════════ */ + +/* ── task events ── */ + +DEFINE_EVENT(TASK_CREATE, task_cls, SAFE, (uint32_t p1, uint32_t p2), + TR_TID, + _SET(param1, p1), + _SET(param2, p2), + _PRINT(" creator=%u tid=%u prio=%u", _e->task_id, _e->param1, _e->param2) +) +DEFINE_EVENT(TASK_DESTROY, task_cls, RAW, (uint32_t p1, uint32_t p2), + TR_TID, + _SET(param1, p1), + _SET(param2, p2), + _PRINT(" destroyer=%u tid=%u prev=%u", _e->task_id, _e->param1, _e->param2) +) +DEFINE_EVENT(TASK_SWITCH, task_cls, RAW, (uint32_t p1, uint32_t p2), + _NO(task_id), + _SET(param1, p1), + _SET(param2, p2), + _PRINT(" prev=%u next=%u", _e->param1, _e->param2) +) +DEFINE_EVENT(TASK_DELAY, task_cls, SAFE, (uint32_t p1, uint16_t p2), + _SET(task_id, p2), + _SET(param1, p1), + _NO(param2), + _PRINT(" tid=%u ticks=%u", _e->task_id, _e->param1) +) +DEFINE_EVENT(TASK_SUSPEND, task_cls, RAW, (uint32_t id), + TR_TID, + _SET(param1, id), + _NO(param2), + _PRINT(" tid=%u id=%u", _e->task_id, _e->param1) +) +DEFINE_EVENT(TASK_RESUME, task_cls, RAW, (uint32_t id), + TR_TID, + _SET(param1, id), + _NO(param2), + _PRINT(" tid=%u id=%u", _e->task_id, _e->param1) +) +DEFINE_EVENT(TASK_YIELD, task_cls, SAFE, (void), + TR_TID, + _NO(param1), + _NO(param2), + _PRINT(" tid=%u", _e->task_id) +) +DEFINE_EVENT(EXCEPTION, task_cls, SAFE, (uint32_t p1, uint32_t p2), + _NO(task_id), + _SET(param1, p1), + _SET(param2, p2), + _PRINT(" p1=%u p2=%u", _e->param1, _e->param2) +) + +/* ── pipe events ── */ + +DEFINE_EVENT(PIPE_READ, pipe_cls, SAFE, (uint32_t len, uint32_t addr), + TR_TID, + _SET(len, len), + _SET(addr, addr), + _PRINT(" tid=%u len=%u addr=0x%x", _e->task_id, _e->len, _e->addr) +) +DEFINE_EVENT(PIPE_WRITE, pipe_cls, SAFE, (uint32_t len, uint32_t addr), + TR_TID, + _SET(len, len), + _SET(addr, addr), + _PRINT(" tid=%u len=%u addr=0x%x", _e->task_id, _e->len, _e->addr) +) + +/* ── mqueue events ── */ + +DEFINE_EVENT(MQUEUE_SEND, mqueue_cls, SAFE, (uint32_t len, uint32_t data), + TR_TID, + _SET(len, len), + _SET(data, data), + _PRINT(" tid=%u len=%u data=%u", _e->task_id, _e->len, _e->data) +) +DEFINE_EVENT(MQUEUE_RECV, mqueue_cls, SAFE, (uint32_t len, uint32_t data), + TR_TID, + _SET(len, len), + _SET(data, data), + _PRINT(" tid=%u len=%u data=%u", _e->task_id, _e->len, _e->data) +) + +/* ── semaphore events ── */ + +DEFINE_EVENT(SEM_WAIT, sem_cls, SAFE, (uint32_t sem_id), + TR_TID, + _SET(sem_id, sem_id), + _PRINT(" tid=%u sem=%u", _e->task_id, _e->sem_id) +) +DEFINE_EVENT(SEM_POST, sem_cls, SAFE, (uint32_t sem_id), + TR_TID, + _SET(sem_id, sem_id), + _PRINT(" tid=%u sem=%u", _e->task_id, _e->sem_id) +) + +/* ── mutex events ── */ + +DEFINE_EVENT(MUTEX_LOCK, mutex_cls, SAFE, (uint32_t mutex_id), + TR_TID, + _SET(mutex_id, mutex_id), + _PRINT(" tid=%u mtx=%u", _e->task_id, _e->mutex_id) +) +DEFINE_EVENT(MUTEX_UNLOCK, mutex_cls, SAFE, (uint32_t mutex_id), + TR_TID, + _SET(mutex_id, mutex_id), + _PRINT(" tid=%u mtx=%u", _e->task_id, _e->mutex_id) +) + +/* ── ISR events ── */ + +DEFINE_EVENT(ISR_ENTER, isr_cls, RAW, (uint8_t num), + _SET(isr_num, num), + _PRINT(" isr=%u", _e->isr_num) +) +DEFINE_EVENT(ISR_EXIT, isr_cls, RAW, (uint8_t num), + _SET(isr_num, num), + _PRINT(" isr=%u", _e->isr_num) +) + diff --git a/kernel/debug_trace.c b/kernel/debug_trace.c new file mode 100644 index 00000000..e0d10330 --- /dev/null +++ b/kernel/debug_trace.c @@ -0,0 +1,216 @@ +#include +#include +#include + +#if CONFIG_DEBUG_TRACE + +/* + * Fixed‑stride trace buffer — every event occupies exactly + * DEBUG_TRACE_EVENT_WORDS words (DEBUG_EVENT_STRUCT_SIZE bytes) + * + * The per‑type macros (debug_trace.h) write only the fields that + * actually carry data; unused param slots are left uninitialized. + * + * debug_trace_total is a monotonic event counter. The buffer holds + * the last DEBUG_EVENT_BUFFER_SIZE events in circular fashion. + */ +uint32_t debug_trace_buffer[DEBUG_EVENT_BUFFER_SIZE * DEBUG_TRACE_EVENT_WORDS]; +volatile uint32_t debug_trace_total; + +/* ------------------------------------------------------------------ * + * Internal helpers + * ------------------------------------------------------------------ */ + +static uint32_t retained_count_locked(void) +{ + if (debug_trace_total < DEBUG_EVENT_BUFFER_SIZE) + return debug_trace_total; + return DEBUG_EVENT_BUFFER_SIZE; +} + +static uint32_t overwrite_count_locked(void) +{ + if (debug_trace_total > DEBUG_EVENT_BUFFER_SIZE) + return debug_trace_total - DEBUG_EVENT_BUFFER_SIZE; + return 0U; +} + +/* + * Map a retained-event index (0 = oldest) to its absolute sequence + * number, or return false when the index is out of range. + */ +static bool retained_sequence(uint32_t index, uint32_t *seq_out) +{ + uint32_t retained = retained_count_locked(); + + if (index >= retained) + return false; + + uint32_t first_seq = + (debug_trace_total > DEBUG_EVENT_BUFFER_SIZE) + ? debug_trace_total - DEBUG_EVENT_BUFFER_SIZE + : 0U; + + *seq_out = first_seq + index; + return true; +} +/* ================================================================== * + * Pass 4: per-event print functions + * + * Generated from trace_events.h with print-context _TR_PROCP_ + * definitions. _SET / TR_TID / _NO pair actions are no-ops here; + * only _PRINT emits output. + * ================================================================== */ + +#undef _TR_PROCP__NO +#undef _TR_PROCP__SET +#undef _TR_PROCP_TR_TID +#undef _TR_PROCP__PRINT + +#define _TR_PROCP__NO(...) /* */ +#define _TR_PROCP__SET(...) /* */ +#define _TR_PROCP_TR_TID /* */ +#define _TR_PROCP__PRINT(...) int _tr_has_print; printf(__VA_ARGS__); + +#define DEFINE_EVENT_CLASS(...) /* nothing */ +#define __field(...) /* nothing */ + +#define DEFINE_EVENT(name, cls, prot, proto, ...) \ + static void _tr_print_EVENT_##name(uint32_t idx, uint32_t base) { \ + const struct debug_event_cls_##cls *_e = \ + (const void *)&debug_trace_buffer[base]; \ + printf("[%u] %14s ts=%u", idx, #name, _e->timestamp); \ + _TR_FOR_EACH_PAIR(__VA_ARGS__) \ + (void)_tr_has_print; \ + printf("\n"); \ + } + +#include + +#undef DEFINE_EVENT + +/* ================================================================== * + * Pass 5: print-function pointer table + * + * Indexed by EVENT_##name, maps each event type to its + * _tr_print_EVENT_##name handler. + * ================================================================== */ + +static void (*const _tr_print_fn[EVENT_TYPE_MAX])(uint32_t, uint32_t) = { +#define DEFINE_EVENT_CLASS(...) /* nothing */ +#define __field(...) /* nothing */ +#define DEFINE_EVENT(name, ...) [EVENT_##name] = _tr_print_EVENT_##name, +#include +}; + +#undef DEFINE_EVENT +#undef __field +#undef DEFINE_EVENT_CLASS + +static void _tr_print_event(uint32_t idx, uint32_t base) +{ + uint8_t ev = debug_trace_buffer[base] & 0xFFU; + + if (ev < EVENT_TYPE_MAX && _tr_print_fn[ev]) + _tr_print_fn[ev](idx, base); + else + printf("[%u] UNKNOWN\n", idx); +} + +/* ------------------------------------------------------------------ * + * Public API + * ------------------------------------------------------------------ */ + +void debug_dump_events(void) +{ + uint32_t count; + uint32_t overwrites; + uint32_t first_seq; + CRITICAL_ENTER(); + + count = retained_count_locked(); + overwrites = overwrite_count_locked(); + first_seq = (debug_trace_total > DEBUG_EVENT_BUFFER_SIZE) + ? debug_trace_total - DEBUG_EVENT_BUFFER_SIZE + : 0U; + + printf("debug trace: %u retained event%s, %u overwrite%s\n", count, + (count == 1U) ? "" : "s", overwrites, + (overwrites == 1U) ? "" : "s"); + + for (uint32_t i = 0U; i < count; i++) { + uint32_t base = DEBUG_TRACE_BUFFER_INDEX(first_seq + i) * DEBUG_TRACE_EVENT_WORDS; + + _tr_print_event(i, base); + } + + CRITICAL_LEAVE(); +} + +void debug_clear_events(void) +{ + CRITICAL_ENTER(); + + debug_trace_total = 0U; + + CRITICAL_LEAVE(); +} + +uint32_t debug_trace_count(void) +{ + uint32_t count; + CRITICAL_ENTER(); + + count = retained_count_locked(); + + CRITICAL_LEAVE(); + return count; +} + +uint32_t debug_trace_overwrites(void) +{ + uint32_t overwrites; + CRITICAL_ENTER(); + + overwrites = overwrite_count_locked(); + + CRITICAL_LEAVE(); + return overwrites; +} + +/* + * Fill *event from the i-th retained event (0 = oldest). + * + * debug_event_t is a common-readout struct. Only event_type and + * timestamp are always valid. param1 / param2 (and any future + * fields) may contain stale data from previously overwritten slots. + * Likewise, task_id is stale for events that don't emit TR_TID + * (e.g. ISR_ENTER / ISR_EXIT) — this avoids per-event field + * zeroing so write cost stays minimal. Callers must use event_type + * to know which fields the current event actually defines. +* + * Returns 0 on success, -1 if index is out of range or event is NULL. + */ +int32_t debug_trace_get(uint32_t index, debug_event_t *event) +{ + uint32_t seq; + uint32_t base; + + if (!event) + return -1; + + CRITICAL_ENTER(); + + if (!retained_sequence(index, &seq)) { + CRITICAL_LEAVE(); + return -1; + } + + base = DEBUG_TRACE_BUFFER_INDEX(seq) * DEBUG_TRACE_EVENT_WORDS; + *event = *(const debug_event_t *)(const void *)&debug_trace_buffer[base]; + + CRITICAL_LEAVE(); + return 0; +} + +#endif /* CONFIG_DEBUG_TRACE */ From df2c53e883f39d07e353ae541d62ce4c406a9466 Mon Sep 17 00:00:00 2001 From: Synte Peng Date: Sat, 25 Jul 2026 02:21:26 +0800 Subject: [PATCH 3/5] Add debug trace events Add 7 tracepoints to task.c: TASK_CREATE, TASK_DESTROY, TASK_SWITCH, TASK_DELAY, TASK_SUSPEND, TASK_RESUME, TASK_YIELD. Refactor mo_task_delay() and mo_task_suspend() to call _yield() directly instead of mo_task_yield(). mo_task_yield() now emits TASK_YIELD, so calling it from within mo_task_delay/suspend would double-trace (TASK_DELAY + TASK_YIELD, or TASK_SUSPEND + TASK_YIELD). The internal _yield() path is trace-free so each operation records exactly one event. Guard the previous_state capture in mo_task_cancel() with #if CONFIG_DEBUG_TRACE so the variable is compiled out when tracing is disabled. --- kernel/task.c | 24 ++++++++++++++++++++---- 1 file changed, 20 insertions(+), 4 deletions(-) diff --git a/kernel/task.c b/kernel/task.c index 286e83e0..70f6a961 100644 --- a/kernel/task.c +++ b/kernel/task.c @@ -9,6 +9,7 @@ #include #include #include +#include #include #include "private/error.h" @@ -692,6 +693,9 @@ void dispatch(void) next_task->state = TASK_RUNNING; next_task->time_slice = get_priority_timeslice(next_task->prio_level); + if (next_task != prev_task) + DEBUG_TRACE_EVENT(EVENT_TASK_SWITCH, prev_task->id, next_task->id); + /* Switch PMP configuration if tasks have different memory spaces */ pmp_switch_context(prev_task->mspace, next_task->mspace); @@ -949,6 +953,7 @@ static int32_t task_spawn_internal(void *task_entry, /* Add to cache and mark ready */ cache_task(tcb->id, tcb); sched_enqueue_task(tcb); + DEBUG_TRACE_EVENT(EVENT_TASK_CREATE, tcb->id, tcb->prio_level); return tcb->id; } @@ -1003,6 +1008,9 @@ int32_t mo_task_cancel(uint16_t id) } tcb_t *tcb = node->data; +#if CONFIG_DEBUG_TRACE + uint16_t previous_state = tcb ? tcb->state : 0; +#endif if (!tcb || tcb->state == TASK_RUNNING) { CRITICAL_LEAVE(); return ERR_TASK_CANT_REMOVE; @@ -1020,6 +1028,9 @@ int32_t mo_task_cancel(uint16_t id) } } +#if CONFIG_DEBUG_TRACE + DEBUG_TRACE_EVENT(EVENT_TASK_DESTROY, id, previous_state); +#endif CRITICAL_LEAVE(); /* Free memory outside critical section */ @@ -1034,6 +1045,10 @@ int32_t mo_task_cancel(uint16_t id) void mo_task_yield(void) { + /* TASK_YIELD tracks explicit mo_task_yield() calls only. Other reschedule + * paths call _yield() directly and must not emit this event. + */ + DEBUG_TRACE_EVENT(EVENT_TASK_YIELD); _yield(); } @@ -1056,9 +1071,10 @@ void mo_task_delay(uint16_t ticks) /* Set delay and blocked state - scheduler will skip blocked tasks */ self->delay = ticks; self->state = TASK_BLOCKED; + DEBUG_TRACE_EVENT(EVENT_TASK_DELAY, ticks, self->id); NOSCHED_LEAVE(); - mo_task_yield(); + _yield(); } int32_t mo_task_suspend(uint16_t id) @@ -1082,11 +1098,11 @@ int32_t mo_task_suspend(uint16_t id) task->state = TASK_SUSPENDED; bool is_current = (kcb->task_current->data == task); - + DEBUG_TRACE_EVENT(EVENT_TASK_SUSPEND, id); CRITICAL_LEAVE(); if (is_current) - mo_task_yield(); + _yield(); return ERR_OK; } @@ -1111,7 +1127,7 @@ int32_t mo_task_resume(uint16_t id) /* mark as ready - scheduler will find it */ task->state = TASK_READY; - + DEBUG_TRACE_EVENT(EVENT_TASK_RESUME, id); CRITICAL_LEAVE(); return ERR_OK; } From 3491a422f55f844e4075bc64a7e9851cb8d576bb Mon Sep 17 00:00:00 2001 From: Synte Peng Date: Mon, 27 Jul 2026 06:06:56 +0800 Subject: [PATCH 4/5] Snapshot debug trace buffer to shorten critical section debug_dump_events() held global interrupt-disable across up to 256 printf() calls. On a slow UART this delays timer dispatch and other interrupts for an unbounded amount of time. Fix by snapshotting the entire ring buffer into a static _tr_snap[] inside the critical section, then performing all printf output with interrupts re-enabled. All _tr_print_EVENT_* functions now take a buffer pointer instead of hard-coding debug_trace_buffer, and _tr_print_event() dispatches through it. --- kernel/debug_trace.c | 46 +++++++++++++++++++++++++++----------------- 1 file changed, 28 insertions(+), 18 deletions(-) diff --git a/kernel/debug_trace.c b/kernel/debug_trace.c index e0d10330..437b34fe 100644 --- a/kernel/debug_trace.c +++ b/kernel/debug_trace.c @@ -16,6 +16,7 @@ */ uint32_t debug_trace_buffer[DEBUG_EVENT_BUFFER_SIZE * DEBUG_TRACE_EVENT_WORDS]; volatile uint32_t debug_trace_total; +static uint32_t _tr_snap[DEBUG_EVENT_BUFFER_SIZE * DEBUG_TRACE_EVENT_WORDS]; /* ------------------------------------------------------------------ * * Internal helpers @@ -75,10 +76,11 @@ static bool retained_sequence(uint32_t index, uint32_t *seq_out) #define DEFINE_EVENT_CLASS(...) /* nothing */ #define __field(...) /* nothing */ -#define DEFINE_EVENT(name, cls, prot, proto, ...) \ - static void _tr_print_EVENT_##name(uint32_t idx, uint32_t base) { \ - const struct debug_event_cls_##cls *_e = \ - (const void *)&debug_trace_buffer[base]; \ +#define DEFINE_EVENT(name, cls, prot, proto, ...) \ + static void _tr_print_EVENT_##name(uint32_t idx, const uint32_t *buf, \ + uint32_t base) { \ + const struct debug_event_cls_##cls *_e = \ + (const void *)&buf[base]; \ printf("[%u] %14s ts=%u", idx, #name, _e->timestamp); \ _TR_FOR_EACH_PAIR(__VA_ARGS__) \ (void)_tr_has_print; \ @@ -96,7 +98,7 @@ static bool retained_sequence(uint32_t index, uint32_t *seq_out) * _tr_print_EVENT_##name handler. * ================================================================== */ -static void (*const _tr_print_fn[EVENT_TYPE_MAX])(uint32_t, uint32_t) = { +static void (*const _tr_print_fn[EVENT_TYPE_MAX])(uint32_t, const uint32_t *, uint32_t) = { #define DEFINE_EVENT_CLASS(...) /* nothing */ #define __field(...) /* nothing */ #define DEFINE_EVENT(name, ...) [EVENT_##name] = _tr_print_EVENT_##name, @@ -107,12 +109,12 @@ static void (*const _tr_print_fn[EVENT_TYPE_MAX])(uint32_t, uint32_t) = { #undef __field #undef DEFINE_EVENT_CLASS -static void _tr_print_event(uint32_t idx, uint32_t base) +static void _tr_print_event(uint32_t idx, const uint32_t *buf, uint32_t base) { - uint8_t ev = debug_trace_buffer[base] & 0xFFU; + uint8_t ev = buf[base] & 0xFFU; if (ev < EVENT_TYPE_MAX && _tr_print_fn[ev]) - _tr_print_fn[ev](idx, base); + _tr_print_fn[ev](idx, buf, base); else printf("[%u] UNKNOWN\n", idx); } @@ -125,26 +127,34 @@ void debug_dump_events(void) { uint32_t count; uint32_t overwrites; - uint32_t first_seq; + uint32_t total; + + /* + * snapshot the entire ring buffer inside the critical + * section so the slow per‑event printf loop + * runs with interrupts enabled. + */ CRITICAL_ENTER(); + __builtin_memcpy(_tr_snap, (const void *)debug_trace_buffer, + sizeof(_tr_snap)); + total = debug_trace_total; + CRITICAL_LEAVE(); - count = retained_count_locked(); - overwrites = overwrite_count_locked(); - first_seq = (debug_trace_total > DEBUG_EVENT_BUFFER_SIZE) - ? debug_trace_total - DEBUG_EVENT_BUFFER_SIZE - : 0U; + count = (total < DEBUG_EVENT_BUFFER_SIZE) + ? total : DEBUG_EVENT_BUFFER_SIZE; + overwrites = (total > DEBUG_EVENT_BUFFER_SIZE) + ? total - DEBUG_EVENT_BUFFER_SIZE : 0U; printf("debug trace: %u retained event%s, %u overwrite%s\n", count, (count == 1U) ? "" : "s", overwrites, (overwrites == 1U) ? "" : "s"); for (uint32_t i = 0U; i < count; i++) { - uint32_t base = DEBUG_TRACE_BUFFER_INDEX(first_seq + i) * DEBUG_TRACE_EVENT_WORDS; + uint32_t base = DEBUG_TRACE_BUFFER_INDEX(total - count + i) + * DEBUG_TRACE_EVENT_WORDS; - _tr_print_event(i, base); + _tr_print_event(i, _tr_snap, base); } - - CRITICAL_LEAVE(); } void debug_clear_events(void) From 04756f08e613f7b114129bc204a6c4695b9004ac Mon Sep 17 00:00:00 2001 From: Synte Peng Date: Mon, 27 Jul 2026 06:23:47 +0800 Subject: [PATCH 5/5] Serialize debug_trace dump against re-entrant calls Concurrent debug_dump_events() calls share the static _tr_snap[] buffer. Once interrupts are re-enabled for the printf loop the scheduler can switch to another task which, if it also calls dump, overwrites the snapshot and corrupts the first task's output. Add a volatile _tr_dumping flaginside the critical section. Re-entrant callers skip the dump entirely instead of blocking. --- kernel/debug_trace.c | 8 ++++++++ 1 file changed, 8 insertions(+) diff --git a/kernel/debug_trace.c b/kernel/debug_trace.c index 437b34fe..737fd1a0 100644 --- a/kernel/debug_trace.c +++ b/kernel/debug_trace.c @@ -17,6 +17,7 @@ uint32_t debug_trace_buffer[DEBUG_EVENT_BUFFER_SIZE * DEBUG_TRACE_EVENT_WORDS]; volatile uint32_t debug_trace_total; static uint32_t _tr_snap[DEBUG_EVENT_BUFFER_SIZE * DEBUG_TRACE_EVENT_WORDS]; +static volatile bool _tr_dumping; /* ------------------------------------------------------------------ * * Internal helpers @@ -135,6 +136,11 @@ void debug_dump_events(void) * runs with interrupts enabled. */ CRITICAL_ENTER(); + if (_tr_dumping) { + CRITICAL_LEAVE(); + return; + } + _tr_dumping = true; __builtin_memcpy(_tr_snap, (const void *)debug_trace_buffer, sizeof(_tr_snap)); total = debug_trace_total; @@ -155,6 +161,8 @@ void debug_dump_events(void) _tr_print_event(i, _tr_snap, base); } + + _tr_dumping = false; } void debug_clear_events(void)