1use std::sync::Arc;
6use std::sync::atomic::{AtomicBool, AtomicUsize, Ordering};
7
8use crate::task::Kernel;
9use crate::vfs::OutputBuffer;
10use fuchsia_inspect::Property;
11use fuchsia_rcu::RcuDroppableArc;
12use paged_ring_buffer::LocklessRingBuffer;
13use starnix_logging::log_error;
14use starnix_sync::{LockDepMutex, PerfTraceEventQueueListLock};
15use starnix_types::PAGE_SIZE;
16use starnix_uapi::errors::Errno;
17use starnix_uapi::{errno, error};
18use zerocopy::native_endian::{I32, U16, U32, U64};
19use zerocopy::{Immutable, IntoBytes, Unaligned};
20use zx::BootTimeline;
21
22const DEFAULT_RING_BUFFER_SIZE_BYTES: usize = 2097152;
24
25const FTRACE_PRINT_ID: U16 = U16::new(5);
27
28const DROPPED_PAGES: &str = "dropped_pages";
30
31const MAX_TIME_DELTA_NANOS: u32 = (1 << 27) - 1;
32
33#[repr(C)]
34#[derive(Debug, Default, IntoBytes, Immutable, Unaligned)]
35struct PrintEventHeader {
36 common_type: U16,
37 common_flags: u8,
38 common_preempt_count: u8,
39 common_pid: I32,
40 ip: U64,
41}
42
43#[repr(C)]
44#[derive(Debug, IntoBytes, Immutable, Unaligned)]
45struct PrintEvent {
46 header: PrintEventHeader,
47}
48
49impl PrintEvent {
50 fn new(pid: i32) -> Self {
51 Self {
52 header: PrintEventHeader {
53 common_type: FTRACE_PRINT_ID,
54 common_pid: I32::new(pid),
55 ..Default::default()
57 },
58 }
59 }
60
61 fn size(&self) -> usize {
62 std::mem::size_of::<PrintEventHeader>()
63 }
64}
65
66#[repr(C)]
67#[derive(Debug, Default, IntoBytes, PartialEq, Immutable, Unaligned)]
68struct TraceEventHeader {
69 time_delta: U32,
73
74 data: U32,
77}
78
79impl TraceEventHeader {
80 fn new(size: usize) -> Self {
81 let size = (std::mem::size_of::<u32>() + size) as u32;
84 Self { time_delta: U32::new(0), data: U32::new(size) }
85 }
86
87 fn set_time_delta(&mut self, nanos: u32) {
88 let saturated_nanos = nanos.min(MAX_TIME_DELTA_NANOS);
92 self.time_delta = U32::new(saturated_nanos << 5);
94 }
95}
96
97#[repr(C)]
98#[derive(Debug, IntoBytes, Immutable, Unaligned)]
99pub struct TraceEvent {
100 header: TraceEventHeader, event: PrintEvent,
108}
109
110impl TraceEvent {
111 pub fn new(pid: i32, data_len: usize) -> Self {
112 let event = PrintEvent::new(pid);
113 let header = TraceEventHeader::new(event.size() + data_len + 1);
115 Self { header, event }
116 }
117
118 fn size(&self) -> usize {
119 std::mem::size_of::<u32>() + self.header.data.get() as usize
121 }
122}
123
124pub struct TraceEventQueue {
126 ring_buffer: RcuDroppableArc<LocklessRingBuffer>,
128
129 pub async_id_read: fuchsia_trace::Id,
131
132 pub async_id_write: fuchsia_trace::Id,
134
135 pub cpu_id: u32,
137}
138
139const STATIC_READ_TRACK_NAMES: [&str; 8] = [
140 "Tracefs read 0",
141 "Tracefs read 1",
142 "Tracefs read 2",
143 "Tracefs read 3",
144 "Tracefs read 4",
145 "Tracefs read 5",
146 "Tracefs read 6",
147 "Tracefs read 7",
148];
149
150const STATIC_WRITE_TRACK_NAMES: [&str; 8] = [
151 "Tracefs write 0",
152 "Tracefs write 1",
153 "Tracefs write 2",
154 "Tracefs write 3",
155 "Tracefs write 4",
156 "Tracefs write 5",
157 "Tracefs write 6",
158 "Tracefs write 7",
159];
160
161impl<'a> TraceEventQueue {
162 pub(crate) fn new(cpu_id: u32) -> Result<Self, Errno> {
163 Self::new_with_size(cpu_id, DEFAULT_RING_BUFFER_SIZE_BYTES)
164 }
165
166 pub(crate) fn new_with_size(cpu_id: u32, size_bytes: usize) -> Result<Self, Errno> {
167 let async_id_read = fuchsia_trace::Id::new();
168 let async_id_write = fuchsia_trace::Id::new();
169 let ring_buffer = Arc::new(
170 LocklessRingBuffer::new(size_bytes, true, async_id_write)
171 .map_err(|_| errno!(ENOMEM))?,
172 );
173 ring_buffer.disable()?;
174
175 Ok(Self {
176 ring_buffer: RcuDroppableArc::new(ring_buffer),
177 async_id_read,
178 async_id_write,
179 cpu_id,
180 })
181 }
182
183 pub fn read_track_name(&self) -> std::borrow::Cow<'static, str> {
184 if let Some(&name) = STATIC_READ_TRACK_NAMES.get(self.cpu_id as usize) {
185 std::borrow::Cow::Borrowed(name)
186 } else {
187 std::borrow::Cow::Owned(format!("Tracefs read {}", self.cpu_id))
188 }
189 }
190
191 pub fn write_track_name(&self) -> std::borrow::Cow<'static, str> {
192 if let Some(&name) = STATIC_WRITE_TRACK_NAMES.get(self.cpu_id as usize) {
193 std::borrow::Cow::Borrowed(name)
194 } else {
195 std::borrow::Cow::Owned(format!("Tracefs write {}", self.cpu_id))
196 }
197 }
198
199 fn enable(&self) -> Result<zx::BootInstant, Errno> {
200 self.ring_buffer.read().enable()
201 }
202
203 fn disable(&self) -> Result<u64, Errno> {
206 self.ring_buffer.read().disable()
207 }
208
209 pub fn read(&self, buf: &mut dyn OutputBuffer) -> Result<usize, Errno> {
214 self.ring_buffer.read().read(&mut RingOutputBuffer(buf))
215 }
216
217 pub fn push_event(
224 &self,
225 mut event: TraceEvent,
226 data: &[u8],
227 ) -> Result<zx::Duration<BootTimeline>, Errno> {
228 let size = event.size();
229 let ring_buffer = self.ring_buffer.read();
230
231 let (res, _timestamp, delta) = match ring_buffer.reserve(size) {
232 Ok(res) => res,
233 Err(e) if e == errno!(EINVAL) => {
234 log_error!("Invalid reservation size: {}", size);
235 return Err(errno!(EINVAL));
236 }
237 Err(e) if e == errno!(ENOSPC) => {
238 log_error!("Ring buffer full, dropping event of size: {}", size);
239 return Err(errno!(ENOSPC));
240 }
241 Err(e) => return Err(e),
242 };
243
244 let nanos = delta.into_nanos().try_into().unwrap_or(u32::MAX);
245 event.header.set_time_delta(nanos);
246
247 let bytes = event.as_bytes();
248 res.write_at(0, bytes);
249 res.write_at(bytes.len(), data);
250 res.write_at(bytes.len() + data.len(), b"\n");
251
252 ring_buffer.commit(res);
253
254 Ok(delta)
255 }
256}
257
258pub struct TraceEventQueueList {
259 pub queues: Vec<Arc<TraceEventQueue>>,
260 state_mutex: LockDepMutex<(), PerfTraceEventQueueListLock>,
265 tracing_enabled: Arc<AtomicBool>,
266 configured_buffer_size_kb: AtomicUsize,
267 tracefs_node: fuchsia_inspect::Node,
268 buffer_size_kb_property: fuchsia_inspect::UintProperty,
269 total_capacity_bytes_property: fuchsia_inspect::UintProperty,
270}
271
272impl TraceEventQueueList {
273 pub fn from(kernel: &Kernel) -> Arc<Self> {
274 kernel.expando.get_or_init(|| {
275 let num_cpus = zx::system_get_num_cpus() as usize;
276 Self::new(num_cpus, kernel.inspect_node.create_child("tracefs"))
277 })
278 }
279
280 #[cfg(test)]
281 pub(crate) fn new_for_testing(
282 num_cpus: usize,
283 inspect_parent: &fuchsia_inspect::Node,
284 ) -> Arc<Self> {
285 Arc::new(Self::new(num_cpus, inspect_parent.create_child("tracefs")))
286 }
287
288 fn new(num_cpus: usize, tracefs_node: fuchsia_inspect::Node) -> Self {
289 let default_size_kb = DEFAULT_RING_BUFFER_SIZE_BYTES / 1024;
290 let buffer_size_kb_property =
291 tracefs_node.create_uint("buffer_size_kb", default_size_kb as u64);
292 let total_capacity_bytes_property = tracefs_node.create_uint(
293 "total_capacity_bytes",
294 (DEFAULT_RING_BUFFER_SIZE_BYTES * num_cpus) as u64,
295 );
296 let queues = (0..num_cpus)
297 .map(|cpu| Arc::new(TraceEventQueue::new(cpu as u32).expect("create queue")))
298 .collect();
299 Self {
300 queues,
301 state_mutex: Default::default(),
302 tracing_enabled: Arc::new(AtomicBool::new(false)),
303 configured_buffer_size_kb: AtomicUsize::new(default_size_kb),
304 tracefs_node,
305 buffer_size_kb_property,
306 total_capacity_bytes_property,
307 }
308 }
309
310 pub fn is_enabled(&self) -> bool {
311 self.tracing_enabled.load(Ordering::Acquire)
312 }
313
314 pub fn buffer_size_kb(&self) -> usize {
315 self.configured_buffer_size_kb.load(Ordering::Acquire)
316 }
317
318 pub fn set_buffer_size_kb(&self, size_kb: usize) -> Result<usize, Errno> {
327 if size_kb == 0 {
328 return error!(EINVAL);
329 }
330 let _lock = self.state_mutex.lock();
331 let enabled = self.is_enabled();
332
333 let page_size_kb = (*PAGE_SIZE as usize) / 1024;
334 let requested_pages = size_kb.div_ceil(page_size_kb);
335 let pages = std::cmp::max(3, requested_pages);
337 let actual_size_kb = pages.checked_mul(page_size_kb).ok_or_else(|| errno!(ENOMEM))?;
338 let target_bytes = actual_size_kb.checked_mul(1024).ok_or_else(|| errno!(ENOMEM))?;
339 let total_capacity_bytes =
340 target_bytes.checked_mul(self.queues.len()).ok_or_else(|| errno!(ENOMEM))?;
341
342 let mut new_buffers = Vec::with_capacity(self.queues.len());
344 for queue in &self.queues {
345 let ring_buffer = Arc::new(
346 LocklessRingBuffer::new(target_bytes, true, queue.async_id_write)
347 .map_err(|_| errno!(ENOMEM))?,
348 );
349 if !enabled {
350 ring_buffer.disable()?;
351 }
352 new_buffers.push(ring_buffer);
353 }
354
355 for (queue, new_buffer) in self.queues.iter().zip(new_buffers) {
357 queue.ring_buffer.update(new_buffer);
358 }
359
360 self.configured_buffer_size_kb.store(actual_size_kb, Ordering::Release);
361 self.buffer_size_kb_property.set(actual_size_kb as u64);
362 self.total_capacity_bytes_property.set(total_capacity_bytes as u64);
363
364 Ok(actual_size_kb)
365 }
366
367 pub fn enable(&self) -> Result<(), Errno> {
372 let _lock = self.state_mutex.lock();
373 let mut first_error = None;
374 for queue in &self.queues {
375 if let Err(e) = queue.enable() {
376 if first_error.is_none() {
377 first_error = Some(e);
378 }
379 }
380 }
381 if let Some(e) = first_error {
382 return Err(e);
383 }
384 self.tracing_enabled.store(true, Ordering::Release);
385 Ok(())
386 }
387
388 pub fn disable(&self) -> Result<(), Errno> {
389 let _lock = self.state_mutex.lock();
390 self.tracing_enabled.store(false, Ordering::Release);
392 let mut first_error = None;
393 let mut total_dropped = 0;
394 for queue in &self.queues {
395 match queue.disable() {
396 Ok(dropped) => total_dropped += dropped,
397 Err(e) => {
398 if first_error.is_none() {
399 first_error = Some(e);
400 }
401 }
402 }
403 }
404
405 self.tracefs_node.record_uint(DROPPED_PAGES, total_dropped);
406
407 if let Some(e) = first_error {
408 return Err(e);
409 }
410 Ok(())
411 }
412}
413
414struct RingOutputBuffer<'a>(&'a mut dyn OutputBuffer);
417
418impl paged_ring_buffer::OutputBuffer for RingOutputBuffer<'_> {
419 fn available(&self) -> usize {
420 self.0.available()
421 }
422 fn write_each(
423 &mut self,
424 callback: &mut paged_ring_buffer::OutputBufferCallback<'_>,
425 ) -> Result<usize, Errno> {
426 self.0.write_each(callback)
427 }
428}
429
430#[cfg(test)]
431mod tests {
432 use super::{
433 DEFAULT_RING_BUFFER_SIZE_BYTES, LocklessRingBuffer, TraceEvent, TraceEventQueue,
434 TraceEventQueueList,
435 };
436 use crate::vfs::OutputBuffer;
437 use crate::vfs::buffers::VecOutputBuffer;
438 use diagnostics_assertions::assert_data_tree;
439 use std::sync::Arc;
440
441 use starnix_types::PAGE_SIZE;
442 use starnix_uapi::error;
443
444 #[fuchsia::test]
445 fn trace_event_queue_empty_errors() {
446 let queue = TraceEventQueue::new(0).unwrap();
447
448 let mut buffer = VecOutputBuffer::new(*PAGE_SIZE as usize);
449 assert_eq!(queue.read(&mut buffer), error!(EAGAIN));
450
451 let data = b"B|1234|slice_name";
452 let event = TraceEvent::new(1234, data.len());
453 assert_eq!(queue.push_event(event, data), error!(ENOMEM));
454 }
455
456 #[fuchsia::test]
457 fn read_empty_queue() {
458 let queue = TraceEventQueue::new(0).expect("create queue");
459 let mut buffer = VecOutputBuffer::new(*PAGE_SIZE as usize);
460 assert_eq!(queue.read(&mut buffer), error!(EAGAIN));
461 }
462
463 #[fuchsia::test]
464 fn enable_disable_queue() {
465 let queue = TraceEventQueue::new(0).expect("create queue");
466 assert!(!queue.ring_buffer.read().is_enabled());
467
468 assert!(queue.enable().is_ok());
470
471 let data = b"B|1234|slice_name";
473 let event = TraceEvent::new(1234, data.len());
474 let result = queue.push_event(event, data);
475
476 assert!(result.is_ok());
477 assert_eq!(result.as_ref().unwrap().into_nanos(), 0);
478
479 assert!(queue.disable().is_ok());
481 assert!(!queue.ring_buffer.read().is_enabled());
482 }
483
484 #[fuchsia::test]
485 fn buffer_size_kb_configuration() {
486 let inspector = fuchsia_inspect::Inspector::default();
487 let list = TraceEventQueueList::new_for_testing(2, inspector.root());
488 assert_eq!(list.buffer_size_kb(), DEFAULT_RING_BUFFER_SIZE_BYTES / 1024);
489
490 let new_size_kb = list.set_buffer_size_kb(4096).expect("set buffer size");
492 assert_eq!(new_size_kb, 4096);
493 assert_eq!(list.buffer_size_kb(), 4096);
494 for queue in &list.queues {
495 assert_eq!(queue.ring_buffer.read().size_bytes(), 4096 * 1024);
496 assert!(!queue.ring_buffer.read().is_enabled());
497 }
498
499 let clamped_size_kb = list.set_buffer_size_kb(4).expect("clamp buffer size");
501 assert_eq!(clamped_size_kb, 12);
502 assert_eq!(list.buffer_size_kb(), 12);
503 for queue in &list.queues {
504 assert_eq!(queue.ring_buffer.read().size_bytes(), 12 * 1024);
505 assert!(!queue.ring_buffer.read().is_enabled());
506 }
507
508 assert_eq!(list.set_buffer_size_kb(0), error!(EINVAL));
510
511 list.enable().expect("enable tracing");
513 let enabled_size_kb = list.set_buffer_size_kb(2048).expect("set buffer size while enabled");
514 assert_eq!(enabled_size_kb, 2048);
515 assert_eq!(list.buffer_size_kb(), 2048);
516 for queue in &list.queues {
517 assert_eq!(queue.ring_buffer.read().size_bytes(), 2048 * 1024);
518 assert!(queue.ring_buffer.read().is_enabled());
519 }
520 list.disable().expect("disable tracing");
521 }
522
523 #[fuchsia::test]
524 async fn buffer_size_kb_inspect_updates_in_place() {
525 let inspector = fuchsia_inspect::Inspector::default();
526 let list = TraceEventQueueList::new_for_testing(2, inspector.root());
527 assert_data_tree!(inspector, root: {
528 tracefs: {
529 buffer_size_kb: (DEFAULT_RING_BUFFER_SIZE_BYTES / 1024) as u64,
530 total_capacity_bytes: (DEFAULT_RING_BUFFER_SIZE_BYTES * 2) as u64,
531 }
532 });
533
534 list.set_buffer_size_kb(4096).expect("set buffer size");
537 list.set_buffer_size_kb(1024).expect("set buffer size");
538 assert_data_tree!(inspector, root: {
539 tracefs: {
540 buffer_size_kb: 1024u64,
541 total_capacity_bytes: (1024 * 1024 * 2) as u64,
542 }
543 });
544 }
545
546 #[fuchsia::test]
547 fn create_trace_event() {
548 let event = TraceEvent::new(1234, b"B|1234|slice_name".len());
550 let event_size = event.size();
551 assert_eq!(event_size, 42);
552 }
553
554 #[fuchsia::test]
556 fn single_trace_event_fails_read() {
557 let queue = TraceEventQueue::new(0).expect("create queue");
558 queue.enable().expect("enable queue");
559 let data = b"B|1234|slice_name";
561 let event = TraceEvent::new(1234, data.len());
562
563 let result = queue.push_event(event, data);
565 assert!(result.is_ok());
566 assert_eq!(result.ok().expect("delta").into_nanos(), 0);
567
568 let mut buffer = VecOutputBuffer::new(*PAGE_SIZE as usize);
569 assert_eq!(queue.read(&mut buffer), error!(EAGAIN));
570 }
571
572 #[fuchsia::test]
573 fn page_overflow() {
574 let queue = TraceEventQueue::new(0).expect("create queue");
575 let queue_start_timestamp = queue.enable().expect("enable queue");
576
577 let pid = 1234;
578 let data = b"B|1234|loooooooooooooooooooooooooooooooooooooooooooooooooooooooooo\
579 ooooooooooooooooooooooooooooooooooooooooooooooooooooooooongevent";
580 let expected_event = TraceEvent::new(pid, data.len());
581 assert_eq!(expected_event.size(), 155);
582
583 let events_per_page =
584 (*PAGE_SIZE as usize - LocklessRingBuffer::PAGE_HEADER_SIZE) / expected_event.size();
585
586 for i in 0..=events_per_page {
588 let event = TraceEvent::new(pid, data.len());
589 let result = queue.push_event(event, data);
590 assert!(result.is_ok());
591 let delta = result.ok().expect("delta").into_nanos();
592 if i == 0 || i == events_per_page {
596 assert_eq!(delta, 0);
597 } else {
598 assert!(delta > 0);
599 }
600 }
601
602 let mut buffer = VecOutputBuffer::new(*PAGE_SIZE as usize);
604 assert_eq!(queue.read(&mut buffer), Ok(*PAGE_SIZE as usize));
605 assert_eq!(buffer.bytes_written() as u64, *PAGE_SIZE);
606
607 let actual_ts_bytes = &buffer.data()[0..8];
609 let actual_ts = u64::from_le_bytes(actual_ts_bytes.try_into().unwrap());
610 assert!(actual_ts >= queue_start_timestamp.into_nanos() as u64);
611
612 let actual_size_bytes = &buffer.data()[8..16];
614 let expected_size_bytes = &((expected_event.size() * events_per_page) as u64).to_le_bytes();
615 assert_eq!(actual_size_bytes, expected_size_bytes);
616
617 let mut buffer = VecOutputBuffer::new(*PAGE_SIZE as usize);
619 assert_eq!(queue.read(&mut buffer), error!(EAGAIN));
620 }
621
622 #[fuchsia::test]
629 fn concurrent_enable_disable_keeps_list_consistent() {
630 let list = TraceEventQueueList::new_for_testing(4, &fuchsia_inspect::Node::default());
631 for _ in 0..200 {
632 let barrier = Arc::new(std::sync::Barrier::new(2));
633 let enabler = {
634 let list = Arc::clone(&list);
635 let barrier = Arc::clone(&barrier);
636 std::thread::spawn(move || {
637 barrier.wait();
638 list.enable().unwrap();
639 })
640 };
641 barrier.wait();
642 list.disable().unwrap();
643 enabler.join().unwrap();
644
645 let enabled = list.is_enabled();
646 for queue in &list.queues {
647 assert_eq!(queue.ring_buffer.read().is_enabled(), enabled);
648 }
649 }
650 }
651}