Merge "pvmfw: Replace calls to emergency_write_str"
diff --git a/tests/helper/src/java/com/android/microdroid/test/common/MetricsProcessor.java b/tests/helper/src/java/com/android/microdroid/test/common/MetricsProcessor.java
index 42eb6a1..dd68d6a 100644
--- a/tests/helper/src/java/com/android/microdroid/test/common/MetricsProcessor.java
+++ b/tests/helper/src/java/com/android/microdroid/test/common/MetricsProcessor.java
@@ -50,8 +50,8 @@
         Collections.sort(values);
 
         double sum = 0;
-        double min = Double.MAX_VALUE;
-        double max = Double.MIN_VALUE;
+        double min = Double.POSITIVE_INFINITY;
+        double max = Double.NEGATIVE_INFINITY;
         for (Double d : values) {
             sum += d;
             if (min > d) min = d;
@@ -63,7 +63,7 @@
             sqSum += (d - avg) * (d - avg);
         }
         double stdDev = Math.sqrt(sqSum / (values.size() - 1));
-        double median = Double.MIN_VALUE;
+        double median = Double.NaN;
         if (values.size() > 0) {
             int rank = values.size() / 2;
             if (values.size() % 2 == 0) {
diff --git a/virtualizationservice/src/aidl.rs b/virtualizationservice/src/aidl.rs
index e0b78ba..3888df2 100644
--- a/virtualizationservice/src/aidl.rs
+++ b/virtualizationservice/src/aidl.rs
@@ -26,13 +26,13 @@
     IVirtualizationServiceInternal::IVirtualizationServiceInternal,
 };
 use android_system_virtualmachineservice::aidl::android::system::virtualmachineservice::IVirtualMachineService::VM_TOMBSTONES_SERVICE_PORT;
-use anyhow::{anyhow, bail, Context, Result};
+use anyhow::{anyhow, ensure, Context, Result};
 use binder::{self, BinderFeatures, ExceptionCode, Interface, LazyServiceGuard, Status, Strong};
 use libc::VMADDR_CID_HOST;
 use log::{error, info, warn};
 use rustutils::system_properties;
 use std::collections::HashMap;
-use std::fs::{create_dir, read_dir, remove_dir, remove_file, set_permissions, Permissions};
+use std::fs::{create_dir, remove_dir_all, set_permissions, Permissions};
 use std::io::{Read, Write};
 use std::os::unix::fs::PermissionsExt;
 use std::os::unix::raw::{pid_t, uid_t};
@@ -268,20 +268,10 @@
 /// Removes a directory owned by a different user by first changing its owner back
 /// to VirtualizationService.
 pub fn remove_temporary_dir(path: &PathBuf) -> Result<()> {
-    if !path.as_path().is_dir() {
-        bail!("Path {:?} is not a directory", path);
-    }
+    ensure!(path.as_path().is_dir(), "Path {:?} is not a directory", path);
     chown(path, Some(Uid::current()), None)?;
     set_permissions(path, Permissions::from_mode(0o700))?;
-    remove_temporary_files(path)?;
-    remove_dir(path)?;
-    Ok(())
-}
-
-pub fn remove_temporary_files(path: &PathBuf) -> Result<()> {
-    for dir_entry in read_dir(path)? {
-        remove_file(dir_entry?.path())?;
-    }
+    remove_dir_all(path)?;
     Ok(())
 }
 
diff --git a/vmbase/README.md b/vmbase/README.md
index 552ac31..7f621fb 100644
--- a/vmbase/README.md
+++ b/vmbase/README.md
@@ -51,12 +51,14 @@
 entry point. Instead, `vmbase` provides a macro to specify your main function:
 
 ```rust
-use vmbase::{main, println};
+use vmbase::{logger, main};
+use log::{info, LevelFilter};
 
 main!(main);
 
 pub fn main(arg0: u64, arg1: u64, arg2: u64, arg3: u64) {
-    println!("Hello world");
+    logger::init(LevelFilter::Info).unwrap();
+    info!("Hello world");
 }
 ```
 
diff --git a/vmbase/example/src/layout.rs b/vmbase/example/src/layout.rs
index 4c3af6d..e660c5f 100644
--- a/vmbase/example/src/layout.rs
+++ b/vmbase/example/src/layout.rs
@@ -17,8 +17,8 @@
 use aarch64_paging::paging::{MemoryRegion, VirtualAddress};
 use core::arch::asm;
 use core::ops::Range;
+use log::info;
 use vmbase::layout;
-use vmbase::println;
 use vmbase::STACK_CHK_GUARD;
 
 /// The first 1 GiB of memory are used for MMIO.
@@ -74,14 +74,14 @@
 
 pub fn print_addresses() {
     let dtb = dtb_range();
-    println!("dtb:        {}..{} ({} bytes)", dtb.start, dtb.end, dtb.end - dtb.start);
+    info!("dtb:        {}..{} ({} bytes)", dtb.start, dtb.end, dtb.end - dtb.start);
     let text = text_range();
-    println!("text:       {}..{} ({} bytes)", text.start, text.end, text.end - text.start);
+    info!("text:       {}..{} ({} bytes)", text.start, text.end, text.end - text.start);
     let rodata = rodata_range();
-    println!("rodata:     {}..{} ({} bytes)", rodata.start, rodata.end, rodata.end - rodata.start);
-    println!("binary end: {}", binary_end());
+    info!("rodata:     {}..{} ({} bytes)", rodata.start, rodata.end, rodata.end - rodata.start);
+    info!("binary end: {}", binary_end());
     let data = data_range();
-    println!(
+    info!(
         "data:       {}..{} ({} bytes, loaded at {})",
         data.start,
         data.end,
@@ -89,9 +89,9 @@
         data_load_address(),
     );
     let bss = bss_range();
-    println!("bss:        {}..{} ({} bytes)", bss.start, bss.end, bss.end - bss.start);
+    info!("bss:        {}..{} ({} bytes)", bss.start, bss.end, bss.end - bss.start);
     let boot_stack = boot_stack_range();
-    println!(
+    info!(
         "boot_stack: {}..{} ({} bytes)",
         boot_stack.start,
         boot_stack.end,
diff --git a/vmbase/example/src/main.rs b/vmbase/example/src/main.rs
index 9ec2dc4..ed0275b 100644
--- a/vmbase/example/src/main.rs
+++ b/vmbase/example/src/main.rs
@@ -34,8 +34,8 @@
 use core::ffi::CStr;
 use fdtpci::PciInfo;
 use libfdt::Fdt;
-use log::{debug, info, trace, LevelFilter};
-use vmbase::{logger, main, println};
+use log::{debug, error, info, trace, warn, LevelFilter};
+use vmbase::{logger, main};
 
 static INITIALISED_DATA: [u32; 4] = [1, 2, 3, 4];
 static mut ZEROED_DATA: [u32; 10] = [0; 10];
@@ -55,7 +55,7 @@
 pub fn main(arg0: u64, arg1: u64, arg2: u64, arg3: u64) {
     logger::init(LevelFilter::Debug).unwrap();
 
-    println!("Hello world");
+    info!("Hello world");
     info!("x0={:#018x}, x1={:#018x}, x2={:#018x}, x3={:#018x}", arg0, arg1, arg2, arg3);
     print_addresses();
     assert_eq!(arg0, dtb_range().start.0 as u64);
@@ -127,6 +127,8 @@
 
     let mut pci_root = unsafe { pci_info.make_pci_root() };
     check_pci(&mut pci_root);
+
+    emit_suppressed_log();
 }
 
 fn check_stack_guard() {
@@ -236,3 +238,21 @@
         ]
     );
 }
+
+macro_rules! log_all_levels {
+    ($msg:literal) => {{
+        error!($msg);
+        warn!($msg);
+        info!($msg);
+        debug!($msg);
+        trace!($msg);
+    }};
+}
+
+fn emit_suppressed_log() {
+    {
+        let _guard = logger::suppress();
+        log_all_levels!("Suppressed message");
+    }
+    log_all_levels!("Unsuppressed message");
+}
diff --git a/vmbase/example/tests/test.rs b/vmbase/example/tests/test.rs
index 8f0eaa5..9088f1a 100644
--- a/vmbase/example/tests/test.rs
+++ b/vmbase/example/tests/test.rs
@@ -24,6 +24,7 @@
 use anyhow::{Context, Error};
 use log::info;
 use std::{
+    collections::{HashSet, VecDeque},
     fs::File,
     io::{self, BufRead, BufReader, Read, Write},
     os::unix::io::FromRawFd,
@@ -89,7 +90,7 @@
         taskProfiles: vec![],
         gdbPort: 0, // no gdb
     });
-    let console = android_log_fd()?;
+    let (handle, console) = android_log_fd()?;
     let (mut log_reader, log_writer) = pipe()?;
     let vm = VmInstance::create(service.as_ref(), &config, Some(console), Some(log_writer), None)
         .context("Failed to create VM")?;
@@ -99,6 +100,7 @@
     // Wait for VM to finish, and check that it shut down cleanly.
     let death_reason = vm.wait_for_death();
     assert_eq!(death_reason, DeathReason::Shutdown);
+    handle.join().unwrap();
 
     // Check that the expected string was written to the log VirtIO console device.
     let expected = "Hello VirtIO console\n";
@@ -109,15 +111,10 @@
     Ok(())
 }
 
-fn android_log_fd() -> io::Result<File> {
+fn android_log_fd() -> Result<(thread::JoinHandle<()>, File), io::Error> {
     let (reader, writer) = pipe()?;
-
-    thread::spawn(|| {
-        for line in BufReader::new(reader).lines() {
-            info!("{}", line.unwrap());
-        }
-    });
-    Ok(writer)
+    let handle = thread::spawn(|| VmLogProcessor::new(reader).run().unwrap());
+    Ok((handle, writer))
 }
 
 fn pipe() -> io::Result<(File, File)> {
@@ -129,3 +126,51 @@
 
     Ok((reader, writer))
 }
+
+struct VmLogProcessor {
+    reader: Option<File>,
+    expected: VecDeque<String>,
+    unexpected: HashSet<String>,
+    had_unexpected: bool,
+}
+
+impl VmLogProcessor {
+    fn messages() -> (VecDeque<String>, HashSet<String>) {
+        let mut expected = VecDeque::new();
+        let mut unexpected = HashSet::new();
+        for log_lvl in ["[ERROR]", "[WARN]", "[INFO]", "[DEBUG]"] {
+            expected.push_back(format!("{log_lvl} Unsuppressed message"));
+            unexpected.insert(format!("{log_lvl} Suppressed message"));
+        }
+        (expected, unexpected)
+    }
+
+    fn new(reader: File) -> Self {
+        let (expected, unexpected) = Self::messages();
+        Self { reader: Some(reader), expected, unexpected, had_unexpected: false }
+    }
+
+    fn verify(&mut self, msg: &str) {
+        if self.expected.front() == Some(&msg.to_owned()) {
+            self.expected.pop_front();
+        }
+        if !self.had_unexpected && self.unexpected.contains(msg) {
+            self.had_unexpected = true;
+        }
+    }
+
+    fn run(mut self) -> Result<(), &'static str> {
+        for line in BufReader::new(self.reader.take().unwrap()).lines() {
+            let msg = line.unwrap();
+            info!("{msg}");
+            self.verify(&msg);
+        }
+        if !self.expected.is_empty() {
+            Err("missing expected log message")
+        } else if self.had_unexpected {
+            Err("unexpected log message")
+        } else {
+            Ok(())
+        }
+    }
+}
diff --git a/vmbase/src/console.rs b/vmbase/src/console.rs
index fabea91..7c8ddf6 100644
--- a/vmbase/src/console.rs
+++ b/vmbase/src/console.rs
@@ -40,14 +40,14 @@
 /// Writes a string to the console.
 ///
 /// Panics if [`init`] was not called first.
-pub fn write_str(s: &str) {
+pub(crate) fn write_str(s: &str) {
     CONSOLE.lock().as_mut().unwrap().write_str(s).unwrap();
 }
 
 /// Writes a formatted string to the console.
 ///
 /// Panics if [`init`] was not called first.
-pub fn write_args(format_args: Arguments) {
+pub(crate) fn write_args(format_args: Arguments) {
     write(CONSOLE.lock().as_mut().unwrap(), format_args).unwrap();
 }
 
@@ -69,20 +69,10 @@
     let _ = write(&mut uart, format_args);
 }
 
-/// Prints the given string to the console.
-///
-/// Panics if the console has not yet been initialised. May hang if used in an exception context;
-/// use `eprint!` instead.
-#[macro_export]
-macro_rules! print {
-    ($($arg:tt)*) => ($crate::console::write_args(format_args!($($arg)*)));
-}
-
 /// Prints the given formatted string to the console, followed by a newline.
 ///
 /// Panics if the console has not yet been initialised. May hang if used in an exception context;
 /// use `eprintln!` instead.
-#[macro_export]
 macro_rules! println {
     () => ($crate::console::write_str("\n"));
     ($($arg:tt)*) => ({
@@ -91,6 +81,8 @@
     );
 }
 
+pub(crate) use println; // Make it available in this crate.
+
 /// Prints the given string to the console in an emergency, such as an exception handler.
 ///
 /// Never panics.
diff --git a/vmbase/src/entry.rs b/vmbase/src/entry.rs
index 1510ae2..8cdfe77 100644
--- a/vmbase/src/entry.rs
+++ b/vmbase/src/entry.rs
@@ -36,12 +36,14 @@
 /// Example:
 ///
 /// ```rust
-/// use vmbase::main;
+/// use vmbase::{logger, main};
+/// use log::{info, LevelFilter};
 ///
 /// main!(my_main);
 ///
 /// fn my_main() {
-///     println!("Hello world");
+///     logger::init(LevelFilter::Info).unwrap();
+///     info!("Hello world");
 /// }
 /// ```
 #[macro_export]
diff --git a/vmbase/src/logger.rs b/vmbase/src/logger.rs
index 5f0f1c2..94dc880 100644
--- a/vmbase/src/logger.rs
+++ b/vmbase/src/logger.rs
@@ -20,27 +20,71 @@
 
 extern crate log;
 
-use super::println;
+use crate::console::println;
+use core::sync::atomic::{AtomicBool, Ordering};
 use log::{LevelFilter, Log, Metadata, Record, SetLoggerError};
 
-struct Logger;
-static LOGGER: Logger = Logger;
+struct Logger {
+    is_enabled: AtomicBool,
+}
+static mut LOGGER: Logger = Logger::new();
+
+impl Logger {
+    const fn new() -> Self {
+        Self { is_enabled: AtomicBool::new(true) }
+    }
+
+    fn swap_enabled(&mut self, enabled: bool) -> bool {
+        self.is_enabled.swap(enabled, Ordering::Relaxed)
+    }
+}
 
 impl Log for Logger {
     fn enabled(&self, _metadata: &Metadata) -> bool {
-        true
+        self.is_enabled.load(Ordering::Relaxed)
     }
 
     fn log(&self, record: &Record) {
-        println!("[{}] {}", record.level(), record.args());
+        if self.enabled(record.metadata()) {
+            println!("[{}] {}", record.level(), record.args());
+        }
     }
 
     fn flush(&self) {}
 }
 
+/// An RAII implementation of a log suppressor. When the instance is dropped, logging is re-enabled.
+pub struct SuppressGuard {
+    old_enabled: bool,
+}
+
+impl SuppressGuard {
+    fn new() -> Self {
+        // Safe because it modifies an atomic.
+        unsafe { Self { old_enabled: LOGGER.swap_enabled(false) } }
+    }
+}
+
+impl Drop for SuppressGuard {
+    fn drop(&mut self) {
+        // Safe because it modifies an atomic.
+        unsafe {
+            LOGGER.swap_enabled(self.old_enabled);
+        }
+    }
+}
+
 /// Initialize vmbase logger with a given max logging level.
 pub fn init(max_level: LevelFilter) -> Result<(), SetLoggerError> {
-    log::set_logger(&LOGGER)?;
+    // Safe because it only sets the global logger.
+    unsafe {
+        log::set_logger(&LOGGER)?;
+    }
     log::set_max_level(max_level);
     Ok(())
 }
+
+/// Suppress logging until the return value goes out of scope.
+pub fn suppress() -> SuppressGuard {
+    SuppressGuard::new()
+}