shadow_shim/
shimlogger.rs

1use core::fmt::Write;
2use core::time::Duration;
3
4use formatting_nostd::{BorrowedFdWriter, FormatBuffer};
5use rustix::fd::BorrowedFd;
6use shadow_shim_helper_rs::util::time::TimeParts;
7
8/// For internal use; writes to an internal buffer, flushing to stdout
9/// when the buffer fills or the object is dropped.
10struct ShimLoggerWriter {
11    buffer: FormatBuffer<1000>,
12    stdout: BorrowedFdWriter<'static>,
13}
14
15impl ShimLoggerWriter {
16    pub fn new() -> Self {
17        Self {
18            buffer: FormatBuffer::new(),
19            stdout: BorrowedFdWriter::new(unsafe {
20                BorrowedFd::borrow_raw(linux_raw_sys::general::STDOUT_FILENO.try_into().unwrap())
21            }),
22        }
23    }
24
25    pub fn flush(&mut self) {
26        self.stdout.write_str(self.buffer.as_str()).unwrap();
27        self.buffer.reset();
28    }
29}
30
31impl core::fmt::Write for ShimLoggerWriter {
32    fn write_str(&mut self, s: &str) -> Result<(), core::fmt::Error> {
33        if s.len() > self.buffer.capacity_remaining() {
34            // Flush to make room and keep output FIFO.
35            self.flush();
36        }
37        if s.len() > self.buffer.capacity_remaining() {
38            // There will never be enough room. Write directly to stdout.
39            self.stdout.write_str(s)
40        } else {
41            // Write to buffer. Should be impossible to fail.
42            self.buffer.write_str(s)
43        }
44    }
45}
46
47impl Drop for ShimLoggerWriter {
48    fn drop(&mut self) {
49        self.flush();
50    }
51}
52
53/// Implementation of `log::Log` for use in the shim.
54///
55/// Includes some shim related metadata (such as simulation time), is no_std,
56/// and is careful to only make inlined syscalls to avoid getting intercepted by
57/// the shim's seccomp filter.
58pub struct ShimLogger {}
59
60impl ShimLogger {
61    /// Install a `ShimLogger` as  the logging backend in the Rust `log` crate.
62    /// Should only be called once.
63    pub fn install(log_level: log::LevelFilter) {
64        // log::set_logger requires a logger with a static lifetime.
65        const SHIM_LOGGER: ShimLogger = ShimLogger {};
66
67        log::set_max_level(log_level);
68        log::set_logger(&SHIM_LOGGER).unwrap();
69    }
70}
71
72impl log::Log for ShimLogger {
73    fn enabled(&self, metadata: &log::Metadata) -> bool {
74        metadata.level() <= log::max_level()
75    }
76
77    fn log(&self, record: &log::Record) {
78        if !self.enabled(record.metadata()) {
79            return;
80        }
81
82        let mut writer = ShimLoggerWriter::new();
83
84        match crate::global_manager_shmem::try_get() {
85            Some(m) => {
86                // rustix's `clock_gettime` goes through VDSO, which is overwritten with our trampoline,
87                // which would end up trying to log and recurse.
88                // `linux_api`'s `clock_gettime` always makes the syscall, which is what we want.
89                let now = linux_api::time::clock_gettime(linux_api::time::ClockId::CLOCK_REALTIME)
90                    .unwrap();
91
92                let now = Duration::from_secs(now.tv_sec.try_into().unwrap())
93                    + Duration::from_nanos(now.tv_nsec.try_into().unwrap());
94
95                let start = Duration::from_micros(m.log_start_time_micros.try_into().unwrap());
96                let elapsed = now - start;
97                let parts = TimeParts::from_nanos(elapsed.as_nanos());
98                write!(&mut writer, "{} ", parts.fmt_hr_min_sec_nano(),).unwrap();
99            }
100            None => {
101                writer.write_str("? ").unwrap();
102            }
103        }
104
105        match crate::simtime() {
106            Some(t) => {
107                let t = Duration::from(t);
108                let parts = TimeParts::from_nanos(t.as_nanos());
109                write!(&mut writer, "[{}] ", parts.fmt_hr_min_sec_nano(),).unwrap();
110            }
111            None => {
112                writer.write_str("[?] ").unwrap();
113            }
114        };
115
116        write!(
117            &mut writer,
118            "[shd-shim] [{level}] [{file_name}:{line_number}] [{function_name}] ",
119            level = record.level(),
120            file_name = record.file().unwrap_or("?"),
121            line_number = record.line().unwrap_or(0),
122            function_name = record.module_path().unwrap_or("?"),
123        )
124        .unwrap();
125        core::fmt::write(&mut writer, *record.args()).unwrap();
126        writer.write_char('\n').unwrap();
127    }
128
129    fn flush(&self) {}
130}
131
132pub mod export {
133    use super::*;
134
135    #[unsafe(no_mangle)]
136    pub extern "C-unwind" fn shimlogger_install(level: logger::LogLevel) {
137        let level = log_c2rust::c_to_rust_log_level(level).unwrap();
138        ShimLogger::install(level.to_level_filter());
139    }
140}