Standardize logging and error handling

- Introduce new types: LoggedResult and LoggedError
- Introduce new extension methods to log and add additional msgs
- Never exit when logging error messages in Rust (all errors should be
  handled by using Result and Rust's error propagation)
- Remove all usages of anyhow as it doesn't fit Magisk's use cases

native/src/base/Cargo.toml

@@ -14,4 +14,3 @@ cxx = { workspace = true }
 libc = { workspace = true }
 cfg-if = { workspace = true }
 thiserror = { workspace = true }
-anyhow = { workspace = true }

native/src/base/cxx_extern.rs

@@ -1,9 +1,9 @@
 // Functions listed here are just to export to C++
 
+use std::fmt::Write;
 use std::io;
 use std::os::fd::{BorrowedFd, OwnedFd, RawFd};
 
-use anyhow::Context;
 use cxx::private::c_char;
 use libc::mode_t;
 
@@ -14,8 +14,7 @@ use crate::{
 
 pub(crate) fn fd_path_for_cxx(fd: RawFd, buf: &mut [u8]) -> isize {
     fd_path(fd, buf)
-        .context("fd_path failed")
-        .log()
+        .log_cxx_with_msg(|w| w.write_str("fd_path failed"))
         .map_or(-1_isize, |v| v as isize)
 }
 
@@ -54,7 +53,7 @@ unsafe extern "C" fn frm_rf(fd: OwnedFd) -> bool {
 pub(crate) fn map_file_for_cxx(path: &[u8], rw: bool) -> &'static mut [u8] {
     unsafe {
         map_file(Utf8CStr::from_bytes_unchecked(path), rw)
-            .log()
+            .log_cxx()
             .unwrap_or(&mut [])
     }
 }
@@ -62,7 +61,7 @@ pub(crate) fn map_file_for_cxx(path: &[u8], rw: bool) -> &'static mut [u8] {
 pub(crate) fn map_fd_for_cxx(fd: RawFd, sz: usize, rw: bool) -> &'static mut [u8] {
     unsafe {
         map_fd(BorrowedFd::borrow_raw(fd), sz, rw)
-            .log()
+            .log_cxx()
             .unwrap_or(&mut [])
     }
 }

native/src/base/lib.rs

@@ -20,6 +20,7 @@ mod xwrap;
 pub mod ffi {
     #[derive(Copy, Clone)]
     pub enum LogLevel {
+        ErrorCxx,
         Error,
         Warn,
         Info,
@@ -32,6 +33,7 @@ pub mod ffi {
     }
 
     extern "Rust" {
+        #[rust_name = "log_from_cxx"]
         fn log_with_rs(level: LogLevel, msg: &[u8]);
         fn exit_on_error(b: bool);
         fn set_log_level_state(level: LogLevel, enabled: bool);

native/src/base/logging.cpp

@@ -33,7 +33,7 @@ extern "C" int magisk_log_print(int prio, const char *tag, const char *fmt, ...)
         level = LogLevel::Warn;
         break;
     case ANDROID_LOG_ERROR:
-        level = LogLevel::Error;
+        level = LogLevel::ErrorCxx;
         break;
     default:
         return 0;
@@ -70,9 +70,9 @@ void LOGD(const char *fmt, ...) {}
 #endif
 void LOGI(const char *fmt, ...) { LOG_BODY(Info) }
 void LOGW(const char *fmt, ...) { LOG_BODY(Warn) }
-void LOGE(const char *fmt, ...) { LOG_BODY(Error) }
+void LOGE(const char *fmt, ...) { LOG_BODY(ErrorCxx) }
 
 // Export raw symbol to fortify compat
 extern "C" void __vloge(const char* fmt, va_list ap) {
-    fmt_and_log_with_rs(LogLevel::Error, fmt, ap);
+    fmt_and_log_with_rs(LogLevel::ErrorCxx, fmt, ap);
 }

native/src/base/logging.rs

@@ -1,9 +1,23 @@
-use std::fmt::{Arguments, Display};
+use std::fmt;
+use std::fmt::{Arguments, Display, Write as fWrite};
 use std::io::{stderr, stdout, Write};
 use std::process::exit;
 
 use crate::ffi::LogLevel;
-use crate::fmt_to_buf;
+use crate::BufFormatter;
+
+// Error handling and logging throughout the Rust codebase in Magisk:
+//
+// All errors should be logged and consumed as soon as possible and converted into LoggedError.
+// Implement `From<ErrorType> for LoggedError` for non-standard error types so that we can
+// directly use the `?` operator to propagate LoggedResult.
+//
+// To log an error with more information, use `ResultExt::log_with_msg()`.
+//
+// The "cxx" method variants in `ResultExt` are only used for C++ interop and
+// should not be used directly in any Rust code.
+//
+// For general logging, use the <level>!(...) macros.
 
 // Ugly hack to avoid using enum
 #[allow(non_snake_case, non_upper_case_globals)]
@@ -41,7 +55,7 @@ pub fn exit_on_error(b: bool) {
 impl LogLevel {
     fn as_disable_flag(&self) -> u32 {
         match *self {
-            LogLevel::Error => LogFlag::DisableError,
+            LogLevel::Error | LogLevel::ErrorCxx => LogFlag::DisableError,
             LogLevel::Warn => LogFlag::DisableWarn,
             LogLevel::Info => LogFlag::DisableInfo,
             LogLevel::Debug => LogFlag::DisableDebug,
@@ -61,28 +75,32 @@ pub fn set_log_level_state(level: LogLevel, enabled: bool) {
     }
 }
 
-pub fn log_with_rs(level: LogLevel, msg: &[u8]) {
+fn do_log<F: FnOnce(fn(level: LogLevel, msg: &[u8]))>(level: LogLevel, f: F) {
     let logger = unsafe { LOGGER };
     if (logger.flags & level.as_disable_flag()) != 0 {
         return;
     }
-    (logger.write)(level, msg);
-    if level == LogLevel::Error && (logger.flags & LogFlag::ExitOnError) != 0 {
+    f(logger.write);
+    if level == LogLevel::ErrorCxx && (logger.flags & LogFlag::ExitOnError) != 0 {
         exit(1);
     }
 }
 
-pub fn log_impl(level: LogLevel, args: Arguments) {
-    let logger = unsafe { LOGGER };
-    if (logger.flags & level.as_disable_flag()) != 0 {
-        return;
-    }
-    let mut buf: [u8; 4096] = [0; 4096];
-    let len = fmt_to_buf(&mut buf, args);
-    (logger.write)(level, &buf[..len]);
-    if level == LogLevel::Error && (logger.flags & LogFlag::ExitOnError) != 0 {
-        exit(1);
-    }
+pub fn log_from_cxx(level: LogLevel, msg: &[u8]) {
+    do_log(level, |write| write(level, msg));
+}
+
+pub fn log_with_formatter<F: FnOnce(&mut BufFormatter) -> fmt::Result>(level: LogLevel, f: F) {
+    do_log(level, |write| {
+        let mut buf = [0_u8; 4096];
+        let mut w = BufFormatter::new(&mut buf);
+        let len = if f(&mut w).is_ok() { w.used } else { 0 };
+        write(level, &buf[..len]);
+    });
+}
+
+pub fn log_with_args(level: LogLevel, args: Arguments) {
+    log_with_formatter(level, |w| w.write_fmt(args));
 }
 
 pub fn cmdline_logging() {
@@ -103,44 +121,33 @@ pub fn cmdline_logging() {
     }
 }
 
-#[macro_export]
-macro_rules! perror {
-    ($fmt:expr) => {
-        $crate::log_impl($crate::ffi::LogLevel::Error, format_args_nl!(
-            concat!($fmt, " failed with {}: {}"),
-            $crate::errno(),
-            $crate::error_str()
-        ))
-    };
-    ($fmt:expr, $($args:tt)*) => {
-        $crate::log_impl($crate::ffi::LogLevel::Error, format_args_nl!(
-            concat!($fmt, " failed with {}: {}"),
-            $($args)*,
-            $crate::errno(),
-            $crate::error_str()
-        ))
-    };
-}
-
 #[macro_export]
 macro_rules! error {
-    ($($args:tt)+) => ($crate::log_impl($crate::ffi::LogLevel::Error, format_args_nl!($($args)+)))
+    ($($args:tt)+) => {
+        $crate::log_with_args($crate::ffi::LogLevel::Error, format_args_nl!($($args)+))
+    }
 }
 
 #[macro_export]
 macro_rules! warn {
-    ($($args:tt)+) => ($crate::log_impl($crate::ffi::LogLevel::Warn, format_args_nl!($($args)+)))
+    ($($args:tt)+) => {
+        $crate::log_with_args($crate::ffi::LogLevel::Warn, format_args_nl!($($args)+))
+    }
 }
 
 #[macro_export]
 macro_rules! info {
-    ($($args:tt)+) => ($crate::log_impl($crate::ffi::LogLevel::Info, format_args_nl!($($args)+)))
+    ($($args:tt)+) => {
+        $crate::log_with_args($crate::ffi::LogLevel::Info, format_args_nl!($($args)+))
+    }
 }
 
 #[cfg(debug_assertions)]
 #[macro_export]
 macro_rules! debug {
-    ($($args:tt)+) => ($crate::log_impl($crate::ffi::LogLevel::Debug, format_args_nl!($($args)+)))
+    ($($args:tt)+) => {
+        $crate::log_with_args($crate::ffi::LogLevel::Debug, format_args_nl!($($args)+))
+    }
 }
 
 #[cfg(not(debug_assertions))]
@@ -149,15 +156,111 @@ macro_rules! debug {
     ($($args:tt)+) => {};
 }
 
-pub trait ResultExt {
-    fn log(self) -> Self;
-}
+#[derive(Default)]
+pub struct LoggedError {}
 
-impl<T, E: Display> ResultExt for Result<T, E> {
-    fn log(self) -> Self {
-        if let Err(e) = &self {
-            error!("{:#}", e);
-        }
-        self
+// Automatically handle all printable errors
+impl<T: Display> From<T> for LoggedError {
+    fn from(e: T) -> Self {
+        log_with_args(LogLevel::Error, format_args_nl!("{:#}", e));
+        LoggedError::default()
+    }
+}
+
+pub type LoggedResult<T> = Result<T, LoggedError>;
+
+#[macro_export]
+macro_rules! log_err {
+    ($msg:literal $(,)?) => {{
+        $crate::log_with_args($crate::ffi::LogLevel::Error, format_args_nl!($msg));
+        $crate::LoggedError::default()
+    }};
+    ($err:expr $(,)?) => {{
+        $crate::log_with_args($crate::ffi::LogLevel::Error, format_args_nl!("{}", $err));
+        $crate::LoggedError::default()
+    }};
+    ($($args:tt)+) => {{
+        $crate::log_with_args($crate::ffi::LogLevel::Error, format_args_nl!($($args)+));
+        $crate::LoggedError::default()
+    }};
+}
+
+pub trait ResultExt<T>
+where
+    Self: Sized,
+{
+    fn log(self) -> LoggedResult<T> {
+        self.log_impl(LogLevel::Error)
+    }
+    fn log_cxx(self) -> LoggedResult<T> {
+        self.log_impl(LogLevel::ErrorCxx)
+    }
+    fn log_with_msg<F: FnOnce(&mut BufFormatter) -> fmt::Result>(self, f: F) -> LoggedResult<T> {
+        self.log_with_msg_impl(LogLevel::Error, f)
+    }
+    fn log_cxx_with_msg<F: FnOnce(&mut BufFormatter) -> fmt::Result>(
+        self,
+        f: F,
+    ) -> LoggedResult<T> {
+        self.log_with_msg_impl(LogLevel::ErrorCxx, f)
+    }
+
+    fn log_impl(self, level: LogLevel) -> LoggedResult<T>;
+    fn log_with_msg_impl<F: FnOnce(&mut BufFormatter) -> fmt::Result>(
+        self,
+        level: LogLevel,
+        f: F,
+    ) -> LoggedResult<T>;
+}
+
+impl<T> ResultExt<T> for LoggedResult<T> {
+    fn log_impl(self, _: LogLevel) -> LoggedResult<T> {
+        self
+    }
+
+    fn log_with_msg_impl<F: FnOnce(&mut BufFormatter) -> fmt::Result>(
+        self,
+        level: LogLevel,
+        f: F,
+    ) -> LoggedResult<T> {
+        match self {
+            Ok(v) => Ok(v),
+            Err(_) => {
+                log_with_formatter(level, |w| {
+                    f(w)?;
+                    w.write_char('\n')
+                });
+                Err(LoggedError::default())
+            }
+        }
+    }
+}
+
+impl<T, E: Display> ResultExt<T> for Result<T, E> {
+    fn log_impl(self, level: LogLevel) -> LoggedResult<T> {
+        match self {
+            Ok(v) => Ok(v),
+            Err(e) => {
+                log_with_args(level, format_args_nl!("{:#}", e));
+                Err(LoggedError::default())
+            }
+        }
+    }
+
+    fn log_with_msg_impl<F: FnOnce(&mut BufFormatter) -> fmt::Result>(
+        self,
+        level: LogLevel,
+        f: F,
+    ) -> LoggedResult<T> {
+        match self {
+            Ok(v) => Ok(v),
+            Err(e) => {
+                log_with_formatter(level, |w| {
+                    f(w)?;
+                    writeln!(w, ": {:#}", e)
+                });
+                Err(LoggedError::default())
+            }
+        }
     }
 }

native/src/base/misc.rs

@@ -26,18 +26,18 @@ pub fn copy_cstr<T: AsRef<CStr> + ?Sized>(dest: &mut [u8], src: &T) -> usize {
     len - 1
 }
 
-struct BufFmtWriter<'a> {
+pub struct BufFormatter<'a> {
     buf: &'a mut [u8],
-    used: usize,
+    pub used: usize,
 }
 
-impl<'a> BufFmtWriter<'a> {
-    fn new(buf: &'a mut [u8]) -> Self {
-        BufFmtWriter { buf, used: 0 }
+impl<'a> BufFormatter<'a> {
+    pub fn new(buf: &'a mut [u8]) -> Self {
+        BufFormatter { buf, used: 0 }
     }
 }
 
-impl<'a> fmt::Write for BufFmtWriter<'a> {
+impl<'a> fmt::Write for BufFormatter<'a> {
     // The buffer should always be null terminated
     fn write_str(&mut self, s: &str) -> fmt::Result {
         if self.used >= self.buf.len() - 1 {
@@ -51,7 +51,7 @@ impl<'a> fmt::Write for BufFmtWriter<'a> {
 }
 
 pub fn fmt_to_buf(buf: &mut [u8], args: Arguments) -> usize {
-    let mut w = BufFmtWriter::new(buf);
+    let mut w = BufFormatter::new(buf);
     if let Ok(()) = fmt::write(&mut w, args) {
         w.used
     } else {

native/src/base/xwrap.rs

@@ -1,24 +1,45 @@
+use std::fmt::Write;
 use std::os::unix::io::RawFd;
 use std::ptr;
 
-use anyhow::Context;
 use libc::{
     c_char, c_uint, c_ulong, c_void, dev_t, mode_t, nfds_t, off_t, pollfd, sockaddr, socklen_t,
     ssize_t, SYS_dup3,
 };
 
-use crate::{cstr, errno, error, mkdirs, perror, ptr_to_str, raw_cstr, ResultExt, Utf8CStr};
+use crate::{cstr, errno, mkdirs, ptr_to_str, raw_cstr, ResultExt, Utf8CStr};
+
+macro_rules! error_cxx {
+    ($($args:tt)+) => {
+        ($crate::log_with_args($crate::ffi::LogLevel::ErrorCxx, format_args_nl!($($args)+)))
+    }
+}
+
+macro_rules! perror {
+    ($fmt:expr) => {
+        $crate::log_with_formatter($crate::ffi::LogLevel::ErrorCxx, |w| {
+            w.write_str($fmt)?;
+            w.write_fmt(format_args!(" failed with {}: {}", $crate::errno(), $crate::error_str()))
+        })
+    };
+    ($fmt:expr, $($args:tt)*) => {
+        $crate::log_with_formatter($crate::ffi::LogLevel::ErrorCxx, |w| {
+            w.write_fmt(format_args!($fmt, $($args)*))?;
+            w.write_fmt(format_args!(" failed with {}: {}", $crate::errno(), $crate::error_str()))
+        })
+    };
+}
 
 mod unsafe_impl {
+    use std::fmt::Write;
     use std::os::unix::io::RawFd;
 
-    use anyhow::Context;
     use cfg_if::cfg_if;
     use libc::{c_char, nfds_t, off_t, pollfd};
 
     use crate::{
-        perror, ptr_to_str, readlink_unsafe, realpath, slice_from_ptr, slice_from_ptr_mut,
-        ResultExt, Utf8CStr,
+        ptr_to_str, readlink_unsafe, realpath, slice_from_ptr, slice_from_ptr_mut, ResultExt,
+        Utf8CStr,
     };
 
     #[no_mangle]
@@ -40,8 +61,7 @@ mod unsafe_impl {
     unsafe extern "C" fn xrealpath(path: *const c_char, buf: *mut u8, bufsz: usize) -> isize {
         match Utf8CStr::from_ptr(path) {
             Ok(p) => realpath(p, slice_from_ptr_mut(buf, bufsz))
-                .with_context(|| format!("realpath {} failed", p))
-                .log()
+                .log_cxx_with_msg(|w| w.write_fmt(format_args!("realpath {} failed", p)))
                 .map_or(-1, |v| v as isize),
             Err(_) => -1,
         }
@@ -172,7 +192,7 @@ pub fn xwrite(fd: RawFd, data: &[u8]) -> isize {
             }
         }
         if !remain.is_empty() {
-            error!("write ({} != {})", write_sz, data.len())
+            error_cxx!("write ({} != {})", write_sz, data.len())
         }
         write_sz as isize
     }
@@ -211,7 +231,7 @@ pub fn xxread(fd: RawFd, data: &mut [u8]) -> isize {
             }
         }
         if !remain.is_empty() {
-            error!("read ({} != {})", read_sz, data.len())
+            error_cxx!("read ({} != {})", read_sz, data.len())
         }
         read_sz as isize
     }
@@ -572,8 +592,7 @@ pub unsafe extern "C" fn xmkdir(path: *const c_char, mode: mode_t) -> i32 {
 pub unsafe extern "C" fn xmkdirs(path: *const c_char, mode: mode_t) -> i32 {
     match Utf8CStr::from_ptr(path) {
         Ok(p) => mkdirs(p, mode)
-            .with_context(|| format!("mkdirs {} failed", p))
-            .log()
+            .log_cxx_with_msg(|w| w.write_fmt(format_args!("mkdirs {} failed", p)))
             .map_or(-1, |_| 0),
         Err(_) => -1,
     }