diff --git a/src/firecracker/src/main.rs b/src/firecracker/src/main.rs index 44a5c9c7075..0b822ebd9fb 100644 --- a/src/firecracker/src/main.rs +++ b/src/firecracker/src/main.rs @@ -11,7 +11,7 @@ use std::process; use std::sync::{Arc, Mutex}; use event_manager::SubscriberOps; -use logger::{error, info, IncMetric, ProcessTimeReporter, LOGGER, METRICS}; +use logger::{error, info, ProcessTimeReporter, StoreMetric, LOGGER, METRICS}; use mmds::MMDS; use seccompiler::BpfThreadMap; use snapshot::Snapshot; @@ -96,7 +96,7 @@ fn main_exitable() -> ExitCode { ); } - METRICS.vmm.panic_count.inc(); + METRICS.vmm.panic_count.store(1); // Write the metrics before aborting. if let Err(e) = METRICS.write() { diff --git a/src/firecracker/src/metrics.rs b/src/firecracker/src/metrics.rs index ddca21a6d0b..72000dcdc5d 100644 --- a/src/firecracker/src/metrics.rs +++ b/src/firecracker/src/metrics.rs @@ -46,8 +46,6 @@ impl PeriodicMetrics { } fn write_metrics(&mut self) { - // Please note that, if METRICS has no output file configured yet, it will write to - // stdout, so metrics writing will interfere with console output. if let Err(e) = METRICS.write() { METRICS.logger.missed_metrics_count.inc(); error!("Failed to write metrics: {}", e); diff --git a/src/logger/src/metrics.rs b/src/logger/src/metrics.rs index 99601702bf3..37b9a35a1d6 100644 --- a/src/logger/src/metrics.rs +++ b/src/logger/src/metrics.rs @@ -134,10 +134,19 @@ impl Metrics { /// Upon success, the function will return `True` (if metrics system was initialized and metrics /// were successfully written to disk) or `False` (if metrics system was not yet initialized). /// - /// This function is supposed to be called only from a single thread and + /// This function is usually supposed to be called only from a single thread and /// is not meant to be used in a multithreaded scenario. The reason /// `metrics_buf` is enclosed in a `Mutex` is that `lazy_static` enforces /// thread-safety on all its members. + /// The only exception is for signal handlers that result in process exit, which may be run on + /// any thread. To prevent the race condition present in the serialisation step of + /// SharedIncMetrics, deadly signals use SharedStoreMetrics instead (which have a thread-safe + /// serialise implementation). + /// The only known caveat is that other metrics may not be properly written before exiting from + /// a signal handler. We make this compromise since the process will be killed anyway and the + /// important metric in this case is the signal one. + /// The alternative is to hold a Mutex over the entire function call, but this increases the + /// known deadlock potential. pub fn write(&self) -> Result { if self.is_initialized.load(Ordering::Relaxed) { match serde_json::to_string(&self.app_metrics) { @@ -674,7 +683,7 @@ impl RtcEvents for RTCDeviceMetrics { #[derive(Default, Serialize)] pub struct SeccompMetrics { /// Number of errors inside the seccomp filtering. - pub num_faults: SharedIncMetric, + pub num_faults: SharedStoreMetric, } /// Metrics specific to the UART device. @@ -695,22 +704,25 @@ pub struct SerialDeviceMetrics { } /// Metrics related to signals. +/// Deadly signals must be of `SharedStoreMetric` type, since they can ever be either 0 or 1. +/// This avoids a tricky race condition caused by the unatomic serialize method of +/// `SharedIncMetric`, between two threads calling `METRICS.write()`. #[derive(Default, Serialize)] pub struct SignalMetrics { /// Number of times that SIGBUS was handled. - pub sigbus: SharedIncMetric, + pub sigbus: SharedStoreMetric, /// Number of times that SIGSEGV was handled. - pub sigsegv: SharedIncMetric, + pub sigsegv: SharedStoreMetric, /// Number of times that SIGXFSZ was handled. - pub sigxfsz: SharedIncMetric, + pub sigxfsz: SharedStoreMetric, /// Number of times that SIGXCPU was handled. - pub sigxcpu: SharedIncMetric, + pub sigxcpu: SharedStoreMetric, /// Number of times that SIGPIPE was handled. pub sigpipe: SharedIncMetric, /// Number of times that SIGHUP was handled. - pub sighup: SharedIncMetric, + pub sighup: SharedStoreMetric, /// Number of times that SIGILL was handled. - pub sigill: SharedIncMetric, + pub sigill: SharedStoreMetric, } /// Metrics specific to VCPUs' mode of functioning. @@ -736,7 +748,7 @@ pub struct VmmMetrics { /// Number of device related events received for a VM. pub device_events: SharedIncMetric, /// Metric for signaling a panic has occurred. - pub panic_count: SharedIncMetric, + pub panic_count: SharedStoreMetric, } /// Vsock-related metrics. diff --git a/src/vmm/src/signal_handler.rs b/src/vmm/src/signal_handler.rs index d39719f00bd..6ae19fdb600 100644 --- a/src/vmm/src/signal_handler.rs +++ b/src/vmm/src/signal_handler.rs @@ -6,7 +6,7 @@ use libc::{ }; use crate::{ExitCode, FC_EXIT_CODE_UNEXPECTED_ERROR}; -use logger::{error, IncMetric, METRICS}; +use logger::{error, IncMetric, StoreMetric, METRICS}; use utils::signal::register_signal_handler; // The offset of `si_syscall` (offending syscall identifier) within the siginfo structure @@ -39,7 +39,7 @@ macro_rules! generate_handler { if num != si_signo || num != $signal_name { exit_with_code(FC_EXIT_CODE_UNEXPECTED_ERROR); } - $signal_metric.inc(); + $signal_metric.store(1); error!( "Shutting down VM after intercepting signal {}, code {}.", @@ -209,31 +209,31 @@ mod tests { let filter = make_test_seccomp_bpf_filter(); assert!(seccompiler::apply_filter(&filter).is_ok()); - assert_eq!(METRICS.seccomp.num_faults.count(), 0); + assert_eq!(METRICS.seccomp.num_faults.fetch(), 0); // Call the forbidden `SYS_mkdirat`. unsafe { libc::syscall(libc::SYS_mkdirat, "/foo/bar\0") }; // Call SIGBUS signal handler. - assert_eq!(METRICS.signals.sigbus.count(), 0); + assert_eq!(METRICS.signals.sigbus.fetch(), 0); unsafe { syscall(libc::SYS_kill, process::id(), SIGBUS); } // Call SIGSEGV signal handler. - assert_eq!(METRICS.signals.sigsegv.count(), 0); + assert_eq!(METRICS.signals.sigsegv.fetch(), 0); unsafe { syscall(libc::SYS_kill, process::id(), SIGSEGV); } // Call SIGXFSZ signal handler. - assert_eq!(METRICS.signals.sigxfsz.count(), 0); + assert_eq!(METRICS.signals.sigxfsz.fetch(), 0); unsafe { syscall(libc::SYS_kill, process::id(), SIGXFSZ); } // Call SIGXCPU signal handler. - assert_eq!(METRICS.signals.sigxcpu.count(), 0); + assert_eq!(METRICS.signals.sigxcpu.fetch(), 0); unsafe { syscall(libc::SYS_kill, process::id(), SIGXCPU); } @@ -245,13 +245,13 @@ mod tests { } // Call SIGHUP signal handler. - assert_eq!(METRICS.signals.sighup.count(), 0); + assert_eq!(METRICS.signals.sighup.fetch(), 0); unsafe { syscall(libc::SYS_kill, process::id(), SIGHUP); } // Call SIGILL signal handler. - assert_eq!(METRICS.signals.sigill.count(), 0); + assert_eq!(METRICS.signals.sigill.fetch(), 0); unsafe { syscall(libc::SYS_kill, process::id(), SIGILL); } @@ -268,17 +268,17 @@ mod tests { // tests, so we use this as an heuristic to decide if we check the assertion. if cpu_count() > 1 { // The signal handler should let the program continue during unit tests. - assert!(METRICS.seccomp.num_faults.count() >= 1); + assert!(METRICS.seccomp.num_faults.fetch() >= 1); } - assert!(METRICS.signals.sigbus.count() >= 1); - assert!(METRICS.signals.sigsegv.count() >= 1); - assert!(METRICS.signals.sigxfsz.count() >= 1); - assert!(METRICS.signals.sigxcpu.count() >= 1); + assert!(METRICS.signals.sigbus.fetch() >= 1); + assert!(METRICS.signals.sigsegv.fetch() >= 1); + assert!(METRICS.signals.sigxfsz.fetch() >= 1); + assert!(METRICS.signals.sigxcpu.fetch() >= 1); assert!(METRICS.signals.sigpipe.count() >= 1); - assert!(METRICS.signals.sighup.count() >= 1); + assert!(METRICS.signals.sighup.fetch() >= 1); // Workaround to GitHub issue 2216. #[cfg(not(target_arch = "aarch64"))] - assert!(METRICS.signals.sigill.count() >= 1); + assert!(METRICS.signals.sigill.fetch() >= 1); } fn make_test_seccomp_bpf_filter() -> Vec { diff --git a/tests/integration_tests/build/test_coverage.py b/tests/integration_tests/build/test_coverage.py index 0eb3b73198c..6fd70244ee4 100644 --- a/tests/integration_tests/build/test_coverage.py +++ b/tests/integration_tests/build/test_coverage.py @@ -31,7 +31,7 @@ if utils.is_io_uring_supported(): COVERAGE_DICT = {"Intel": 85.09, "AMD": 84.51, "ARM": 84.21} else: - COVERAGE_DICT = {"Intel": 82.03, "AMD": 81.5, "ARM": 81.10} + COVERAGE_DICT = {"Intel": 82.03, "AMD": 81.5, "ARM": 81.16} PROC_MODEL = proc.proc_type() diff --git a/tests/integration_tests/security/test_custom_seccomp.py b/tests/integration_tests/security/test_custom_seccomp.py index 515effd2282..99f0921ed47 100644 --- a/tests/integration_tests/security/test_custom_seccomp.py +++ b/tests/integration_tests/security/test_custom_seccomp.py @@ -205,7 +205,7 @@ def test_failing_filter(test_microvm_with_api): for line in lines: num_faults += json.loads(line)["seccomp"]["num_faults"] - assert num_faults == 1 + assert num_faults >= 1 # assert that the process was killed assert not psutil.pid_exists(test_microvm.jailer_clone_pid)