diff options
| author | Mason Reed <mason@vector35.com> | 2025-12-17 21:23:46 -0500 |
|---|---|---|
| committer | Mason Reed <35282038+emesare@users.noreply.github.com> | 2026-01-11 10:36:01 -0800 |
| commit | 168a3fd34824adc9c6a606cd144219701f15cccf (patch) | |
| tree | 9bbac31ece5ea6ab6627998d995a77f7f7e2f8e6 /rust | |
| parent | ca91bc1933976c62d24248f0f7c35af38451ff11 (diff) | |
[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.
Diffstat (limited to 'rust')
| -rw-r--r-- | rust/Cargo.toml | 6 | ||||
| -rw-r--r-- | rust/plugin_examples/data_renderer/src/lib.rs | 5 | ||||
| -rw-r--r-- | rust/src/architecture.rs | 28 | ||||
| -rw-r--r-- | rust/src/architecture/flag.rs | 8 | ||||
| -rw-r--r-- | rust/src/architecture/intrinsic.rs | 2 | ||||
| -rw-r--r-- | rust/src/architecture/register.rs | 4 | ||||
| -rw-r--r-- | rust/src/command.rs | 183 | ||||
| -rw-r--r-- | rust/src/custom_binary_view.rs | 52 | ||||
| -rw-r--r-- | rust/src/ffi.rs | 40 | ||||
| -rw-r--r-- | rust/src/file_accessor.rs | 1 | ||||
| -rw-r--r-- | rust/src/file_metadata.rs | 17 | ||||
| -rw-r--r-- | rust/src/lib.rs | 1 | ||||
| -rw-r--r-- | rust/src/logger.rs | 288 | ||||
| -rw-r--r-- | rust/src/low_level_il/expression.rs | 3 | ||||
| -rw-r--r-- | rust/src/low_level_il/lifting.rs | 6 | ||||
| -rw-r--r-- | rust/src/low_level_il/operation.rs | 6 | ||||
| -rw-r--r-- | rust/src/tracing.rs | 305 | ||||
| -rw-r--r-- | rust/src/workflow/activity.rs | 4 |
18 files changed, 600 insertions, 359 deletions
diff --git a/rust/Cargo.toml b/rust/Cargo.toml index 4856f97b..2d7aa6a5 100644 --- a/rust/Cargo.toml +++ b/rust/Cargo.toml @@ -18,14 +18,16 @@ demo = ["no_exports"] core = ["binaryninjacore-sys/core"] [dependencies] -log = { version = "0.4", features = ["std"] } rayon = { version = "1.10", optional = true } -binaryninjacore-sys = { path = "binaryninjacore-sys", default-features = false} +binaryninjacore-sys = { path = "binaryninjacore-sys", default-features = false } thiserror = "2.0" serde = "1.0" serde_derive = "1.0" # Parts of the collaboration and workflow APIs consume and produce JSON. serde_json = "1.0" +# Used for tracing compatible logs +tracing = { version = "0.1", default-features = false, features = ["std"] } +tracing-subscriber = { version = "0.3", default-features = false, features = ["std", "registry", "smallvec", "parking_lot"] } [dev-dependencies] rstest = "0.24" diff --git a/rust/plugin_examples/data_renderer/src/lib.rs b/rust/plugin_examples/data_renderer/src/lib.rs index 178402af..97b81f23 100644 --- a/rust/plugin_examples/data_renderer/src/lib.rs +++ b/rust/plugin_examples/data_renderer/src/lib.rs @@ -100,9 +100,8 @@ impl CustomDataRenderer for UuidDataRenderer { #[unsafe(no_mangle)] pub unsafe extern "C" fn CorePluginInit() -> bool { // Initialize logging - binaryninja::logger::Logger::new("UUID Data Renderer") - .with_level(log::LevelFilter::Debug) - .init(); + binaryninja::tracing_init!(); + binaryninja::tracing::info!("Core plugin initialized"); // Register data renderer register_data_renderer(UuidDataRenderer {}); diff --git a/rust/src/architecture.rs b/rust/src/architecture.rs index 1a6253b0..669b84c8 100644 --- a/rust/src/architecture.rs +++ b/rust/src/architecture.rs @@ -68,32 +68,6 @@ pub use instruction::*; pub use intrinsic::*; pub use register::*; -#[macro_export] -macro_rules! new_id_type { - ($name:ident, $inner_type:ty) => { - #[derive(std::fmt::Debug, Clone, Copy, PartialEq, Eq, Hash, PartialOrd, Ord)] - pub struct $name(pub $inner_type); - - impl From<$inner_type> for $name { - fn from(value: $inner_type) -> Self { - Self(value) - } - } - - impl From<$name> for $inner_type { - fn from(value: $name) -> Self { - value.0 - } - } - - impl std::fmt::Display for $name { - fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result { - write!(f, "{}", self.0) - } - } - }; -} - /// The [`Architecture`] trait is the backbone of Binary Ninja's analysis capabilities. It tells the /// core how to interpret the machine code into LLIL, a generic intermediate representation for /// program analysis. @@ -1852,7 +1826,7 @@ where return expr.index.0; } } else { - log::warn!( + tracing::warn!( "unable to unpack flag write op: {:?} with {} operands", op, operands.len() diff --git a/rust/src/architecture/flag.rs b/rust/src/architecture/flag.rs index 7c0f5deb..4cbd2dc1 100644 --- a/rust/src/architecture/flag.rs +++ b/rust/src/architecture/flag.rs @@ -9,11 +9,11 @@ use std::hash::Hash; pub use binaryninjacore_sys::BNFlagRole as FlagRole; pub use binaryninjacore_sys::BNLowLevelILFlagCondition as FlagCondition; -crate::new_id_type!(FlagId, u32); +new_id_type!(FlagId, u32); // TODO: Make this NonZero<u32>? -crate::new_id_type!(FlagWriteId, u32); -crate::new_id_type!(FlagClassId, u32); -crate::new_id_type!(FlagGroupId, u32); +new_id_type!(FlagWriteId, u32); +new_id_type!(FlagClassId, u32); +new_id_type!(FlagGroupId, u32); pub trait Flag: Debug + Sized + Clone + Copy + Hash + Eq { type FlagClass: FlagClass; diff --git a/rust/src/architecture/intrinsic.rs b/rust/src/architecture/intrinsic.rs index 5d9827a1..a00b1e79 100644 --- a/rust/src/architecture/intrinsic.rs +++ b/rust/src/architecture/intrinsic.rs @@ -11,7 +11,7 @@ use std::borrow::Cow; use std::ffi::CStr; use std::fmt::{Debug, Formatter}; -crate::new_id_type!(IntrinsicId, u32); +new_id_type!(IntrinsicId, u32); pub trait Intrinsic: Debug + Sized + Clone + Copy { fn name(&self) -> Cow<'_, str>; diff --git a/rust/src/architecture/register.rs b/rust/src/architecture/register.rs index 1f17c785..0f760844 100644 --- a/rust/src/architecture/register.rs +++ b/rust/src/architecture/register.rs @@ -6,7 +6,7 @@ use std::ffi::CStr; use std::fmt::{Debug, Formatter}; use std::hash::Hash; -crate::new_id_type!(RegisterId, u32); +new_id_type!(RegisterId, u32); impl RegisterId { pub fn is_temporary(&self) -> bool { @@ -14,7 +14,7 @@ impl RegisterId { } } -crate::new_id_type!(RegisterStackId, u32); +new_id_type!(RegisterStackId, u32); #[derive(Debug, Copy, Clone, Eq, PartialEq, Hash)] pub enum ImplicitRegisterExtend { diff --git a/rust/src/command.rs b/rust/src/command.rs index 660e265b..9f585633 100644 --- a/rust/src/command.rs +++ b/rust/src/command.rs @@ -100,42 +100,31 @@ pub fn register_command<C: Command>(name: &str, desc: &str, command: C) { where C: Command, { - ffi_wrap!("Command::action", unsafe { - let cmd = &*(ctxt as *const C); - - debug_assert!(!view.is_null()); - let view = BinaryView { handle: view }; - - cmd.action(&view); - }) + let cmd = unsafe { &*(ctxt as *const C) }; + debug_assert!(!view.is_null()); + let view = BinaryView { handle: view }; + let _span = ffi_span!("Command::action", view); + cmd.action(&view); } extern "C" fn cb_valid<C>(ctxt: *mut c_void, view: *mut BNBinaryView) -> bool where C: Command, { - ffi_wrap!("Command::valid", unsafe { - let cmd = &*(ctxt as *const C); - - debug_assert!(!view.is_null()); - let view = BinaryView { handle: view }; - - cmd.valid(&view) - }) + let cmd = unsafe { &*(ctxt as *const C) }; + debug_assert!(!view.is_null()); + let view = BinaryView { handle: view }; + let _span = ffi_span!("Command::valid", view); + cmd.valid(&view) } let name = name.to_cstr(); let desc = desc.to_cstr(); - - let name_ptr = name.as_ptr(); - let desc_ptr = desc.as_ptr(); - let ctxt = Box::into_raw(Box::new(command)); - unsafe { BNRegisterPluginCommand( - name_ptr, - desc_ptr, + name.as_ptr(), + desc.as_ptr(), Some(cb_action::<C>), Some(cb_valid::<C>), ctxt as *mut _, @@ -197,42 +186,31 @@ pub fn register_command_for_address<C: AddressCommand>(name: &str, desc: &str, c where C: AddressCommand, { - ffi_wrap!("AddressCommand::action", unsafe { - let cmd = &*(ctxt as *const C); - - debug_assert!(!view.is_null()); - let view = BinaryView { handle: view }; - - cmd.action(&view, addr); - }) + let cmd = unsafe { &*(ctxt as *const C) }; + debug_assert!(!view.is_null()); + let view = BinaryView { handle: view }; + let _span = ffi_span!("AddressCommand::action", view); + cmd.action(&view, addr); } extern "C" fn cb_valid<C>(ctxt: *mut c_void, view: *mut BNBinaryView, addr: u64) -> bool where C: AddressCommand, { - ffi_wrap!("AddressCommand::valid", unsafe { - let cmd = &*(ctxt as *const C); - - debug_assert!(!view.is_null()); - let view = BinaryView { handle: view }; - - cmd.valid(&view, addr) - }) + let cmd = unsafe { &*(ctxt as *const C) }; + debug_assert!(!view.is_null()); + let view = BinaryView { handle: view }; + let _span = ffi_span!("AddressCommand::valid", view); + cmd.valid(&view, addr) } let name = name.to_cstr(); let desc = desc.to_cstr(); - - let name_ptr = name.as_ptr(); - let desc_ptr = desc.as_ptr(); - let ctxt = Box::into_raw(Box::new(command)); - unsafe { BNRegisterPluginCommandForAddress( - name_ptr, - desc_ptr, + name.as_ptr(), + desc.as_ptr(), Some(cb_action::<C>), Some(cb_valid::<C>), ctxt as *mut _, @@ -298,14 +276,11 @@ where where C: RangeCommand, { - ffi_wrap!("RangeCommand::action", unsafe { - let cmd = &*(ctxt as *const C); - - debug_assert!(!view.is_null()); - let view = BinaryView { handle: view }; - - cmd.action(&view, addr..addr.wrapping_add(len)); - }) + let cmd = unsafe { &*(ctxt as *const C) }; + debug_assert!(!view.is_null()); + let view = BinaryView { handle: view }; + let _span = ffi_span!("RangeCommand::action", view); + cmd.action(&view, addr..addr.wrapping_add(len)); } extern "C" fn cb_valid<C>( @@ -317,28 +292,20 @@ where where C: RangeCommand, { - ffi_wrap!("RangeCommand::valid", unsafe { - let cmd = &*(ctxt as *const C); - - debug_assert!(!view.is_null()); - let view = BinaryView { handle: view }; - - cmd.valid(&view, addr..addr.wrapping_add(len)) - }) + let cmd = unsafe { &*(ctxt as *const C) }; + debug_assert!(!view.is_null()); + let view = BinaryView { handle: view }; + let _span = ffi_span!("RangeCommand::valid", view); + cmd.valid(&view, addr..addr.wrapping_add(len)) } let name = name.to_cstr(); let desc = desc.to_cstr(); - - let name_ptr = name.as_ptr(); - let desc_ptr = desc.as_ptr(); - let ctxt = Box::into_raw(Box::new(command)); - unsafe { BNRegisterPluginCommandForRange( - name_ptr, - desc_ptr, + name.as_ptr(), + desc.as_ptr(), Some(cb_action::<C>), Some(cb_valid::<C>), ctxt as *mut _, @@ -401,17 +368,13 @@ pub fn register_command_for_function<C: FunctionCommand>(name: &str, desc: &str, where C: FunctionCommand, { - ffi_wrap!("FunctionCommand::action", unsafe { - let cmd = &*(ctxt as *const C); - - debug_assert!(!view.is_null()); - let view = BinaryView { handle: view }; - - debug_assert!(!func.is_null()); - let func = Function { handle: func }; - - cmd.action(&view, &func); - }) + let cmd = unsafe { &*(ctxt as *const C) }; + debug_assert!(!view.is_null()); + let view = BinaryView { handle: view }; + debug_assert!(!func.is_null()); + let func = Function { handle: func }; + let _span = ffi_span!("FunctionCommand::action", view); + cmd.action(&view, &func); } extern "C" fn cb_valid<C>( @@ -422,31 +385,22 @@ pub fn register_command_for_function<C: FunctionCommand>(name: &str, desc: &str, where C: FunctionCommand, { - ffi_wrap!("FunctionCommand::valid", unsafe { - let cmd = &*(ctxt as *const C); - - debug_assert!(!view.is_null()); - let view = BinaryView { handle: view }; - - debug_assert!(!func.is_null()); - let func = Function { handle: func }; - - cmd.valid(&view, &func) - }) + let cmd = unsafe { &*(ctxt as *const C) }; + debug_assert!(!view.is_null()); + let view = BinaryView { handle: view }; + debug_assert!(!func.is_null()); + let func = Function { handle: func }; + let _span = ffi_span!("FunctionCommand::valid", view); + cmd.valid(&view, &func) } let name = name.to_cstr(); let desc = desc.to_cstr(); - - let name_ptr = name.as_ptr(); - let desc_ptr = desc.as_ptr(); - let ctxt = Box::into_raw(Box::new(command)); - unsafe { BNRegisterPluginCommandForFunction( - name_ptr, - desc_ptr, + name.as_ptr(), + desc.as_ptr(), Some(cb_action::<C>), Some(cb_valid::<C>), ctxt as *mut _, @@ -464,42 +418,29 @@ pub fn register_command_for_project<C: ProjectCommand>(name: &str, desc: &str, c where C: ProjectCommand, { - ffi_wrap!("Command::action", unsafe { - let cmd = &*(ctxt as *const C); - - let handle = NonNull::new(project).expect("project handle is null"); - let project = Project { handle }; - - cmd.action(&project); - }) + let cmd = unsafe { &*(ctxt as *const C) }; + let handle = NonNull::new(project).expect("project handle is null"); + let project = Project { handle }; + cmd.action(&project); } extern "C" fn cb_valid<C>(ctxt: *mut c_void, project: *mut BNProject) -> bool where C: ProjectCommand, { - ffi_wrap!("Command::valid", unsafe { - let cmd = &*(ctxt as *const C); - - let handle = NonNull::new(project).expect("project handle is null"); - let project = Project { handle }; - - cmd.valid(&project) - }) + let cmd = unsafe { &*(ctxt as *const C) }; + let handle = NonNull::new(project).expect("project handle is null"); + let project = Project { handle }; + cmd.valid(&project) } let name = name.to_cstr(); let desc = desc.to_cstr(); - - let name_ptr = name.as_ptr(); - let desc_ptr = desc.as_ptr(); - let ctxt = Box::into_raw(Box::new(command)); - unsafe { BNRegisterPluginCommandForProject( - name_ptr, - desc_ptr, + name.as_ptr(), + desc.as_ptr(), Some(cb_action::<C>), Some(cb_valid::<C>), ctxt as *mut _, diff --git a/rust/src/custom_binary_view.rs b/rust/src/custom_binary_view.rs index aff7b3b6..8e070b15 100644 --- a/rust/src/custom_binary_view.rs +++ b/rust/src/custom_binary_view.rs @@ -96,10 +96,7 @@ where // to the core -- we're transferring ownership of the Ref here Ref::into_raw(bv.handle).handle } - Err(_) => { - log::error!("CustomBinaryViewType::create_custom_view returned Err"); - ptr::null_mut() - } + Err(_) => ptr::null_mut(), } }) } @@ -124,10 +121,7 @@ where // to the core -- we're transferring ownership of the Ref here Ref::into_raw(bv.handle).handle } - Err(_) => { - log::error!("CustomBinaryViewType::parse returned Err"); - ptr::null_mut() - } + Err(_) => ptr::null_mut(), } }) } @@ -173,7 +167,6 @@ where // be one since view types live for the life of the process) as // MaybeUninit suppress the Drop implementation of it's inner type drop(Box::from_raw(ctxt)); - panic!("bvt registration failed"); } @@ -303,10 +296,7 @@ pub trait BinaryViewTypeExt: BinaryViewTypeBase { let handle = unsafe { BNCreateBinaryViewOfType(self.as_ref().handle, data.handle) }; if handle.is_null() { - log::error!( - "failed to create BinaryView of BinaryViewType '{}'", - self.name() - ); + // TODO: Proper Result, possibly introduce BNSetError to populate. return Err(()); } @@ -317,10 +307,7 @@ pub trait BinaryViewTypeExt: BinaryViewTypeBase { let handle = unsafe { BNParseBinaryViewOfType(self.as_ref().handle, data.handle) }; if handle.is_null() { - log::error!( - "failed to parse BinaryView of BinaryViewType '{}'", - self.name() - ); + // TODO: Proper Result, possibly introduce BNSetError to populate. return Err(()); } @@ -503,7 +490,7 @@ impl<'a, T: CustomBinaryViewType> CustomViewBuilder<'a, T> { if let Some(bv) = file.view_of_type(&view_name) { // while it seems to work most of the time, you can get really unlucky - // if the a free of the existing view of the same type kicks off while + // if a free of the existing view of the same type kicks off while // BNCreateBinaryViewOfType is still running. the freeObject callback // will run for the new view before we've even finished initializing, // and that's all she wrote. @@ -511,7 +498,7 @@ impl<'a, T: CustomBinaryViewType> CustomViewBuilder<'a, T> { // even if we deal with it gracefully in cb_free_object, // BNCreateBinaryViewOfType is still going to crash, so we're just // going to try and stop this from happening in the first place. - log::error!( + tracing::error!( "attempt to create duplicate view of type '{}' (existing: {:?})", view_name, bv.handle @@ -572,12 +559,14 @@ impl<'a, T: CustomBinaryViewType> CustomViewBuilder<'a, T> { true } Err(_) => { - log::error!("CustomBinaryView::init failed; custom view returned Err"); + tracing::error!( + "CustomBinaryView::init failed; custom view returned Err" + ); false } }, Err(_) => { - log::error!("CustomBinaryView::new failed; custom view returned Err"); + tracing::error!("CustomBinaryView::new failed; custom view returned Err"); false } } @@ -607,7 +596,7 @@ impl<'a, T: CustomBinaryViewType> CustomViewBuilder<'a, T> { // // if we're here, it's too late to do anything about it, though we can at least not // run the destructor on the custom view since that memory is uninitialized. - log::error!( + tracing::error!( "BinaryViewBase::freeObject called on partially initialized object! crash imminent!" ); } else if matches!( @@ -626,7 +615,7 @@ impl<'a, T: CustomBinaryViewType> CustomViewBuilder<'a, T> { // // we can't do anything to prevent this, but we can at least have the crash // not be our fault. - log::error!("BinaryViewBase::freeObject called on leaked/never initialized custom view!"); + tracing::error!("BinaryViewBase::freeObject called on leaked/never initialized custom view!"); } }) } @@ -884,20 +873,11 @@ impl<'a, T: CustomBinaryViewType> CustomViewBuilder<'a, T> { parent.handle, &mut bn_obj, ); - - if res.is_null() { - // TODO not sure when this can even happen, let alone what we're supposed to do about - // it. cb_init isn't normally called until later, and cb_free_object definitely won't - // have been called, so we'd at least be on the hook for freeing that stuff... - // probably. - // - // no idea how to force this to fail so I can test this, so just going to do the - // reasonable thing and panic. - panic!("failed to create custom binary view!"); - } - + assert!( + !res.is_null(), + "BNCreateCustomBinaryView cannot return null" + ); (*ctxt).raw_handle = res; - Ok(CustomView { handle: BinaryView::ref_from_raw(res), _builder: PhantomData, diff --git a/rust/src/ffi.rs b/rust/src/ffi.rs index d337df34..b6124dd4 100644 --- a/rust/src/ffi.rs +++ b/rust/src/ffi.rs @@ -20,7 +20,7 @@ macro_rules! ffi_wrap { use std::process; panic::catch_unwind(|| $b).unwrap_or_else(|_| { - log::error!("ffi callback caught panic: {}", $n); + tracing::error!("ffi callback caught panic: {}", $n); process::abort() }) }}; @@ -30,3 +30,41 @@ pub(crate) fn time_from_bn(timestamp: u64) -> SystemTime { let m = Duration::from_secs(timestamp); UNIX_EPOCH + m } + +#[macro_export] +macro_rules! ffi_span { + ($name:expr, $bv:expr) => {{ + use $crate::binary_view::BinaryViewExt; + #[allow(unused_imports)] + use $crate::file_metadata::FileMetadata; + tracing::info_span!($name, session_id = $bv.file().session_id().0).entered() + }}; + ($name:expr) => { + tracing::info_span!($name).entered() + }; +} + +macro_rules! new_id_type { + ($name:ident, $inner_type:ty) => { + #[derive(std::fmt::Debug, Clone, Copy, PartialEq, Eq, Hash, PartialOrd, Ord)] + pub struct $name(pub $inner_type); + + impl From<$inner_type> for $name { + fn from(value: $inner_type) -> Self { + Self(value) + } + } + + impl From<$name> for $inner_type { + fn from(value: $name) -> Self { + value.0 + } + } + + impl std::fmt::Display for $name { + fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result { + write!(f, "{}", self.0) + } + } + }; +} diff --git a/rust/src/file_accessor.rs b/rust/src/file_accessor.rs index dd6626f6..54bd3eba 100644 --- a/rust/src/file_accessor.rs +++ b/rust/src/file_accessor.rs @@ -46,7 +46,6 @@ impl<A: Accessor> FileAccessor<A> { let dest = unsafe { slice::from_raw_parts_mut(dest as *mut u8, len) }; if f.seek(SeekFrom::Start(offset)).is_err() { - log::debug!("Failed to seek to offset {:x}", offset); 0 } else { f.read(dest).unwrap_or(0) diff --git a/rust/src/file_metadata.rs b/rust/src/file_metadata.rs index 20f0aff5..27ceb4af 100644 --- a/rust/src/file_metadata.rs +++ b/rust/src/file_metadata.rs @@ -16,15 +16,7 @@ use crate::binary_view::BinaryView; use crate::database::Database; use crate::rc::*; use crate::string::*; -use binaryninjacore_sys::{ - BNBeginUndoActions, BNCloseFile, BNCommitUndoActions, BNCreateDatabase, BNCreateFileMetadata, - BNFileMetadata, BNFileMetadataGetSessionId, BNForgetUndoActions, BNFreeFileMetadata, - BNGetCurrentOffset, BNGetCurrentView, BNGetExistingViews, BNGetFileMetadataDatabase, - BNGetFileViewOfType, BNGetFilename, BNGetProjectFile, BNIsAnalysisChanged, - BNIsBackedByDatabase, BNIsFileModified, BNMarkFileModified, BNMarkFileSaved, BNNavigate, - BNNewFileReference, BNOpenDatabaseForConfiguration, BNOpenExistingDatabase, BNRedo, - BNRevertUndoActions, BNSaveAutoSnapshot, BNSetFilename, BNUndo, -}; +use binaryninjacore_sys::*; use binaryninjacore_sys::{BNCreateDatabaseWithProgress, BNOpenExistingDatabaseWithProgress}; use std::ffi::c_void; use std::fmt::{Debug, Display, Formatter}; @@ -34,6 +26,8 @@ use crate::progress::ProgressCallback; use crate::project::file::ProjectFile; use std::ptr::{self, NonNull}; +new_id_type!(SessionId, usize); + #[derive(PartialEq, Eq, Hash)] pub struct FileMetadata { pub(crate) handle: *mut BNFileMetadata, @@ -64,8 +58,9 @@ impl FileMetadata { } } - pub fn session_id(&self) -> usize { - unsafe { BNFileMetadataGetSessionId(self.handle) } + pub fn session_id(&self) -> SessionId { + let raw = unsafe { BNFileMetadataGetSessionId(self.handle) }; + SessionId(raw) } pub fn filename(&self) -> String { diff --git a/rust/src/lib.rs b/rust/src/lib.rs index 769280fb..10719f9a 100644 --- a/rust/src/lib.rs +++ b/rust/src/lib.rs @@ -82,6 +82,7 @@ pub mod string; pub mod symbol; pub mod tags; pub mod template_simplifier; +pub mod tracing; pub mod types; pub mod update; pub mod variable; 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, { diff --git a/rust/src/low_level_il/expression.rs b/rust/src/low_level_il/expression.rs index 1e4ab21b..8103518c 100644 --- a/rust/src/low_level_il/expression.rs +++ b/rust/src/low_level_il/expression.rs @@ -536,8 +536,7 @@ where } _ => { - // #[cfg(debug_assertions)] - log::error!( + tracing::error!( "Got unexpected operation {:?} in value expr at 0x{:x}", op.operation, op.address diff --git a/rust/src/low_level_il/lifting.rs b/rust/src/low_level_il/lifting.rs index bab0906c..d162b3f6 100644 --- a/rust/src/low_level_il/lifting.rs +++ b/rust/src/low_level_il/lifting.rs @@ -533,7 +533,7 @@ macro_rules! prim_int_lifter { }; if !is_safe { - log::error!("il @ {:x} attempted to lift constant 0x{:x} as {} byte expr (won't fit!)", + tracing::error!("il @ {:x} attempted to lift constant 0x{:x} as {} byte expr (won't fit!)", il.current_address(), val, size); } } @@ -660,7 +660,7 @@ impl<'a> LiftableLowLevelILWithSize<'a> for LowLevelILExpression<'a, Mutable, No use crate::low_level_il::ExpressionHandler; if let Some(expr_size) = expr.kind().size() { if expr_size != _size { - log::warn!( + tracing::warn!( "il @ {:x} attempted to lift {} byte expression as {} bytes", il.current_address(), expr_size, @@ -788,7 +788,7 @@ impl<'a> LiftableLowLevelILWithSize<'a> for ExpressionBuilder<'a, ValueExpr> { use binaryninjacore_sys::BNLowLevelILOperation::{LLIL_UNIMPL, LLIL_UNIMPL_MEM}; if expr.size != _size && ![LLIL_UNIMPL, LLIL_UNIMPL_MEM].contains(&expr.op) { - log::warn!( + tracing::warn!( "il @ {:x} attempted to lift {} byte expression builder as {} bytes", il.current_address(), expr.size, diff --git a/rust/src/low_level_il/operation.rs b/rust/src/low_level_il/operation.rs index f8bbc3c6..8f94b74f 100644 --- a/rust/src/low_level_il/operation.rs +++ b/rust/src/low_level_il/operation.rs @@ -1745,7 +1745,7 @@ where }; if !is_safe { - log::error!( + tracing::error!( "il expr @ {:x} contains constant 0x{:x} as {} byte value (doesn't fit!)", self.op.address, self.op.operands[0], @@ -1810,7 +1810,7 @@ where } _ => { // Log error for unexpected sizes - log::error!( + tracing::error!( "il expr @ {:x} has invalid float size {} (expected 4 or 8 bytes)", self.op.address, self.op.size @@ -1858,7 +1858,7 @@ where }; if !is_safe { - log::error!( + tracing::error!( "il expr @ {:x} contains extern 0x{:x} as {} byte value (doesn't fit!)", self.op.address, self.op.operands[0], diff --git a/rust/src/tracing.rs b/rust/src/tracing.rs new file mode 100644 index 00000000..2afdcd5e --- /dev/null +++ b/rust/src/tracing.rs @@ -0,0 +1,305 @@ +// TODO: Add top level docs here. + +use crate::file_metadata::SessionId; +use crate::logger::{ + bn_log_with_session, BnLogLevel, LogContext, LogListener, LOGGER_DEFAULT_SESSION_ID, +}; +use tracing::{Event, Id, Level, Subscriber}; +use tracing_subscriber::prelude::*; + +// Re-export specific things to make it easy for the user +pub use tracing::{debug, error, info, trace, warn}; +use tracing_subscriber::layer::Context; +use tracing_subscriber::registry::LookupSpan; +use tracing_subscriber::Layer; + +/// Helper macro to initialize the [`BinaryNinjaLayer`] tracing layer for plugins. +/// +/// Maps the current crate name to the provided display name and enables target formatting. +/// Use [`init_with_layer`] if you intend on registering a [`BinaryNinjaLayer`] with non-default values. +/// +/// ## Note for Plugins +/// +/// This should **only** be called once, at the start of plugins. +/// +/// ```no_run +/// #[unsafe(no_mangle)] +/// pub unsafe extern "C" fn CorePluginInit() -> bool { +/// binaryninja::tracing_init!("MyPlugin"); +/// binaryninja::tracing::info!("Core plugin initialized"); +/// true +/// } +/// ``` +/// +/// ## Note for Headless +/// +/// This should **never** be called if you are running headlessly and as you will likely be +/// registering a [`LogListener`], which will possibly round-trip back to tracing logs and deadlock +/// the program. +#[macro_export] +macro_rules! tracing_init { + () => { + let layer = $crate::tracing::BinaryNinjaLayer::default(); + $crate::tracing::init_with_layer(layer); + }; + ($name:expr) => { + let layer = $crate::tracing::BinaryNinjaLayer::default() + .with_target_mapping(env!("CARGO_CRATE_NAME"), $name); + $crate::tracing::init_with_layer(layer); + }; +} + +/// Initialize the core tracing subscriber with the given [`BinaryNinjaLayer`]. Collects and sends logs +/// to the core. +pub fn init_with_layer(layer: BinaryNinjaLayer) { + let subscriber = tracing_subscriber::registry().with(layer); + let _ = tracing::subscriber::set_global_default(subscriber); +} + +/// Subscribes to all spans and events emitted by `tracing` and forwards them to the core logging API. +#[derive(Clone)] +pub struct BinaryNinjaLayer { + /// Rewrite mappings for the default target. + /// + /// # Example + /// + /// Given the target "my_crate::commands::analyze" and the mapping ("my_crate", "MyPlugin") the + /// target will be rewritten to "MyPlugin::commands::analyze", assuming no other rewrites occur. + pub target_mappings: Vec<(String, String)>, + /// Whether the default target should be formatted to be displayed in the "common" logger name + /// format for Binary Ninja. + /// + /// This formatting will only be applied when the target name is implicit. Explicitly provided + /// target names will be preserved as-is. + /// + /// # Example + /// + /// Given the target "my_crate::commands::analyze" the target will be rewritten to "MyCrate.Commands.Analyze". + pub format_target: bool, +} + +impl BinaryNinjaLayer { + pub fn new() -> Self { + Self::default() + } + + /// Add a target mapping which will rewrite the `old` in the default target to `new`. + /// + /// This is typically done when you have a plugin name that is verbose, and you wish to display + /// it in the logs as something else. + pub fn with_target_mapping(mut self, old: &str, new: &str) -> Self { + self.target_mappings + .push((old.to_string(), new.to_string())); + self + } + + /// Whether formatting of the default target should be applied when sending logs to the core. + pub fn with_format_target(mut self, formatted: bool) -> Self { + self.format_target = formatted; + self + } +} + +impl BinaryNinjaLayer { + /// Rewrite the target so that the logger name will be displayed in the common Binary Ninja format. + pub fn rewrite_target(&self, mut target: String) -> String { + // Formats the target such that "my_crate::commands::analyze" becomes "MyPlugin.Commands.Analyze". + let format_target = |target: &str| -> String { + let mut result = String::with_capacity(target.len()); + let mut capitalize_next = true; + let mut chars = target.chars().peekable(); + + while let Some(c) = chars.next() { + match c { + ':' if chars.peek() == Some(&':') => { + // Found "::", consume the second ':' and treat as a dot separator + chars.next(); + result.push('.'); + capitalize_next = true; + } + '.' => { + result.push('.'); + capitalize_next = true; + } + '_' => { + // Treat underscore as a separator: strip it and capitalize next + capitalize_next = true; + } + _ if capitalize_next => { + for upper in c.to_uppercase() { + result.push(upper); + } + capitalize_next = false; + } + _ => { + result.push(c); + } + } + } + + result + }; + + // Perform "my_crate" -> "MyPlugin" rewrite rules. + for (old, new) in &self.target_mappings { + target = target.replace(old, new); + } + + if self.format_target { + target = format_target(&target); + } + + target + } +} + +impl Default for BinaryNinjaLayer { + fn default() -> Self { + Self { + target_mappings: vec![("binaryninja".to_string(), "Binary Ninja".to_string())], + format_target: true, + } + } +} + +impl<S> Layer<S> for BinaryNinjaLayer +where + S: Subscriber + for<'a> LookupSpan<'a>, +{ + fn on_new_span(&self, attrs: &tracing::span::Attributes<'_>, id: &Id, ctx: Context<'_, S>) { + let span = ctx.span(id).expect("Span not found in registry"); + + let mut visitor = BnFieldVisitor::default(); + attrs.record(&mut visitor); + + // If this span has a session_id, store it in the span's extensions + if let Some(session_id) = visitor.session_id { + span.extensions_mut().insert(session_id); + } + } + + fn on_event(&self, event: &Event<'_>, ctx: Context<'_, S>) { + let level = match *event.metadata().level() { + Level::ERROR => BnLogLevel::ErrorLog, + Level::WARN => BnLogLevel::WarningLog, + Level::INFO => BnLogLevel::InfoLog, + Level::DEBUG | Level::TRACE => BnLogLevel::DebugLog, + }; + + let mut visitor = BnFieldVisitor::default(); + event.record(&mut visitor); + + // Walk up the span tree to find the session id. + // NOTE: Inserted by `BinaryNinjaLayer::on_new_span`. + let session_from_scope = || { + ctx.event_scope(event).and_then(|scope| { + scope + .from_root() + .find_map(|span| span.extensions().get::<SessionId>().copied()) + }) + }; + + // First we check the log event itself, then we check the scope context. + let session_id = visitor + .session_id + .or_else(session_from_scope) + .unwrap_or(LOGGER_DEFAULT_SESSION_ID); + + let mut logger_name = event.metadata().target().to_string(); + // Target is not overridden, we should try and apply mapping. + if let Some(module_path) = event.metadata().module_path() { + if module_path == logger_name { + // Target is the default module path, rewrite it into a more friendly format. + logger_name = self.rewrite_target(logger_name); + } + } + + bn_log_with_session(session_id, &logger_name, level, &visitor.message); + } +} + +#[derive(Default)] +struct BnFieldVisitor { + message: String, + session_id: Option<SessionId>, +} + +impl tracing::field::Visit for BnFieldVisitor { + fn record_i64(&mut self, field: &tracing::field::Field, value: i64) { + if field.name() == "session_id" { + self.session_id = Some(SessionId(value as usize)); + } + } + + fn record_u64(&mut self, field: &tracing::field::Field, value: u64) { + if field.name() == "session_id" { + self.session_id = Some(SessionId(value as usize)); + } + } + + fn record_debug(&mut self, field: &tracing::field::Field, value: &dyn std::fmt::Debug) { + if field.name() == "message" { + use std::fmt::Write; + let _ = write!(self.message, "{:?}", value); + } + } +} + +/// A [`LogListener`] that forwards logs to the registered [`Subscriber`]. +/// +/// This should **never** be registered if the [`BinaryNinjaLayer`] is active. The [`BinaryNinjaLayer`] +/// will consume our events we send in this log listener and send them back to the core, causing a +/// never-ending cycle of sending and receiving the same logs. +/// +/// Typically, you will register this listener for headless applications. You can technically use this +/// in a plugin, but it is likely that you are sending tracing logs to the core, in which case you will +/// run into the problem above. +/// +/// ```no_run +/// use binaryninja::tracing::TracingLogListener; +/// use binaryninja::logger::{register_log_listener, BnLogLevel, bn_log}; +/// use binaryninja::headless::Session; +/// +/// pub fn main() { +/// // Register our tracing subscriber, this will send tracing events to stdout. +/// tracing_subscriber::fmt::init(); +/// // Register our log listener, this will send logs from the core to our tracing subscriber. +/// let _listener = register_log_listener(TracingLogListener::new(BnLogLevel::DebugLog)); +/// // Should see logs from the core in regard to initialization show up. +/// let _session = Session::new().expect("Failed to create session"); +/// bn_log("Test", BnLogLevel::DebugLog, "Hello, world!"); +/// } +/// ``` +pub struct TracingLogListener { + minimum_level: BnLogLevel, +} + +impl TracingLogListener { + pub fn new(minimum_level: BnLogLevel) -> Self { + Self { minimum_level } + } +} + +impl LogListener for TracingLogListener { + fn log(&self, ctx: &LogContext, level: BnLogLevel, message: &str) { + let session = ctx.session_id.map(|s| s.0); + match level { + BnLogLevel::ErrorLog | BnLogLevel::AlertLog => { + error!(session_id = session, target = %ctx.logger_name, "{}", message) + } + BnLogLevel::WarningLog => { + warn!(session_id = session, target = %ctx.logger_name, "{}", message) + } + BnLogLevel::InfoLog => { + info!(session_id = session, target = %ctx.logger_name, "{}", message) + } + BnLogLevel::DebugLog => { + debug!(session_id = session, target = %ctx.logger_name, "{}", message) + } + }; + } + + fn level(&self) -> BnLogLevel { + self.minimum_level + } +} diff --git a/rust/src/workflow/activity.rs b/rust/src/workflow/activity.rs index a9afc2f1..2e5d6e80 100644 --- a/rust/src/workflow/activity.rs +++ b/rust/src/workflow/activity.rs @@ -69,7 +69,9 @@ impl Activity { ) { let ctxt = &mut *(ctxt as *mut F); if let Some(analysis) = NonNull::new(analysis) { - ctxt(&AnalysisContext::from_raw(analysis)) + let analysis = AnalysisContext::from_raw(analysis); + let _span = ffi_span!("Activity::action", analysis.view()); + ctxt(&analysis) } } let config = config.as_config(); |
