1 // Copyright © 2022 Intel Corporation 2 // 3 // SPDX-License-Identifier: Apache-2.0 4 // 5 6 #![allow(static_mut_refs)] 7 8 use std::collections::HashMap; 9 use std::fs::File; 10 use std::io::Write; 11 use std::sync::atomic::{AtomicU64, Ordering}; 12 use std::sync::{Arc, Mutex}; 13 use std::time::{Duration, Instant}; 14 15 use once_cell::unsync::OnceCell; 16 use serde::Serialize; 17 18 #[derive(Debug)] 19 struct Tracer { 20 events: Arc<Mutex<HashMap<String, Vec<TraceEvent>>>>, 21 thread_depths: HashMap<String, Arc<AtomicU64>>, 22 start: Instant, 23 } 24 25 impl Tracer { 26 fn new() -> Self { 27 Self { 28 events: Arc::new(Mutex::new(HashMap::default())), 29 start: Instant::now(), 30 thread_depths: HashMap::default(), 31 } 32 } 33 34 fn end(&self) { 35 let end = Instant::now(); 36 // SAFETY: FFI call 37 let path = format!("cloud-hypervisor-{}.trace", unsafe { libc::getpid() }); 38 let mut file = File::create(&path).unwrap(); 39 40 #[derive(Serialize)] 41 struct TraceReport { 42 duration: Duration, 43 events: Arc<Mutex<HashMap<String, Vec<TraceEvent>>>>, 44 } 45 46 let trace_report = TraceReport { 47 duration: end.duration_since(self.start), 48 events: self.events.clone(), 49 }; 50 51 serde_json::to_writer_pretty(&file, &trace_report).unwrap(); 52 53 file.flush().unwrap(); 54 55 warn!("Trace output: {}", path); 56 } 57 58 fn add_event(&mut self, event: TraceEvent) { 59 let current = std::thread::current(); 60 let thread_name = current.name().unwrap_or(""); 61 let mut events = self.events.lock().unwrap(); 62 if let Some(thread_events) = events.get_mut(thread_name) { 63 thread_events.push(event); 64 } else { 65 events.insert(thread_name.to_string(), vec![event]); 66 } 67 } 68 69 fn increase_thread_depth(&mut self) { 70 let current = std::thread::current(); 71 let thread_name = current.name().unwrap_or(""); 72 if let Some(depth) = self.thread_depths.get_mut(thread_name) { 73 depth.fetch_add(1, Ordering::SeqCst); 74 } else { 75 self.thread_depths 76 .insert(thread_name.to_string(), Arc::new(AtomicU64::new(0))); 77 } 78 } 79 80 fn decrease_thread_depth(&mut self) { 81 let current = std::thread::current(); 82 let thread_name = current.name().unwrap_or(""); 83 if let Some(depth) = self.thread_depths.get_mut(thread_name) { 84 depth.fetch_sub(1, Ordering::SeqCst); 85 } else { 86 panic!("Unmatched decrease for thread: {thread_name}"); 87 } 88 } 89 90 fn thread_depth(&self) -> u64 { 91 let current = std::thread::current(); 92 let thread_name = current.name().unwrap_or(""); 93 self.thread_depths 94 .get(thread_name) 95 .map(|v| v.load(Ordering::SeqCst)) 96 .unwrap_or_default() 97 } 98 } 99 100 static mut TRACER: OnceCell<Tracer> = OnceCell::new(); 101 102 #[derive(Clone, Debug, Serialize)] 103 struct TraceEvent { 104 timestamp: Duration, 105 event: &'static str, 106 end_timestamp: Option<Duration>, 107 depth: u64, 108 } 109 110 pub fn trace_point_log(event: &'static str) { 111 let trace_event = TraceEvent { 112 // SAFETY: start has been initialised as part of initialising the value of TRACER 113 timestamp: Instant::now().duration_since(unsafe { TRACER.get().unwrap().start }), 114 event, 115 end_timestamp: None, 116 // SAFETY: thread_depth accesses current thread only specific data 117 depth: unsafe { TRACER.get().unwrap().thread_depth() }, 118 }; 119 // SAFETY: add_event accesses current thread only specific data 120 unsafe { 121 TRACER.get_mut().unwrap().add_event(trace_event); 122 } 123 } 124 125 pub struct TraceBlock { 126 start: Instant, 127 event: &'static str, 128 } 129 130 impl TraceBlock { 131 pub fn new(event: &'static str) -> Self { 132 // SAFETY: increase_thread_depth accesses current thread only specific data 133 unsafe { 134 TRACER.get_mut().unwrap().increase_thread_depth(); 135 } 136 Self { 137 start: Instant::now(), 138 event, 139 } 140 } 141 } 142 143 impl Drop for TraceBlock { 144 fn drop(&mut self) { 145 // SAFETY: start has been initialised as part of initialising the value of TRACER 146 let start = unsafe { TRACER.get().unwrap().start }; 147 let trace_event = TraceEvent { 148 timestamp: self.start.duration_since(start), 149 event: self.event, 150 end_timestamp: Some(Instant::now().duration_since(start)), 151 // SAFETY: thread_depth() returns a number local to the current thread 152 depth: unsafe { TRACER.get().unwrap().thread_depth() }, 153 }; 154 // SAFETY: add_event and decrease_thread_depth access current thread only specific data 155 unsafe { 156 TRACER.get_mut().unwrap().add_event(trace_event); 157 TRACER.get_mut().unwrap().decrease_thread_depth(); 158 } 159 } 160 } 161 162 #[macro_export] 163 macro_rules! trace_point { 164 ($event:expr) => { 165 $crate::trace_point_log($event) 166 }; 167 } 168 169 #[macro_export] 170 macro_rules! trace_scoped { 171 ($event:expr) => { 172 let _trace_scoped = $crate::TraceBlock::new($event); 173 }; 174 } 175 176 pub fn end() { 177 // SAFETY: this is called after all other threads end 178 unsafe { TRACER.get().unwrap().end() } 179 } 180 181 pub fn start() { 182 // SAFETY: this is called before other threads start 183 unsafe { TRACER.set(Tracer::new()).unwrap() } 184 } 185