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);
    }
}