Fix signal handler race condition on metrics.write()

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() {

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

src/logger/src/metrics.rs

@@ -134,10 +134,19 @@ impl<T: Serialize> Metrics<T> {
     /// 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<bool, MetricsError> {
         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.

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<sock_filter> {

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()
 

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)