Rearchitect logging

native/jni/base/logging.cpp

@@ -11,23 +11,15 @@
 
 using namespace std;
 
-void nop_log(const char *, va_list) {}
-
-log_callback log_cb = {
-    .d = nop_log,
-    .i = nop_log,
-    .w = nop_log,
-    .e = nop_log,
-};
-static bool EXIT_ON_ERROR = false;
-
 static int fmt_and_log_with_rs(LogLevel level, const char *fmt, va_list ap) {
     char buf[4096];
     int ret = vsnprintf(buf, sizeof(buf), fmt, ap);
-    log_with_rs(level, buf);
+    log_with_rs(level, rust::Str(buf, ret));
     return ret;
 }
 
+int (*cpp_logger)(LogLevel level, const char *fmt, va_list ap) = fmt_and_log_with_rs;
+
 // Used to override external C library logging
 extern "C" int magisk_log_print(int prio, const char *tag, const char *fmt, ...) {
     LogLevel level;
@@ -55,48 +47,29 @@ extern "C" int magisk_log_print(int prio, const char *tag, const char *fmt, ...)
     snprintf(fmt_buf + len, sizeof(fmt_buf) - len, ": %s", fmt);
     va_list argv;
     va_start(argv, fmt);
-    int ret = fmt_and_log_with_rs(level, fmt_buf, argv);
+    int ret = cpp_logger(level, fmt_buf, argv);
     va_end(argv);
     return ret;
 }
 
-#define rlog(prio) [](auto fmt, auto ap) { fmt_and_log_with_rs(LogLevel::prio, fmt, ap); }
-void forward_logging_to_rs() {
-    log_cb.d = rlog(Debug);
-    log_cb.i = rlog(Info);
-    log_cb.w = rlog(Warn);
-    log_cb.e = rlog(Error);
-}
-
-void cmdline_logging() {
-    rust::cmdline_logging();
-    forward_logging_to_rs();
-    exit_on_error(true);
-}
-
-void exit_on_error(bool b) {
-    rust::exit_on_error(b);
-    EXIT_ON_ERROR = b;
-}
-
-#define LOG_BODY(prio) { \
+#define LOG_BODY(level) { \
     va_list argv;        \
     va_start(argv, fmt); \
-    log_cb.prio(fmt, argv); \
+    cpp_logger(LogLevel::level, fmt, argv); \
     va_end(argv);        \
 }
 
 // LTO will optimize out the NOP function
 #if MAGISK_DEBUG
-void LOGD(const char *fmt, ...) { LOG_BODY(d) }
+void LOGD(const char *fmt, ...) { LOG_BODY(Debug) }
 #else
 void LOGD(const char *fmt, ...) {}
 #endif
-void LOGI(const char *fmt, ...) { LOG_BODY(i) }
-void LOGW(const char *fmt, ...) { LOG_BODY(w) }
-void LOGE(const char *fmt, ...) { LOG_BODY(e); if (EXIT_ON_ERROR) exit(EXIT_FAILURE); }
+void LOGI(const char *fmt, ...) { LOG_BODY(Info) }
+void LOGW(const char *fmt, ...) { LOG_BODY(Warn) }
+void LOGE(const char *fmt, ...) { LOG_BODY(Error) }
 
 // Export raw symbol to fortify compat
 extern "C" void __vloge(const char* fmt, va_list ap) {
-    log_cb.e(fmt, ap);
+    cpp_logger(LogLevel::Error, fmt, ap);
 }

native/jni/base/logging.hpp

@@ -3,23 +3,12 @@
 #include <cerrno>
 #include <cstdarg>
 
-struct log_callback {
-    void (*d)(const char* fmt, va_list ap);
-    void (*i)(const char* fmt, va_list ap);
-    void (*w)(const char* fmt, va_list ap);
-    void (*e)(const char* fmt, va_list ap);
-};
+#include <base-rs.hpp>
 
-extern log_callback log_cb;
+extern int (*cpp_logger)(LogLevel level, const char *fmt, va_list ap);
 
 void LOGD(const char *fmt, ...) __printflike(1, 2);
 void LOGI(const char *fmt, ...) __printflike(1, 2);
 void LOGW(const char *fmt, ...) __printflike(1, 2);
 void LOGE(const char *fmt, ...) __printflike(1, 2);
 #define PLOGE(fmt, args...) LOGE(fmt " failed with %d: %s\n", ##args, errno, std::strerror(errno))
