[Rust] Replace `log` with `tracing`

- Added more documentation
- Replaced global named logger for plugins, fixing the issue when the CU has multiple (e.g. statically linked demo)
- Simplified some misc code

This is a breaking change, but I believe there is no better time to make it, we cannot continue to use the `log` crate, it is too limited for our needs.

1 files changed, 147 insertions, 141 deletions

diff --git a/rust/src/logger.rs b/rust/src/logger.rs
index 2a6db188..f77cb52c 100644
--- a/rust/src/logger.rs
+++ b/rust/src/logger.rs
@@ -1,114 +1,105 @@
-#![allow(clippy::needless_doctest_main)]
-
-//! To use logging in your script, do something like:
-//!
-//! ```no-test
-//! use binaryninja::logger::Logger;
-//! use log::{info, LevelFilter};
-//!
-//! fn main() {
-//!     Logger::default().init();
-//!     info!("The logger has been initialized!");
-//!     // Your code here...
-//! }
-//! ```
-//!
-//! or
-//!
-//!```no-test
-//! use binaryninja::logger::Logger;
-//! use log::{info, LevelFilter};
-//!
-//! #[no_mangle]
-//! pub extern "C" fn CorePluginInit() -> bool {
-//!     Logger::new("My Plugin").with_level(LevelFilter::Warn).init();
-//!     info!("The logger has been initialized!");
-//!     // Your code here...
-//!     true
-//! }
-//! ```
-
-pub use binaryninjacore_sys::BNLogLevel as Level;
-use binaryninjacore_sys::{
-    BNFreeLogger, BNLogCreateLogger, BNLogListener, BNLogger, BNLoggerGetName,
-    BNLoggerGetSessionId, BNNewLoggerReference, BNUpdateLogListeners,
-};
+// TODO: Describe this in terms of the core Logger, but refer to tracing for how to capture rust logs.
 
+use crate::file_metadata::SessionId;
 use crate::rc::{Ref, RefCountable};
 use crate::string::{raw_to_string, BnString, IntoCStr};
-use log;
-use log::LevelFilter;
+use binaryninjacore_sys::*;
 use std::ffi::CString;
 use std::os::raw::{c_char, c_void};
 use std::ptr::NonNull;
 
