driver_lab_rust/
trace.rs

1// Copyright 2026 The Fuchsia Authors. All rights reserved.
2// Use of this source code is governed by a BSD-style license that can be
3// found in the LICENSE file.
4
5//! System trace emission for driver-lab activity.
6//!
7//! [`AuditTracer`] mirrors audit records into Fuchsia tracing so host
8//! probes, register and knob writes, and interrupt taps share a timeline
9//! with scheduler, power, and driver events. An experiment can then relate
10//! a register or knob change to its effect on, for example, CPU wakeups or
11//! power rail counters within a single trace.
12//!
13//! Each audit record becomes an instant event named after its operation
14//! (for example `read32` or `write32`). Its arguments use the field names of
15//! `target-audit.jsonl` evidence rows (`seq`, `session`, `resource`,
16//! `offset`, `decision`, `denial`, `status`, `value`, `timestamp_ns`,
17//! `run_id`, `item_index`), plus `node` and `resource_name`, so trace events
18//! can be joined with evidence bundles. `timestamp_ns` is the audit record's
19//! monotonic timestamp; the event's own timestamp is when it was written.
20//!
21//! Each successful write also samples a counter named
22//! `<node>/<resource_name>` with one series per register offset (for
23//! example `0x1c`), so A/B arms appear as step functions.
24//!
25//! Events are written only while a trace session enables their category:
26//!
27//! - [`CATEGORY`] (`driver_lab`): all activity except interrupts.
28//! - [`IRQ_CATEGORY`] (`driver_lab:irq`): interrupt taps, kept separate
29//!   because high interrupt rates can crowd other events out of the trace
30//!   buffer.
31//!
32//! When neither category is enabled, the cost is one cached category check
33//! per record.
34
35use fuchsia_trace::{ArgValue, Scope, TraceCategoryContext, trace_site_t};
36use lab_proxy_core::access_policy::{Denial, MmioResource, ResourceId};
37use lab_proxy_core::audit_ring::{AuditObserver, AuditRecord, Decision, OpStatus};
38use std::collections::BTreeMap;
39use std::ffi::CStr;
40use std::sync::Arc;
41
42/// Trace category for driver-lab operations other than interrupts.
43pub const CATEGORY: &CStr = c"driver_lab";
44
45/// Trace category for interrupt taps.
46pub const IRQ_CATEGORY: &CStr = c"driver_lab:irq";
47
48/// Audit operation name for an observed interrupt.
49const INTERRUPT_TAP: &str = "interrupt_tap";
50
51/// Audit operation name for a register or knob write.
52const WRITE32: &str = "write32";
53
54static CATEGORY_SITE: trace_site_t = trace_site_t::new(0);
55static IRQ_CATEGORY_SITE: trace_site_t = trace_site_t::new(0);
56
57/// Writes one driver-lab instance's audit records as trace events.
58#[derive(Debug)]
59pub struct AuditTracer {
60    node: String,
61    resource_names: BTreeMap<ResourceId, String>,
62    counter_names: BTreeMap<ResourceId, String>,
63}
64
65impl AuditTracer {
66    /// Creates a tracer for the instance serving `node` that labels events
67    /// with the names of `resources`.
68    pub fn new(node: &str, resources: &BTreeMap<ResourceId, MmioResource>) -> Self {
69        let resource_names: BTreeMap<ResourceId, String> =
70            resources.iter().map(|(id, resource)| (*id, resource.name.clone())).collect();
71        let counter_names =
72            resource_names.iter().map(|(id, name)| (*id, counter_name(node, name))).collect();
73        Self { node: node.to_string(), resource_names, counter_names }
74    }
75
76    /// Returns an observer for
77    /// [`AuditRing::set_observer`](lab_proxy_core::audit_ring::AuditRing::set_observer)
78    /// that passes each appended record to [`Self::record`].
79    pub fn observer(self: &Arc<Self>) -> AuditObserver {
80        let tracer = Arc::clone(self);
81        Box::new(move |seq, record| tracer.record(Some(seq), record))
82    }
83
84    /// Writes `record` as an instant event, followed by a counter sample if
85    /// it is a successful write. `seq` is the audit sequence number, or
86    /// `None` for events that were not appended to an audit ring.
87    pub fn record(&self, seq: Option<u64>, record: &AuditRecord) {
88        let context = if record.operation == INTERRUPT_TAP {
89            TraceCategoryContext::acquire_cached(IRQ_CATEGORY, &IRQ_CATEGORY_SITE)
90        } else {
91            TraceCategoryContext::acquire_cached(CATEGORY, &CATEGORY_SITE)
92        };
93        let Some(context) = context else {
94            return;
95        };
96
97        let resource_name = record.resource.and_then(|id| self.resource_names.get(&id));
98        let denial = match record.decision {
99            Decision::Allowed => None,
100            Decision::Denied(denial) => Some(denial_label(denial)),
101        };
102
103        let mut args = Vec::with_capacity(13);
104        args.push(ArgValue::of("node", self.node.as_str()));
105        if let Some(seq) = seq {
106            args.push(ArgValue::of("seq", seq));
107        }
108        if let Some(session) = record.session {
109            args.push(ArgValue::of("session", session));
110        }
111        if let Some(resource) = record.resource {
112            args.push(ArgValue::of("resource", resource));
113        }
114        if let Some(name) = resource_name {
115            args.push(ArgValue::of("resource_name", name.as_str()));
116        }
117        if let Some(offset) = record.offset {
118            args.push(ArgValue::of("offset", offset));
119        }
120        args.push(ArgValue::of("decision", if denial.is_some() { "denied" } else { "allowed" }));
121        if let Some(denial) = denial.as_deref() {
122            args.push(ArgValue::of("denial", denial));
123        }
124        args.push(ArgValue::of("status", status_label(record.status)));
125        if let Some(value) = record.value {
126            args.push(ArgValue::of("value", value));
127        }
128        args.push(ArgValue::of("timestamp_ns", record.timestamp_ns));
129        if let Some(run_id) = record.run_id.as_deref() {
130            args.push(ArgValue::of("run_id", run_id));
131        }
132        if let Some(item_index) = record.item_index {
133            args.push(ArgValue::of("item_index", item_index));
134        }
135        fuchsia_trace::instant(&context, record.operation, Scope::Thread, &args);
136
137        if record.operation == WRITE32
138            && record.decision == Decision::Allowed
139            && record.status == OpStatus::Ok
140        {
141            if let (Some(resource), Some(offset), Some(value)) =
142                (record.resource, record.offset, record.value)
143            {
144                self.write_counter(&context, resource, offset, value);
145            }
146        }
147    }
148
149    /// Writes an `interrupt_tap` event for an interrupt observed outside
150    /// the audit ring, such as by the standalone proxy's interrupt threads.
151    /// `sequence` is the per-resource interrupt sequence number.
152    pub fn interrupt(&self, resource: ResourceId, sequence: u64, timestamp_ns: i64) {
153        self.record(
154            None,
155            &AuditRecord {
156                session: None,
157                resource: Some(resource),
158                operation: INTERRUPT_TAP,
159                offset: None,
160                decision: Decision::Allowed,
161                status: OpStatus::Ok,
162                // Matches the truncation in the embedded interrupt tap
163                // audit record.
164                value: Some(sequence as u32),
165                timestamp_ns,
166                run_id: None,
167                item_index: None,
168            },
169        );
170    }
171
172    /// Samples the counter series for `offset` on `resource`.
173    ///
174    /// Successful host writes are sampled automatically. Drivers call this
175    /// when they change a register or knob themselves, so driver and host
176    /// changes share one counter track.
177    pub fn counter(&self, resource: ResourceId, offset: u64, value: u32) {
178        if let Some(context) = TraceCategoryContext::acquire_cached(CATEGORY, &CATEGORY_SITE) {
179            self.write_counter(&context, resource, offset, value);
180        }
181    }
182
183    fn write_counter(
184        &self,
185        context: &TraceCategoryContext,
186        resource: ResourceId,
187        offset: u64,
188        value: u32,
189    ) {
190        let unnamed;
191        let name = match self.counter_names.get(&resource) {
192            Some(name) => name,
193            None => {
194                unnamed = counter_name(&self.node, &resource.to_string());
195                &unnamed
196            }
197        };
198        let series = offset_series(offset);
199        fuchsia_trace::counter(context, name, 0, &[ArgValue::of(series.as_str(), value)]);
200    }
201}
202
203fn counter_name(node: &str, resource_name: &str) -> String {
204    format!("{node}/{resource_name}")
205}
206
207fn offset_series(offset: u64) -> String {
208    format!("{offset:#x}")
209}
210
211/// Converts a [`Denial`] to the snake_case label used in evidence bundles,
212/// for example `NotInAllowlist` to `not_in_allowlist`.
213fn denial_label(denial: Denial) -> String {
214    let name = format!("{denial:?}");
215    let mut label = String::with_capacity(name.len() + 4);
216    for (index, ch) in name.chars().enumerate() {
217        if ch.is_ascii_uppercase() {
218            if index > 0 {
219                label.push('_');
220            }
221            label.push(ch.to_ascii_lowercase());
222        } else {
223            label.push(ch);
224        }
225    }
226    label
227}
228
229/// Returns the evidence bundle label for `status`.
230fn status_label(status: OpStatus) -> &'static str {
231    match status {
232        OpStatus::Ok => "ok",
233        OpStatus::Rejected => "rejected",
234        OpStatus::BackendFault => "backend_fault",
235    }
236}
237
238#[cfg(test)]
239mod tests {
240    use super::*;
241
242    #[test]
243    fn denial_labels_match_evidence_format() {
244        assert_eq!(denial_label(Denial::NotInAllowlist), "not_in_allowlist");
245        assert_eq!(denial_label(Denial::HardDenied), "hard_denied");
246        assert_eq!(denial_label(Denial::UnknownReadsNotPermitted), "unknown_reads_not_permitted");
247        assert_eq!(denial_label(Denial::Timeout), "timeout");
248    }
249
250    #[test]
251    fn status_labels_match_evidence_format() {
252        assert_eq!(status_label(OpStatus::Ok), "ok");
253        assert_eq!(status_label(OpStatus::Rejected), "rejected");
254        assert_eq!(status_label(OpStatus::BackendFault), "backend_fault");
255    }
256
257    #[test]
258    fn counter_tracks_are_named_by_node_resource_and_offset() {
259        let mut resources = BTreeMap::new();
260        resources.insert(0, MmioResource::mmio("regs", 0x100, 0x1000));
261        resources.insert(3, MmioResource::interrupt("irq0"));
262        let tracer = AuditTracer::new("sample-driver", &resources);
263        assert_eq!(tracer.counter_names.get(&0).map(String::as_str), Some("sample-driver/regs"));
264        assert_eq!(tracer.counter_names.get(&3).map(String::as_str), Some("sample-driver/irq0"));
265        assert_eq!(offset_series(0x1c), "0x1c");
266        assert_eq!(offset_series(0), "0x0");
267    }
268
269    #[test]
270    fn emitting_without_an_active_trace_session_is_a_no_op() {
271        let mut resources = BTreeMap::new();
272        resources.insert(0, MmioResource::mmio("regs", 0x100, 0x1000));
273        let tracer = Arc::new(AuditTracer::new("sample-driver", &resources));
274        let observer = tracer.observer();
275        observer(
276            7,
277            &AuditRecord {
278                session: Some(1),
279                resource: Some(0),
280                operation: WRITE32,
281                offset: Some(0x1c),
282                decision: Decision::Allowed,
283                status: OpStatus::Ok,
284                value: Some(1),
285                timestamp_ns: 1,
286                run_id: Some("run".to_string()),
287                item_index: Some(2),
288            },
289        );
290        observer(
291            8,
292            &AuditRecord {
293                decision: Decision::Denied(Denial::HardDenied),
294                status: OpStatus::Rejected,
295                ..AuditRecord::lifecycle("read32", 2)
296            },
297        );
298        tracer.interrupt(0, 1, 3);
299        tracer.counter(0, 0x1c, 0);
300        tracer.counter(99, 0x1c, 0);
301    }
302}
driver_lab_rust/trace.rs

driver_lab_rust/
trace.rs
