1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 100 101 102 103 104 105 106 107 108 109 110 111 112 113 114 115 116 117 118 119 120 121 122 123 124 125 126 127 128 129 130 131 132 133 134 135 136 137 138 139 140 141 142 143 144 145 146 147 148 149 150 151 152 153 154 155 156 157 158 159 160 161 162 163 164 165 166 167 168 169 170 171 172 173 174 175 176 177 178 179 180 181 182 183 184 185 186 187 188 189 190 191 192 193 194 195 196 197 198 199 200 201 202 203 204 205 206 207 208 209 210 211 212 213 214 215 216 217 218 219 220 221 222 223 224 225 226 227 228 229 230 231 232 233 234 235 236 237 238 239 240 241 242 243 244 245 246 247 248 249 250 251 252 253 254 255 256 257 258 259 260 261 262 263 264 265 266 267 268 269 270 271 272 273 274 275 276 277 278 279 280 281 282 283 284 285 286 287 288 289 290 291 292 293 294 295 296 297 298 299 300 301 302 303 304 305 306 307 308 309 310 311 312 313 314 315 316 317
// Copyright 2022 The ChromiumOS Authors
// Use of this source code is governed by a BSD-style license that can be
// found in the LICENSE file.
#![deny(missing_docs)]
use std::fs::File;
use std::fs::OpenOptions;
use std::io::Write;
use std::os::unix::io::AsRawFd;
use std::path::Path;
use base::error;
use base::RawDescriptor;
use sync::Mutex;
static TRACE_MARKER_FILE: Mutex<Option<File>> = Mutex::new(None);
#[macro_export]
/// This macro is used as a placeholder to let us iterate over the compile-time
/// allocated vector of categories when we statically initialize it.
/// This macro should only be used internally to this crate.
macro_rules! zero_internal {
($x:ident) => {
0
};
}
#[macro_export]
/// This macro expands an expression with its value for easier printing.
/// `expand_fmt_internal!(my_var)` becomes `"(my_var: {:?})"`.
macro_rules! expand_fmt_internal {
($x:expr) => {
std::concat!("(", std::stringify!($x), ": {:?})")
};
}
#[macro_export]
/// Macro used to handle fd permanency across jailed devices.
/// If we run crosvm without `--disable-sandbox`, we need to add the `trace_marker`
/// file descriptor to the list of file descriptors allowed to be accessed by the
/// sandboxed process. We call this macro to add the file descriptor to the list
/// of `keep_rds` that the process is allowed to access every time we jail.
macro_rules! push_descriptors {
($fd_vec:expr) => {
$crate::push_descriptors_internal($fd_vec);
};
}
#[macro_export]
/// Prints a single non-scoped message without creating a trace context.
/// The tagged variant lets us enable or disable individual categories.
macro_rules! trace_simple_print {
($category: ident, $($t:tt)+) => {{
if($crate::ENABLED_CATEGORIES[$crate::TracedCategories::$category as usize].load(std::sync::atomic::Ordering::Relaxed)) {
$crate::trace_simple_print!($($t)*);
}
}};
($($t:tt)*) => {{
$crate::trace_simple_print_internal(std::format!($($t)*));
}};
}
/// Platform-specific implementation of the `push_descriptors!` macro. If the
/// `trace_marker` file has been initialized properly, it adds its file descriptor
/// to the list of file descriptors that are allowed to be accessed when the process
/// is jailed in the sandbox.
///
/// # Arguments
///
/// * `keep_rds` - List of file descriptors that will be accessible after jailing
pub fn push_descriptors_internal(keep_rds: &mut Vec<RawDescriptor>) {
if let Some(file) = TRACE_MARKER_FILE.lock().as_ref() {
let fd = file.as_raw_fd();
if !keep_rds.contains(&fd) {
keep_rds.push(fd);
}
}
}
#[macro_export]
/// Macro used to set up the trace environment categories. It takes a variable
/// number of arguments in pairs of category, boolean value on whether or not the
/// tracing category is enabled at compile time.
///
/// # Example usage
///
/// ```ignore
/// setup_trace_marker!(
/// (Category1, true),
/// (Category2, false)
/// );
/// ```
///
/// Categories that are enabled will have their events traced at runtime via
/// `trace_event_begin!()`, `trace_event_end!()`, or `trace_event!()` scoped tracing.
/// The categories that are marked as false will have their events skipped.
macro_rules! setup_trace_marker {
($(($cat:ident, $enabled:literal)),+) => {
#[allow(non_camel_case_types, missing_docs)]
/// The tracing categories that the trace_marker backend supports.
pub enum TracedCategories {
$($cat,)+
/// Hacky way to get the count of how many tracing categories we have in total.
CATEGORY_COUNT,
}
/// Vector counting how many tracing event contexts are running for each category.
pub static CATEGORY_COUNTER: [std::sync::atomic::AtomicI64; TracedCategories::CATEGORY_COUNT as usize] = [
$(
// Note, we pass $cat to the zero_internal! macro here, which always just returns
// 0, because it's impossible to iterate over $cat unless $cat is used.
std::sync::atomic::AtomicI64::new(zero_internal!($cat)),
)+
];
/// Vector used to test if a category is enabled or not for tracing.
pub static ENABLED_CATEGORIES: [std::sync::atomic::AtomicBool; TracedCategories::CATEGORY_COUNT as usize] = [
$(
std::sync::atomic::AtomicBool::new($enabled),
)+
];
/// Sequential identifier for scoped trace events. This unique identifier is incremented
/// for each new `trace_event()` call.
pub static EVENT_COUNTER: std::sync::atomic::AtomicU64 =
std::sync::atomic::AtomicU64::new(0);
}
}
#[macro_export]
/// Returns a Trace object with a new name and index and traces its enter state, if the
/// given category identifier is enabled. Extra args can be provided for easier debugging.
/// Upon exiting its scope, it is automatically collected and its exit gets traced.
///
/// If the category identifier is not enabled for this event, nothing happens and the trace
/// event is skipped.
///
/// # Example usage
///
/// ```ignore
/// {
/// let _trace = trace_event!(Category, "exec", param1, param2);
///
/// // ... Rest of code ...
///
/// // End of `_trace`'s lifetime so `trace_event_end` is called.
/// }
/// ```
///
/// This will output in `trace_marker`:
///
/// - `$uid: $category Enter: exec - (param1: ...)(param2: ...)`
///
/// and when _trace runs out of scope, it will output:
///
/// - `$uid: Exit: exec`
///
/// where `$uid` will be the same unique value across those two events.
macro_rules! trace_event {
($category:ident, $name:literal, $($arg:expr),+) => {{
if($crate::ENABLED_CATEGORIES[$crate::TracedCategories::$category as usize].load(std::sync::atomic::Ordering::Relaxed)) {
$crate::trace_event_begin!($category);
let index = $crate::EVENT_COUNTER.fetch_add(1, std::sync::atomic::Ordering::SeqCst);
$crate::trace_simple_print!($category,
"{} {} Enter: {} - {}",
index,
std::stringify!($category),
$name,
// Creates a formatted list for each argument and their
// values.
std::format_args!(std::concat!($($crate::expand_fmt_internal!($arg),)*), $($arg),*));
Some($crate::Trace::new(index, $name, std::stringify!($category), $crate::TracedCategories::$category as usize))
} else {
None
}
}};
($category:ident, $name:expr) => {{
if($crate::ENABLED_CATEGORIES[$crate::TracedCategories::$category as usize].load(std::sync::atomic::Ordering::Relaxed)) {
$crate::trace_event_begin!($category);
let index = $crate::EVENT_COUNTER.fetch_add(1, std::sync::atomic::Ordering::SeqCst);
$crate::trace_simple_print!($category,
"{} {} Enter: {}", index, std::stringify!($category), $name);
Some($crate::Trace::new(index, $name, std::stringify!($category), $crate::TracedCategories::$category as usize))
} else {
None
}
}};
}
#[macro_export]
/// Begins a tracing event context in the given category, it increases the counter
/// of the currently traced events for that category by one.
///
/// # Arguments
///
/// * `category` - Identifier name of the category.
macro_rules! trace_event_begin {
($category:ident) => {
$crate::CATEGORY_COUNTER[$crate::TracedCategories::$category as usize]
.fetch_add(1, std::sync::atomic::Ordering::SeqCst);
};
}
#[macro_export]
/// Ends a tracing event context in the given category, it decreases the counter
/// of the currently traced events for that category by one.
///
/// # Arguments
///
/// * `category` - Identifier name of the category.
macro_rules! trace_event_end {
($category:ident) => {
if ($crate::ENABLED_CATEGORIES[$crate::TracedCategories::$category as usize]
.load(std::sync::atomic::Ordering::Relaxed))
{
$crate::CATEGORY_COUNTER[$crate::TracedCategories::$category as usize]
.fetch_sub(1, std::sync::atomic::Ordering::SeqCst);
}
};
($category_id:expr) => {
if ($crate::ENABLED_CATEGORIES[$category_id as usize]
.load(std::sync::atomic::Ordering::Relaxed))
{
$crate::CATEGORY_COUNTER[$category_id as usize]
.fetch_sub(1, std::sync::atomic::Ordering::SeqCst);
}
};
}
// List of categories that can be enabled.
// If a category is marked as disabled here, no events will be processed for it.
setup_trace_marker!(
(VirtioFs, true),
(VirtioNet, true),
(USB, true),
(gpu_display, true),
(VirtioBlk, true),
(VirtioScsi, true)
);
/// Platform-specific implementation of the `trace_simple_print!` macro. If tracing
/// is enabled on the system, it writes the given message to the `trace_marker` file.
///
/// # Arguments
///
/// * `message` - The message to be written
pub fn trace_simple_print_internal(message: String) {
// In case tracing is not working or the trace marker file is None we can
// just ignore this. We don't need to handle the error here.
if let Some(file) = TRACE_MARKER_FILE.lock().as_mut() {
// We ignore the error here in case write!() fails, because the trace
// marker file would be normally closed by the system unless we are
// actively tracing the runtime. It is not an error.
let _ = write!(file, "{}", message);
};
}
/// Initializes the trace_marker backend. It attepts to open the `trace_marker`
/// file and keep a reference that can be shared throughout the lifetime of the
/// crosvm process.
///
/// If tracefs is not available on the system or the file cannot be opened,
/// tracing will not work but the crosvm process will still continue execution
/// without tracing.
pub fn init() {
let mut trace_marker_file = TRACE_MARKER_FILE.lock();
if trace_marker_file.is_some() {
return;
}
let path = Path::new("/sys/kernel/tracing/trace_marker");
let file = match OpenOptions::new().read(false).write(true).open(path) {
Ok(f) => f,
Err(e) => {
error!(
"Failed to open {}: {}. Tracing will not work.",
path.display(),
e
);
return;
}
};
*trace_marker_file = Some(file);
}
/// A trace context obtained from a `trace_event!()` call.
pub struct Trace {
/// Unique identifier for the specific event.
identifier: u64,
/// Name of the trace event.
name: String,
/// Category name to which the event belongs.
category: String,
/// Category ID to which the event belongs.
category_id: usize,
}
impl Trace {
/// Returns a Trace object with the given name, id, and category
pub fn new(identifier: u64, name: &str, category: &str, category_id: usize) -> Self {
Trace {
identifier,
name: name.to_string(),
category: category.to_string(),
category_id,
}
}
}
impl Drop for Trace {
fn drop(&mut self) {
trace_simple_print!("{} {} Exit: {}", self.identifier, self.category, self.name);
trace_event_end!(self.category_id);
}
}