-const LOGGER_DEFAULT_SESSION_ID: usize = 0;
+// Used for documentation purposes.
+#[allow(unused_imports)]
+use crate::binary_view::BinaryView;
+
+pub use binaryninjacore_sys::BNLogLevel as BnLogLevel;
+
+pub const LOGGER_DEFAULT_SESSION_ID: SessionId = SessionId(0);
+
+/// Send a global log message **to the core**.
+///
+/// Prefer [`bn_log_with_session`] when a [`SessionId`] is available, via binary views file metadata.
+pub fn bn_log(logger: &str, level: BnLogLevel, msg: &str) {
+    bn_log_with_session(LOGGER_DEFAULT_SESSION_ID, logger, level, msg);
+}
+
+/// Send a session-scoped log message **to the core**.
+///
+/// The [`SessionId`] is how you attribute the log to a specific [`BinaryView`]. Without passing
+/// a session, logs will be shown in the UI globally, which you should not do if you can avoid it.
+pub fn bn_log_with_session(session_id: SessionId, logger: &str, level: BnLogLevel, msg: &str) {
+    if let Ok(msg) = CString::new(msg) {
+        let logger_name = logger.to_cstr();
+        unsafe {
+            BNLog(
+                session_id.0,
+                level,
+                logger_name.as_ptr(),
+                0,
+                c"%s".as_ptr(),
+                msg.as_ptr(),
+            )
+        }
+    }
+}
 
 #[derive(Debug, PartialEq, Eq, PartialOrd, Ord, Hash)]
 pub struct Logger {
     handle: NonNull<BNLogger>,
-    level: LevelFilter,
 }
 
 impl Logger {
+    /// Create a logger with the given name.
     pub fn new(name: &str) -> Ref<Logger> {
         Self::new_with_session(name, LOGGER_DEFAULT_SESSION_ID)
     }
 
-    pub fn new_with_session(name: &str, session_id: usize) -> Ref<Logger> {
+    /// Create a logger scoped with the specific [`SessionId`], hiding the logs when the session
+    /// is not active in the UI.
+    ///
+    /// # Example
+    ///
+    /// Typically, you will want to retrieve the [`SessionId`] from the [`BinaryView`] file metadata
+    ///
+    /// ```no_run
+    /// # use binaryninja::binary_view::BinaryView;
+    /// # use binaryninja::logger::Logger;
+    /// # let bv: BinaryView = todo!();
+    /// Logger::new_with_session("MyLogger", bv.file().session_id());
+    /// ```
+    pub fn new_with_session(name: &str, session_id: SessionId) -> Ref<Logger> {
         let name_raw = CString::new(name).unwrap();
-        let handle = unsafe { BNLogCreateLogger(name_raw.as_ptr(), session_id) };
+        let handle = unsafe { BNLogCreateLogger(name_raw.as_ptr(), session_id.0) };
         unsafe {
             Ref::new(Logger {
                 handle: NonNull::new(handle).unwrap(),
-                level: LevelFilter::Debug,
             })
         }
     }
 
+    /// Name of the logger instance.
     pub fn name(&self) -> String {
         unsafe { BnString::into_string(BNLoggerGetName(self.handle.as_ptr())) }
     }
 
-    pub fn session_id(&self) -> usize {
-        unsafe { BNLoggerGetSessionId(self.handle.as_ptr()) }
-    }
-}
-
-// NOTE: Due to the ref counted core object, we must impl on the ref counted object.
-// NOTE: If we wanted to be less specific than we would need Ref to impl Copy
-impl Ref<Logger> {
-    pub fn with_level(mut self, level: LevelFilter) -> Ref<Logger> {
-        self.level = level;
-        self
-    }
-
-    /// Calling this will set the global logger to `self`.
+    /// The [`SessionId`] associated with the logger instance.
     ///
-    /// NOTE: There is no guarantee that logs will be sent to BinaryNinja as another log sink
-    /// may have already been initialized beforehand.
-    pub fn init(self) {
-        log::set_max_level(self.level);
-        let _ = log::set_boxed_logger(Box::new(self));
+    /// The [`SessionId`] is how the core knows to associate logs with a specific opened binary,
+    /// hiding other sessions (binaries) logs when not active in the UI.
+    pub fn session_id(&self) -> Option<SessionId> {
+        let raw = unsafe { BNLoggerGetSessionId(self.handle.as_ptr()) };
+        match raw {
+            0 => None,
+            _ => Some(SessionId(raw)),
+        }
     }
 
-    /// Send a log to the logger instance, if you instead want to use the `log` crate and its facilities,
-    /// you should use [`Ref<Logger>::init`] to initialize the `log` compatible logger.
-    pub fn send_log(&self, level: Level, msg: &str) {
-        use binaryninjacore_sys::BNLog;
-        if let Ok(msg) = CString::new(msg) {
-            let logger_name = self.name().to_cstr();
-            unsafe {
-                BNLog(
-                    self.session_id(),
-                    level,
-                    logger_name.as_ptr(),
-                    0,
-                    c"%s".as_ptr(),
-                    msg.as_ptr(),
-                )
-            }
-        }
+    /// Send a log to the logger instance.
+    ///
+    /// If you do not have a [`Logger`] you may call [`bn_log`] or [`bn_log_with_session`].
+    pub fn log(&self, level: BnLogLevel, msg: &str) {
+        let session = self.session_id().unwrap_or(LOGGER_DEFAULT_SESSION_ID);
+        bn_log_with_session(session, &self.name(), level, msg);
     }
 }
 
@@ -130,7 +121,6 @@ unsafe impl RefCountable for Logger {
     unsafe fn inc_ref(logger: &Self) -> Ref<Self> {
         Ref::new(Self {
             handle: NonNull::new(BNNewLoggerReference(logger.handle.as_ptr())).unwrap(),
-            level: logger.level,
         })
     }
 
@@ -139,44 +129,67 @@ unsafe impl RefCountable for Logger {
     }
 }
 
-impl log::Log for Ref<Logger> {
-    fn enabled(&self, _metadata: &log::Metadata) -> bool {
-        true
-    }
+unsafe impl Send for Logger {}
+unsafe impl Sync for Logger {}
 
-    fn log(&self, record: &log::Record) {
-        use self::Level::*;
-        let level = match record.level() {
-            log::Level::Error => ErrorLog,
-            log::Level::Warn => WarningLog,
-            log::Level::Info => InfoLog,
-            log::Level::Debug | log::Level::Trace => DebugLog,
-        };
-        self.send_log(level, &format!("{}", record.args()));
+/// Register a [`LogListener`] that will receive log messages **from the core**.
+///
+/// This is typically used in headless usage. It can also be used to temporarily log core
+/// messages to something like a file while some analysis is occurring, once the [`LogGuard`] is
+/// dropped, the listener will be unregistered.
+pub fn register_log_listener<L: LogListener>(listener: L) -> LogGuard<L> {
+    use binaryninjacore_sys::BNRegisterLogListener;
+
+    let raw = Box::into_raw(Box::new(listener));
+    let mut bn_obj = BNLogListener {
+        context: raw as *mut _,
+        log: Some(cb_log::<L>),
+        logWithStackTrace: Some(cb_log_with_stack_trace::<L>),
+        close: Some(cb_close::<L>),
+        getLogLevel: Some(cb_level::<L>),
+    };
+
+    unsafe {
+        BNRegisterLogListener(&mut bn_obj);
+        BNUpdateLogListeners();
     }
 
-    fn flush(&self) {}
+    LogGuard { ctxt: raw }
 }
 
-unsafe impl Send for Logger {}
-unsafe impl Sync for Logger {}
+/// The context associated with a log message received from the core as part of a [`LogListener`].
+#[derive(Debug, Clone, PartialEq, Eq, PartialOrd, Ord, Hash)]
+pub struct LogContext<'a> {
+    /// The optional [`SessionId`] associated with the log message.
+    ///
+    /// This will correspond with a [`BinaryView`] file's [`SessionId`].
+    pub session_id: Option<SessionId>,
+    /// The thread ID associated with the log message.
+    pub thread_id: usize,
+    /// The optional stack trace associated with the log message.
+    pub stack_trace: Option<&'a str>,
+    /// The target [`Logger`] for the log message.
+    pub logger_name: &'a str,
+}
 
+/// The trait implemented by objects that wish to receive log messages from the core.
+///
+/// Currently, we supply one implementation of this trait called [`crate::tracing::TracingLogListener`]
+/// which will send the core logs to the registered tracing subscriber.
 pub trait LogListener: 'static + Sync {
-    fn log(&self, session: usize, level: Level, msg: &str, logger_name: &str, tid: usize);
-    fn level(&self) -> Level;
-    fn close(&self) {}
+    /// Called when a log message is received from the core.
+    ///
+    /// Logs will only be sent that are above the desired [`LogListener::level`].
+    fn log(&self, ctx: &LogContext, lvl: BnLogLevel, msg: &str);
 
-    fn log_with_stack_trace(
-        &self,
-        session: usize,
-        level: Level,
-        _stack_trace: &str,
-        msg: &str,
-        logger_name: &str,
-        tid: usize,
-    ) {
-        self.log(session, level, msg, logger_name, tid);
-    }
+    /// The desired minimum log level, any logs below this level will be ignored.
+    ///
+    /// For example, returning [`BnLogLevel::InfoLog`] will result in [`BnLogLevel::DebugLog`] logs
+    /// being ignored by this listener.
+    fn level(&self) -> BnLogLevel;
+
+    /// Called when the listener is unregistered.
+    fn close(&self) {}
 }
 
 pub struct LogGuard<L: LogListener> {
@@ -204,30 +217,10 @@ impl<L: LogListener> Drop for LogGuard<L> {
     }
 }
 
-pub fn register_listener<L: LogListener>(listener: L) -> LogGuard<L> {
-    use binaryninjacore_sys::BNRegisterLogListener;
-
-    let raw = Box::into_raw(Box::new(listener));
-    let mut bn_obj = BNLogListener {
-        context: raw as *mut _,
-        log: Some(cb_log::<L>),
-        logWithStackTrace: Some(cb_log_with_stack_trace::<L>),
-        close: Some(cb_close::<L>),
-        getLogLevel: Some(cb_level::<L>),
-    };
-
-    unsafe {
-        BNRegisterLogListener(&mut bn_obj);
-        BNUpdateLogListeners();
-    }
-
-    LogGuard { ctxt: raw }
-}
-
 extern "C" fn cb_log<L>(
     ctxt: *mut c_void,
     session: usize,
-    level: Level,
+    level: BnLogLevel,
     msg: *const c_char,
     logger_name: *const c_char,
     tid: usize,
@@ -238,14 +231,24 @@ extern "C" fn cb_log<L>(
         let listener = &*(ctxt as *const L);
         let msg_str = raw_to_string(msg).unwrap();
         let logger_name_str = raw_to_string(logger_name).unwrap();
-        listener.log(session, level, &msg_str, &logger_name_str, tid);
+        let session_id = match session {
+            0 => None,
+            _ => Some(SessionId(session)),
+        };
+        let ctx = LogContext {
+            session_id,
+            thread_id: tid,
+            stack_trace: None,
+            logger_name: &logger_name_str,
+        };
+        listener.log(&ctx, level, &msg_str);
     })
 }
 
 extern "C" fn cb_log_with_stack_trace<L>(
     ctxt: *mut c_void,
     session: usize,
-    level: Level,
+    level: BnLogLevel,
     stack_trace: *const c_char,
     msg: *const c_char,
     logger_name: *const c_char,
@@ -258,14 +261,17 @@ extern "C" fn cb_log_with_stack_trace<L>(
         let stack_trace_str = raw_to_string(stack_trace).unwrap();
         let msg_str = raw_to_string(msg).unwrap();
         let logger_name_str = raw_to_string(logger_name).unwrap();
-        listener.log_with_stack_trace(
-            session,
-            level,
-            &stack_trace_str,
-            &msg_str,
-            &logger_name_str,
-            tid,
-        );
+        let session_id = match session {
+            0 => None,
+            _ => Some(SessionId(session)),
+        };
+        let ctx = LogContext {
+            session_id,
+            thread_id: tid,
+            stack_trace: Some(&stack_trace_str),
+            logger_name: &logger_name_str,
+        };
+        listener.log(&ctx, level, &msg_str);
     })
 }
 
@@ -279,7 +285,7 @@ where
     })
 }
 
-extern "C" fn cb_level<L>(ctxt: *mut c_void) -> Level
+extern "C" fn cb_level<L>(ctxt: *mut c_void) -> BnLogLevel
 where
     L: LogListener,
 {