rivet/
trace.rs

1//! Rivet Debugger wire protocol encoder — emits the binary trace frames
2//! `rivet-debugger-app` (a separate, sibling project — see its own SRS/
3//! PLAN at `../rivet-debugger`) decodes live over a UART.
4//!
5//! Mirrors `rivet-trace-protocol`'s frame layout (SYNC0/SYNC1, CRC-16/
6//! CCITT-FALSE, `EventKind`/`Payload` encoding) by hand, not by sharing
7//! a crate: that project lives in a separate repository, and depending
8//! on it directly from this kernel crate would mean `rivet` no longer
9//! builds standalone from a fresh clone — the same reasoning `rivet`
10//! already applies to every board-specific crate (nothing outside this
11//! repo, nothing MMIO-shaped, in the kernel itself). If the two drift,
12//! `rivet-trace-protocol`'s own decoder is the ground truth; re-derive
13//! this module's byte layout from `rivet-trace-protocol/src/frame.rs`
14//! and `event.rs`, not from memory.
15//!
16//! Gated behind the `trace` feature (off by default, same discipline as
17//! [`crate::latency`]): every call in this module is a no-op unless a
18//! board crate both enables the feature and implements
19//! [`crate::port::board::trace_write`]'s extern symbol.
20
21#[cfg(feature = "trace")]
22mod imp {
23    pub const SYNC0: u8 = 0xA5;
24    pub const SYNC1: u8 = 0x5A;
25    pub const PROTOCOL_VERSION: u8 = 1;
26    pub const NO_TASK: u32 = u32::MAX;
27    pub const MAX_PAYLOAD: usize = 32;
28    pub const FRAME_OVERHEAD: usize = 2 + 1 + 2 + 2 + 1 + 4 + 8 + 1 + 2;
29    pub const MAX_FRAME: usize = FRAME_OVERHEAD + MAX_PAYLOAD;
30
31    pub fn crc16(data: &[u8]) -> u16 {
32        let mut crc: u16 = 0xFFFF;
33        for &byte in data {
34            crc ^= (byte as u16) << 8;
35            for _ in 0..8 {
36                if crc & 0x8000 != 0 {
37                    crc = (crc << 1) ^ 0x1021;
38                } else {
39                    crc <<= 1;
40                }
41            }
42        }
43        crc
44    }
45
46    use core::sync::atomic::{AtomicU16, Ordering};
47    static SEQ: AtomicU16 = AtomicU16::new(0);
48
49    /// Writes one frame into `buf`, returns the number of bytes written.
50    /// `payload.len()` must be `<= MAX_PAYLOAD`.
51    pub fn encode(
52        buf: &mut [u8; MAX_FRAME],
53        kind: u16,
54        core_id: u8,
55        task_id: u32,
56        timestamp: u64,
57        payload: &[u8],
58    ) -> usize {
59        debug_assert!(payload.len() <= MAX_PAYLOAD);
60        let seq = SEQ.fetch_add(1, Ordering::Relaxed);
61        buf[0] = SYNC0;
62        buf[1] = SYNC1;
63        buf[2] = PROTOCOL_VERSION;
64        buf[3..5].copy_from_slice(&seq.to_le_bytes());
65        buf[5..7].copy_from_slice(&kind.to_le_bytes());
66        buf[7] = core_id;
67        buf[8..12].copy_from_slice(&task_id.to_le_bytes());
68        buf[12..20].copy_from_slice(&timestamp.to_le_bytes());
69        buf[20] = payload.len() as u8;
70        buf[21..21 + payload.len()].copy_from_slice(payload);
71        let crc_end = 21 + payload.len();
72        let crc = crc16(&buf[0..crc_end]);
73        buf[crc_end..crc_end + 2].copy_from_slice(&crc.to_le_bytes());
74        crc_end + 2
75    }
76
77    pub fn now_ts() -> u64 {
78        crate::port::board::now_us()
79    }
80
81    pub fn core_id() -> u8 {
82        crate::port::arch::hart_id() as u8
83    }
84}
85
86#[cfg(feature = "trace")]
87use imp::*;
88
89// EventKind discriminants actually emitted from this module — a subset
90// of `rivet-trace-protocol::EventKind`'s full ~48, matching what this
91// kernel currently has real hook points for (`docs/DOCUMENTATION.md`
92// §18 lists broadening this as a follow-up, not a gap hidden here).
93#[cfg(feature = "trace")]
94mod kind {
95    pub const STREAM_HEADER: u16 = 0x0701;
96    pub const TASK_CREATED: u16 = 0x0001;
97    pub const CONTEXT_SWITCH: u16 = 0x0009;
98    pub const IRQ_ENTER: u16 = 0x0301;
99    pub const IRQ_EXIT: u16 = 0x0302;
100    pub const MUTEX_LOCK_ACQUIRED: u16 = 0x0102;
101    pub const MUTEX_UNLOCK: u16 = 0x0104;
102    pub const PRIORITY_INHERIT: u16 = 0x0105;
103    pub const HARD_FAULT: u16 = 0x0601;
104    pub const STACK_OVERFLOW: u16 = 0x0605;
105}
106
107/// Why a context switch happened, matching
108/// `rivet-trace-protocol::SwitchReason`'s wire encoding.
109#[cfg(feature = "trace")]
110#[derive(Clone, Copy)]
111pub enum SwitchReason {
112    Preempted = 0,
113    TimerWake = 6,
114}
115
116// Cached so a late-joining client can be caught up (see
117// `reannounce_stream_header`) — the header is otherwise only ever sent
118// once, at boot, same gap `reannounce_all_tasks` closes for task info.
119#[cfg(feature = "trace")]
120static CACHED_CPU_HZ: core::sync::atomic::AtomicU32 = core::sync::atomic::AtomicU32::new(0);
121#[cfg(feature = "trace")]
122static CACHED_MAX_HARTS: core::sync::atomic::AtomicU8 = core::sync::atomic::AtomicU8::new(0);
123
124/// Sent once, first frame of a session: SRS §19's "target information —
125/// Rivet version, CPU frequency." Call as early as
126/// [`crate::port::board::trace_write`] is usable.
127#[cfg(feature = "trace")]
128pub fn stream_header(cpu_hz: u32, max_harts: u8) {
129    use core::sync::atomic::Ordering;
130    CACHED_CPU_HZ.store(cpu_hz, Ordering::Relaxed);
131    CACHED_MAX_HARTS.store(max_harts, Ordering::Relaxed);
132    let mut payload = [0u8; 8];
133    payload[0] = 0; // rivet_version.major — this workspace ships 0.x
134    payload[1] = 1;
135    payload[2] = 0;
136    payload[3..7].copy_from_slice(&cpu_hz.to_le_bytes());
137    payload[7] = max_harts;
138    let mut buf = [0u8; MAX_FRAME];
139    let n = encode(&mut buf, kind::STREAM_HEADER, core_id(), NO_TASK, now_ts(), &payload);
140    crate::port::board::trace_write(&buf[..n]);
141}
142
143/// Re-sends `StreamHeader` from the values cached by the last real
144/// [`stream_header`] call. A client that connects even slightly after
145/// boot (unavoidable given real server/browser startup latency) misses
146/// the one-shot boot frame and shows "unknown clock" forever — same gap,
147/// same fix shape as [`reannounce_all_tasks`]. No-op if `stream_header`
148/// was never called (cached cpu_hz still 0).
149#[cfg(feature = "trace")]
150pub fn reannounce_stream_header() {
151    use core::sync::atomic::Ordering;
152    let cpu_hz = CACHED_CPU_HZ.load(Ordering::Relaxed);
153    if cpu_hz == 0 {
154        return;
155    }
156    stream_header(cpu_hz, CACHED_MAX_HARTS.load(Ordering::Relaxed));
157}
158
159/// A task was just registered with the scheduler — sent once, right as
160/// [`crate::preempt::spawn`] commits the new task's slot, so the host UI
161/// has the task's real priority before its first `ContextSwitch` ever
162/// arrives.
163#[cfg(feature = "trace")]
164pub fn task_created(task_id: u16, priority: u8, stack_size: u32) {
165    let mut payload = [0u8; 5];
166    payload[0] = priority;
167    payload[1..5].copy_from_slice(&stack_size.to_le_bytes());
168    let mut buf = [0u8; MAX_FRAME];
169    let n = encode(
170        &mut buf,
171        kind::TASK_CREATED,
172        core_id(),
173        task_id as u32,
174        now_ts(),
175        &payload,
176    );
177    crate::port::board::trace_write(&buf[..n]);
178}
179
180/// A real scheduler dispatch: `prev_task` left the CPU (for `reason`),
181/// `next_task` is now running. Called from the scheduler's actual
182/// dispatch commit point, not synthesized from polling.
183#[cfg(feature = "trace")]
184pub fn context_switch(prev_task: u16, next_task: u16, reason: SwitchReason) {
185    let mut payload = [0u8; 9];
186    payload[0..4].copy_from_slice(&(prev_task as u32).to_le_bytes());
187    payload[4..8].copy_from_slice(&(next_task as u32).to_le_bytes());
188    payload[8] = reason as u8;
189    let mut buf = [0u8; MAX_FRAME];
190    let n = encode(
191        &mut buf,
192        kind::CONTEXT_SWITCH,
193        core_id(),
194        next_task as u32,
195        now_ts(),
196        &payload,
197    );
198    crate::port::board::trace_write(&buf[..n]);
199}
200
201/// An interrupt was entered (`entry = true`) or exited.
202#[cfg(feature = "trace")]
203pub fn isr(irq: u32, entry: bool) {
204    let mut payload = [0u8; 4];
205    payload.copy_from_slice(&irq.to_le_bytes());
206    let mut buf = [0u8; MAX_FRAME];
207    let k = if entry { kind::IRQ_ENTER } else { kind::IRQ_EXIT };
208    let n = encode(&mut buf, k, core_id(), NO_TASK, now_ts(), &payload);
209    crate::port::board::trace_write(&buf[..n]);
210}
211
212/// A `PriorityMutex` was acquired by `task_id`.
213#[cfg(feature = "trace")]
214pub fn mutex_lock_acquired(task_id: u16, mutex_id: u32) {
215    let mut payload = [0u8; 4];
216    payload.copy_from_slice(&mutex_id.to_le_bytes());
217    let mut buf = [0u8; MAX_FRAME];
218    let n = encode(
219        &mut buf,
220        kind::MUTEX_LOCK_ACQUIRED,
221        core_id(),
222        task_id as u32,
223        now_ts(),
224        &payload,
225    );
226    crate::port::board::trace_write(&buf[..n]);
227}
228
229/// A `PriorityMutex` was released by `task_id`.
230#[cfg(feature = "trace")]
231pub fn mutex_unlock(task_id: u16, mutex_id: u32) {
232    let mut payload = [0u8; 4];
233    payload.copy_from_slice(&mutex_id.to_le_bytes());
234    let mut buf = [0u8; MAX_FRAME];
235    let n = encode(&mut buf, kind::MUTEX_UNLOCK, core_id(), task_id as u32, now_ts(), &payload);
236    crate::port::board::trace_write(&buf[..n]);
237}
238
239/// `task_id`'s effective priority was boosted by priority inheritance
240/// while a higher-priority task waited on a mutex it holds.
241#[cfg(feature = "trace")]
242pub fn priority_inherit(task_id: u16, mutex_id: u32) {
243    let mut payload = [0u8; 4];
244    payload.copy_from_slice(&mutex_id.to_le_bytes());
245    let mut buf = [0u8; MAX_FRAME];
246    let n = encode(
247        &mut buf,
248        kind::PRIORITY_INHERIT,
249        core_id(),
250        task_id as u32,
251        now_ts(),
252        &payload,
253    );
254    crate::port::board::trace_write(&buf[..n]);
255}
256
257/// A task faulted. `reason` mirrors `crate::fault::FaultKind`'s
258/// discriminant (0=InstructionAccess, 1=LoadAccess, 2=StoreAccess,
259/// 3=MemManage, 4=StackOverflow, 5=BudgetExceeded).
260#[cfg(feature = "trace")]
261pub fn fault(task_id: u16, reason: u8, pc: u32) {
262    let mut payload = [0u8; 8];
263    payload[0..4].copy_from_slice(&(reason as u32).to_le_bytes());
264    payload[4..8].copy_from_slice(&pc.to_le_bytes());
265    let mut buf = [0u8; MAX_FRAME];
266    let k = if reason == 4 { kind::STACK_OVERFLOW } else { kind::HARD_FAULT };
267    let n = encode(&mut buf, k, core_id(), task_id as u32, now_ts(), &payload);
268    crate::port::board::trace_write(&buf[..n]);
269}
270
271/// Re-emits `TaskCreated` for every currently-registered task.
272/// [`task_created`] fires once, at spawn time — a debugger app that
273/// connects even a moment later (or drops and reconnects) never sees
274/// it, and every task it knows about would show priority 0 forever
275/// (a real gap found by actually reconnecting to a live board, not
276/// theorized). Called periodically from the tick path
277/// ([`crate::preempt::on_tick`], counter-gated so it costs one scan of
278/// [`crate::preempt::tcb::MAX_PTASKS`] slots every couple of seconds,
279/// not every tick) so a late-joining client has the true picture within
280/// one interval, not just at boot.
281#[cfg(feature = "trace")]
282pub fn reannounce_all_tasks() {
283    use crate::preempt::tcb;
284    use core::sync::atomic::Ordering;
285    for id in 0..tcb::MAX_PTASKS {
286        let Some(t) = tcb::get(id) else { continue };
287        if !t.used.load(Ordering::Acquire) {
288            continue;
289        }
290        let priority = t.base_priority.load(Ordering::Acquire);
291        let stack_size = t.stack_size.load(Ordering::Acquire) as u32;
292        task_created(id as u16, priority, stack_size);
293    }
294}
rivet/trace.rs

rivet/
trace.rs