-
-void nop_log(const char *, va_list);
-
-void forward_logging_to_rs();
-void cmdline_logging();
-void exit_on_error(bool b);

native/jni/core/core.hpp

@@ -20,7 +20,6 @@ void unlock_blocks();
 void reboot();
 void start_log_daemon();
 void setup_logfile(bool reset);
-void magisk_logging();
 std::string read_certificate(int fd, int version = -1);
 
 // Module stuffs

native/jni/core/logging.cpp

@@ -149,18 +149,6 @@ void magisk_log_write(int prio, const char *msg, int len) {
     }
 }
 
-void magisk_logging() {
-    rust::magisk_logging();
-    forward_logging_to_rs();
-    exit_on_error(false);
-}
-
-void android_logging() {
-    rust::android_logging();
-    forward_logging_to_rs();
-    exit_on_error(false);
-}
-
 void start_log_daemon() {
     int fds[2];
     if (pipe2(fds, O_CLOEXEC) == 0) {

native/jni/include/daemon.hpp

@@ -81,7 +81,6 @@ void exec_task(std::function<void()> &&task);
 
 // Logging
 extern std::atomic<int> logd_fd;
-void android_logging();
 extern "C" void magisk_log_write(int prio, const char *msg, int len);
 
 // Daemon handlers

native/jni/init/getinfo.cpp

@@ -121,6 +121,15 @@ static FILE *kmsg;
 extern "C" void klog_write(const char *msg, int len) {
     fprintf(kmsg, "%.*s", len, msg);
 }
+
+static int klog_with_rs(LogLevel level, const char *fmt, va_list ap) {
+    char buf[4096];
+    strlcpy(buf, "magiskinit: ", sizeof(buf));
+    int len = vsnprintf(buf + 12, sizeof(buf) - 12, fmt, ap) + 12;
+    log_with_rs(level, rust::Str(buf, len));
+    return len;
+}
+
 void setup_klog() {
     // Shut down first 3 fds
     int fd;
@@ -148,8 +157,7 @@ void setup_klog() {
     kmsg = fdopen(fd, "w");
     setbuf(kmsg, nullptr);
     rust::setup_klog();
-    forward_logging_to_rs();
-    exit_on_error(false);
+    cpp_logger = klog_with_rs;
 
     // Disable kmsg rate limiting
     if (FILE *rate = fopen("/proc/sys/kernel/printk_devkmsg", "w")) {

native/jni/resetprop/resetprop.cpp

@@ -337,8 +337,7 @@ int resetprop_main(int argc, char *argv[]) {
         ++argv;
     }
 
-    if (!verbose)
-        log_cb.d = nop_log;
+    set_log_level_state(LogLevel::Debug, verbose);
 
     switch (argc) {
     case 0:

native/jni/sepolicy/rules.cpp

@@ -6,8 +6,7 @@ using namespace std;
 
 void sepolicy::magisk_rules() {
     // Temp suppress warnings
-    auto bak = log_cb.w;
-    log_cb.w = nop_log;
+    set_log_level_state(LogLevel::Warn, false);
 
     // This indicates API 26+
     bool new_rules = exists("untrusted_app_25");
@@ -196,5 +195,5 @@ void sepolicy::magisk_rules() {
     impl->strip_dontaudit();
 #endif
 
-    log_cb.w = bak;
+    set_log_level_state(LogLevel::Warn, true);
 }

native/jni/zygisk/entry.cpp

@@ -17,12 +17,6 @@ using namespace std;
 
 void *self_handle = nullptr;
 
-static void zygisk_logging() {
-    rust::zygisk_logging();
-    forward_logging_to_rs();
-    exit_on_error(false);
-}
-
 // Make sure /proc/self/environ is sanitized
 // Filter env and reset MM_ENV_END
 static void sanitize_environ() {

native/rust/base/src/lib.rs

@@ -8,6 +8,7 @@ mod misc;
 
 #[cxx::bridge]
 pub mod ffi {
+    #[derive(Copy, Clone)]
     pub enum LogLevel {
         Error,
         Warn,
@@ -17,13 +18,8 @@ pub mod ffi {
 
     extern "Rust" {
         fn log_with_rs(level: LogLevel, msg: &str);
-    }
-}
-
-#[cxx::bridge(namespace = "rust")]
-pub mod ffi2 {
-    extern "Rust" {
-        fn cmdline_logging();
         fn exit_on_error(b: bool);
+        fn set_log_level_state(level: LogLevel, enabled: bool);
+        fn cmdline_logging();
     }
 }

native/rust/base/src/logging.rs

@@ -1,64 +1,113 @@
 use std::fmt::Arguments;
+use std::io::{stderr, stdout, Write};
 use std::process::exit;
 
 use crate::ffi::LogLevel;
 
+// Ugly hack to avoid using enum
+#[allow(non_snake_case, non_upper_case_globals)]
+mod LogFlag {
+    pub const DisableError: u32 = 0x1;
+    pub const DisableWarn: u32 = 0x2;
+    pub const DisableInfo: u32 = 0x4;
+    pub const DisableDebug: u32 = 0x8;
+    pub const ExitOnError: u32 = 0x10;
+}
+
 // We don't need to care about thread safety, because all
 // logger changes will only happen on the main thread.
 pub static mut LOGGER: Logger = Logger {
-    d: nop_log,
-    i: nop_log,
-    w: nop_log,
-    e: nop_log,
+    fmt: |_, _| {},
+    write: |_, _| {},
+    flags: 0,
 };
-static mut EXIT_ON_ERROR: bool = false;
 
 #[derive(Copy, Clone)]
 pub struct Logger {
-    pub d: fn(args: Arguments),
-    pub i: fn(args: Arguments),
-    pub w: fn(args: Arguments),
-    pub e: fn(args: Arguments),
-}
-
-pub fn nop_log(_: Arguments) {}
-
-pub fn log_with_rs(level: LogLevel, msg: &str) {
-    log_impl(level, format_args!("{}", msg));
+    pub fmt: fn(level: LogLevel, args: Arguments),
+    pub write: fn(level: LogLevel, msg: &[u8]),
+    pub flags: u32,
 }
 
 pub fn exit_on_error(b: bool) {
-    unsafe { EXIT_ON_ERROR = b; }
+    unsafe {
+        if b {
+            LOGGER.flags |= LogFlag::ExitOnError;
+        } else {
+            LOGGER.flags &= !LogFlag::ExitOnError;
+        }
+    }
 }
 
-pub fn cmdline_logging() {
-    fn print(args: Arguments) { print!("{}", args); }
-    fn eprint(args: Arguments) { eprint!("{}", args); }
+impl LogLevel {
+    fn to_disable_flag(&self) -> u32 {
+        match *self {
+            LogLevel::Error => LogFlag::DisableError,
+            LogLevel::Warn => LogFlag::DisableWarn,
+            LogLevel::Info => LogFlag::DisableInfo,
+            LogLevel::Debug => LogFlag::DisableDebug,
+            _ => 0
+        }
+    }
+}
 
-    let logger = Logger {
-        d: eprint,
-        i: print,
-        w: eprint,
-        e: eprint,
-    };
+pub fn set_log_level_state(level: LogLevel, enabled: bool) {
+    let flag = level.to_disable_flag();
     unsafe {
-        LOGGER = logger;
-        EXIT_ON_ERROR = true;
+        if enabled {
+            LOGGER.flags &= !flag
+        } else {
+            LOGGER.flags |= flag
+        }
+    }
+}
+
+pub fn log_with_rs(level: LogLevel, msg: &str) {
+    let logger = unsafe { LOGGER };
+    if (logger.flags & level.to_disable_flag()) != 0 {
+        return;
+    }
+    (logger.write)(level, msg.as_bytes());
+    if level == LogLevel::Error && (logger.flags & LogFlag::ExitOnError) != 0 {
+        exit(1);
     }
 }
 
 pub fn log_impl(level: LogLevel, args: Arguments) {
     let logger = unsafe { LOGGER };
-    let aoe = unsafe { EXIT_ON_ERROR };
-    match level {
-        LogLevel::Error => {
-            (logger.e)(args);
-            if aoe { exit(1); }
+    if (logger.flags & level.to_disable_flag()) != 0 {
+        return;
+    }
+    (logger.fmt)(level, args);
+    if level == LogLevel::Error && (logger.flags & LogFlag::ExitOnError) != 0 {
+        exit(1);
+    }
+}
+
+pub fn cmdline_logging() {
+    fn print(level: LogLevel, args: Arguments) {
+        if level == LogLevel::Info {
+            print!("{}", args);
+        } else {
+            eprint!("{}", args);
         }
-        LogLevel::Warn => (logger.w)(args),
-        LogLevel::Info => (logger.i)(args),
-        LogLevel::Debug => (logger.d)(args),
-        _ => ()
+    }
+
+    fn write(level: LogLevel, msg: &[u8]) {
+        if level == LogLevel::Info {
+            stdout().write_all(msg).ok();
+        } else {
+            stderr().write_all(msg).ok();
+        }
+    }
+
+    let logger = Logger {
+        fmt: print,
+        write,
+        flags: LogFlag::ExitOnError,
+    };
+    unsafe {
+        LOGGER = logger;
     }
 }
 

native/rust/core/src/lib.rs

@@ -7,12 +7,6 @@ mod logging;
 pub mod ffi {
     extern "Rust" {
         fn rust_test_entry();
-    }
-}
-
-#[cxx::bridge(namespace = "rust")]
-pub mod ffi2 {
-    extern "Rust" {
         fn android_logging();
         fn magisk_logging();
         fn zygisk_logging();

native/rust/core/src/logging.rs

@@ -1,5 +1,6 @@
 use std::fmt::Arguments;
 use base::*;
+use base::ffi::LogLevel;
 
 #[allow(dead_code, non_camel_case_types)]
 #[repr(i32)]
@@ -21,20 +22,34 @@ extern "C" {
     fn zygisk_log_write(prio: i32, msg: *const u8, len: i32);
 }
 
+fn level_to_prio(level: LogLevel) -> i32 {
+    match level {
+        LogLevel::Error => ALogPriority::ANDROID_LOG_ERROR as i32,
+        LogLevel::Warn => ALogPriority::ANDROID_LOG_WARN as i32,
+        LogLevel::Info => ALogPriority::ANDROID_LOG_INFO as i32,
+        LogLevel::Debug => ALogPriority::ANDROID_LOG_DEBUG as i32,
+        _ => 0
+    }
+}
+
 pub fn android_logging() {
-    fn android_log_impl(prio: i32, args: Arguments) {
+    fn android_log_fmt(level: LogLevel, args: Arguments) {
         let mut buf: [u8; 4096] = [0; 4096];
         fmt_to_buf(&mut buf, args);
         unsafe {
-            __android_log_write(prio, b"Magisk\0".as_ptr(), buf.as_ptr());
+            __android_log_write(level_to_prio(level), b"Magisk\0".as_ptr(), buf.as_ptr());
+        }
+    }
+    fn android_log_write(level: LogLevel, msg: &[u8]) {
+        unsafe {
+            __android_log_write(level_to_prio(level), b"Magisk\0".as_ptr(), msg.as_ptr());
         }
     }
 
     let logger = Logger {
-        d: |args| { android_log_impl(ALogPriority::ANDROID_LOG_DEBUG as i32, args) },
-        i: |args| { android_log_impl(ALogPriority::ANDROID_LOG_INFO as i32, args) },
-        w: |args| { android_log_impl(ALogPriority::ANDROID_LOG_WARN as i32, args) },
-        e: |args| { android_log_impl(ALogPriority::ANDROID_LOG_ERROR as i32, args) }
+        fmt: android_log_fmt,
+        write: android_log_write,
+        flags: 0,
     };
     exit_on_error(false);
     unsafe {
@@ -43,20 +58,25 @@ pub fn android_logging() {
 }
 
 pub fn magisk_logging() {
-    fn magisk_log_impl(prio: i32, args: Arguments) {
+    fn magisk_fmt(level: LogLevel, args: Arguments) {
         let mut buf: [u8; 4096] = [0; 4096];
         let len = fmt_to_buf(&mut buf, args);
         unsafe {
-            __android_log_write(prio, b"Magisk\0".as_ptr(), buf.as_ptr());
-            magisk_log_write(prio, buf.as_ptr(), len as i32);
+            __android_log_write(level_to_prio(level), b"Magisk\0".as_ptr(), buf.as_ptr());
+            magisk_log_write(level_to_prio(level), buf.as_ptr(), len as i32);
+        }
+    }
+    fn magisk_write(level: LogLevel, msg: &[u8]) {
+        unsafe {
+            __android_log_write(level_to_prio(level), b"Magisk\0".as_ptr(), msg.as_ptr());
+            magisk_log_write(level_to_prio(level), msg.as_ptr(), msg.len() as i32);
         }
     }
 
     let logger = Logger {
-        d: |args| { magisk_log_impl(ALogPriority::ANDROID_LOG_DEBUG as i32, args) },
-        i: |args| { magisk_log_impl(ALogPriority::ANDROID_LOG_INFO as i32, args) },
-        w: |args| { magisk_log_impl(ALogPriority::ANDROID_LOG_WARN as i32, args) },
-        e: |args| { magisk_log_impl(ALogPriority::ANDROID_LOG_ERROR as i32, args) }
+        fmt: magisk_fmt,
+        write: magisk_write,
+        flags: 0,
     };
     exit_on_error(false);
     unsafe {
@@ -65,20 +85,25 @@ pub fn magisk_logging() {
 }
 
 pub fn zygisk_logging() {
-    fn zygisk_log_impl(prio: i32, args: Arguments) {
+    fn zygisk_fmt(level: LogLevel, args: Arguments) {
         let mut buf: [u8; 4096] = [0; 4096];
         let len = fmt_to_buf(&mut buf, args);
         unsafe {
-            __android_log_write(prio, b"Magisk\0".as_ptr(), buf.as_ptr());
-            zygisk_log_write(prio, buf.as_ptr(), len as i32);
+            __android_log_write(level_to_prio(level), b"Magisk\0".as_ptr(), buf.as_ptr());
+            zygisk_log_write(level_to_prio(level), buf.as_ptr(), len as i32);
+        }
+    }
+    fn zygisk_write(level: LogLevel, msg: &[u8]) {
+        unsafe {
+            __android_log_write(level_to_prio(level), b"Magisk\0".as_ptr(), msg.as_ptr());
+            zygisk_log_write(level_to_prio(level), msg.as_ptr(), msg.len() as i32);
         }
     }
 
     let logger = Logger {
-        d: |args| { zygisk_log_impl(ALogPriority::ANDROID_LOG_DEBUG as i32, args) },
-        i: |args| { zygisk_log_impl(ALogPriority::ANDROID_LOG_INFO as i32, args) },
-        w: |args| { zygisk_log_impl(ALogPriority::ANDROID_LOG_WARN as i32, args) },
-        e: |args| { zygisk_log_impl(ALogPriority::ANDROID_LOG_ERROR as i32, args) }
+        fmt: zygisk_fmt,
+        write: zygisk_write,
+        flags: 0,
     };
     exit_on_error(false);
     unsafe {

native/rust/init/src/logging.rs

@@ -1,15 +1,16 @@
 use std::fmt::Arguments;
 use base::*;
+use base::ffi::LogLevel;
 
 extern "C" {
     fn klog_write(msg: *const u8, len: i32);
 }
 
 pub fn setup_klog() {
-    fn klog_impl(args: Arguments) {
-        const PREFIX: &[u8; 12] = b"magiskinit: ";
-        const PFX_LEN: usize = PREFIX.len();
+    const PREFIX: &[u8; 12] = b"magiskinit: ";
+    const PFX_LEN: usize = PREFIX.len();
 
+    fn klog_fmt(_: LogLevel, args: Arguments) {
         let mut buf: [u8; 4096] = [0; 4096];
         buf[..PFX_LEN].copy_from_slice(PREFIX);
         let len = fmt_to_buf(&mut buf[PFX_LEN..], args) + PFX_LEN;
@@ -18,11 +19,16 @@ pub fn setup_klog() {
         }
     }
 
+    fn klog_write_impl(_: LogLevel, msg: &[u8]) {
+        unsafe {
+            klog_write(msg.as_ptr(), msg.len() as i32);
+        }
+    }
+
     let logger = Logger {
-        d: klog_impl,
-        i: klog_impl,
-        w: klog_impl,
-        e: klog_impl,
+        fmt: klog_fmt,
+        write: klog_write_impl,
+        flags: 0,
     };
     exit_on_error(false);
     unsafe {