From c949e990868eaadbad47467d47977a3973681dda Mon Sep 17 00:00:00 2001 From: Tejas Mehta Date: Sun, 8 Feb 2026 16:21:35 -0500 Subject: [PATCH 1/3] feat: add feature-gated tracing/logging infrastructure - Add tracing and tracing-subscriber as optional dependencies to smb-core and smb - Create feature-gated logging macro wrappers in smb-core/src/logging.rs (no-ops when tracing feature is disabled) - Replace all println! calls with appropriate tracing macros across 18 files: - error!: unrecoverable failures in handler chain - warn!: parse failures, degraded behavior - info!: server start, connection accepted, session setup complete - debug!: command dispatch, handler delegation, message send/receive - trace!: sensitive data (keys, signatures, raw buffers, NTLM flags) - Clean up all commented-out println! calls in smb-core, smb-derive, smb - Initialize tracing-subscriber in main.rs behind #[cfg(feature = "tracing")] with RUST_LOG env var support, defaulting to info level - Features are fully independent and opt-in: - server: async runtime only, no tracing forced - tracing: structured tracing + subscriber - logging: tracing + log crate compatibility bridge --- Cargo.lock | 172 +++++++++++++++++- smb-core/Cargo.toml | 7 +- smb-core/src/lib.rs | 8 +- smb-core/src/logging.rs | 58 ++++++ smb-derive/src/attrs.rs | 15 -- smb-derive/src/field.rs | 3 - smb-derive/src/field_mapping.rs | 6 - smb/Cargo.toml | 4 + smb/src/main.rs | 15 +- .../protocol/body/create/request_context.rs | 4 +- .../protocol/body/create/response_context.rs | 4 +- smb/src/protocol/body/negotiate/context.rs | 2 +- smb/src/protocol/body/tree_connect/buffer.rs | 2 +- smb/src/protocol/message.rs | 4 +- smb/src/server/connection.rs | 28 +-- smb/src/server/message_handler.rs | 30 +-- smb/src/server/mod.rs | 12 +- smb/src/server/session.rs | 14 +- smb/src/server/share/file_system.rs | 3 +- smb/src/server/tree_connect.rs | 5 +- smb/src/socket/message_stream/mod.rs | 10 +- smb/src/socket/message_stream/stream_async.rs | 10 +- .../auth/ntlm/ntlm_authenticate_message.rs | 2 +- smb/src/util/auth/spnego/der_utils.rs | 2 +- smb/src/util/auth/spnego/spnego_token.rs | 4 +- .../util/auth/spnego/spnego_token_response.rs | 2 +- 26 files changed, 331 insertions(+), 95 deletions(-) create mode 100644 smb-core/src/logging.rs diff --git a/Cargo.lock b/Cargo.lock index 15857ae..7cb543a 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -52,6 +52,15 @@ dependencies = [ "subtle", ] +[[package]] +name = "aho-corasick" +version = "1.1.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ddd31a130427c27518df266943a5308ed92d4b226cc639f5a8f1002816174301" +dependencies = [ + "memchr", +] + [[package]] name = "anyhow" version = "1.0.95" @@ -426,12 +435,33 @@ dependencies = [ "generic-array", ] +[[package]] +name = "lazy_static" +version = "1.5.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "bbd2bcb4c963f2ddae06a2efc7e9f3591312473c50c6685e1f298068316e66fe" + [[package]] name = "libc" version = "0.2.169" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "b5aba8db14291edd000dfcc4d620c7ebfb122c613afb886ca8803fa4e128a20a" +[[package]] +name = "log" +version = "0.4.29" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "5e5032e24019045c762d3c0f28f5b6b8bbf38563a65908389bf7978758920897" + +[[package]] +name = "matchers" +version = "0.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "d1525a2a28c7f4fa0fc98bb91ae755d1e2d1505079e05539e35bc876b5d65ae9" +dependencies = [ + "regex-automata", +] + [[package]] name = "md-5" version = "0.10.6" @@ -480,7 +510,7 @@ checksum = "2886843bf800fba2e3377cff24abf6379b4c4d5c6681eaf9ea5b0d15090450bd" dependencies = [ "libc", "wasi 0.11.0+wasi-snapshot-preview1", - "windows-sys", + "windows-sys 0.52.0", ] [[package]] @@ -515,6 +545,15 @@ dependencies = [ "syn 1.0.109", ] +[[package]] +name = "nu-ansi-term" +version = "0.50.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "7957b9740744892f114936ab4a57b3f487491bbeafaf8083688b16841a4240e5" +dependencies = [ + "windows-sys 0.61.2", +] + [[package]] name = "num_enum" version = "0.5.11" @@ -682,6 +721,23 @@ dependencies = [ "cipher", ] +[[package]] +name = "regex-automata" +version = "0.4.14" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "6e1dd4122fc1595e8162618945476892eefca7b88c52820e74af6262213cae8f" +dependencies = [ + "aho-corasick", + "memchr", + "regex-syntax", +] + +[[package]] +name = "regex-syntax" +version = "0.8.9" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "a96887878f22d7bad8a3b6dc5b7440e0ada9a245242924394987b21cf2210a4c" + [[package]] name = "rustc-demangle" version = "0.1.24" @@ -725,12 +781,28 @@ dependencies = [ "digest", ] +[[package]] +name = "sharded-slab" +version = "0.1.7" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f40ca3c46823713e0d4209592e8d6e826aa57e928f09752619fc696c499637f6" +dependencies = [ + "lazy_static", +] + +[[package]] +name = "smallvec" +version = "1.15.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "67b1b7a3b5fe4f1376887184045fcf45c69e92af734b7aaddc05fb777b6fbd03" + [[package]] name = "smb-core" version = "0.1.0" dependencies = [ "num_enum", "serde", + "tracing", "uuid", ] @@ -777,6 +849,8 @@ dependencies = [ "tokio", "tokio-stream", "tokio-util", + "tracing", + "tracing-subscriber", "uuid", ] @@ -787,7 +861,7 @@ source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "c970269d99b64e60ec3bd6ad27270092a5394c4e309314b18ae3fe575695fbe8" dependencies = [ "libc", - "windows-sys", + "windows-sys 0.52.0", ] [[package]] @@ -830,6 +904,15 @@ dependencies = [ "unicode-ident", ] +[[package]] +name = "thread_local" +version = "1.1.9" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f60246a4944f24f6e018aa17cdeffb7818b76356965d03b07d6a9886e8962185" +dependencies = [ + "cfg-if", +] + [[package]] name = "tokio" version = "1.43.0" @@ -843,7 +926,7 @@ dependencies = [ "pin-project-lite", "socket2", "tokio-macros", - "windows-sys", + "windows-sys 0.52.0", ] [[package]] @@ -898,6 +981,68 @@ dependencies = [ "winnow", ] +[[package]] +name = "tracing" +version = "0.1.44" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "63e71662fa4b2a2c3a26f570f037eb95bb1f85397f3cd8076caed2f026a6d100" +dependencies = [ + "log", + "pin-project-lite", + "tracing-attributes", + "tracing-core", +] + +[[package]] +name = "tracing-attributes" +version = "0.1.31" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "7490cfa5ec963746568740651ac6781f701c9c5ea257c58e057f3ba8cf69e8da" +dependencies = [ + "proc-macro2", + "quote", + "syn 2.0.98", +] + +[[package]] +name = "tracing-core" +version = "0.1.36" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "db97caf9d906fbde555dd62fa95ddba9eecfd14cb388e4f491a66d74cd5fb79a" +dependencies = [ + "once_cell", + "valuable", +] + +[[package]] +name = "tracing-log" +version = "0.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ee855f1f400bd0e5c02d150ae5de3840039a3f54b025156404e34c23c03f47c3" +dependencies = [ + "log", + "once_cell", + "tracing-core", +] + +[[package]] +name = "tracing-subscriber" +version = "0.3.22" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "2f30143827ddab0d256fd843b7a66d164e9f271cfa0dde49142c5ca0ca291f1e" +dependencies = [ + "matchers", + "nu-ansi-term", + "once_cell", + "regex-automata", + "sharded-slab", + "smallvec", + "thread_local", + "tracing", + "tracing-core", + "tracing-log", +] + [[package]] name = "typenum" version = "1.17.0" @@ -943,6 +1088,12 @@ dependencies = [ "syn 2.0.98", ] +[[package]] +name = "valuable" +version = "0.1.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ba73ea9cf16a25df0c8caa16c51acb937d5712a8429db78a3ee29d5dcacd3a65" + [[package]] name = "version_check" version = "0.9.5" @@ -964,6 +1115,12 @@ dependencies = [ "wit-bindgen-rt", ] +[[package]] +name = "windows-link" +version = "0.2.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f0805222e57f7521d6a62e36fa9163bc891acd422f971defe97d64e70d0a4fe5" + [[package]] name = "windows-sys" version = "0.52.0" @@ -973,6 +1130,15 @@ dependencies = [ "windows-targets", ] +[[package]] +name = "windows-sys" +version = "0.61.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ae137229bcbd6cdf0f7b80a31df61766145077ddf49416a728b02cb3921ff3fc" +dependencies = [ + "windows-link", +] + [[package]] name = "windows-targets" version = "0.52.6" diff --git a/smb-core/Cargo.toml b/smb-core/Cargo.toml index 68f76ad..4b1a5c6 100644 --- a/smb-core/Cargo.toml +++ b/smb-core/Cargo.toml @@ -8,4 +8,9 @@ edition = "2024" [dependencies] uuid = "1.3.0" serde = { version = "1.0.144", features = ["derive"] } -num_enum = "0.5.7" \ No newline at end of file +num_enum = "0.5.7" +tracing = { version = "0.1", optional = true } + +[features] +tracing = ["dep:tracing"] +logging = ["tracing/log"] \ No newline at end of file diff --git a/smb-core/src/lib.rs b/smb-core/src/lib.rs index dcc5508..c6c5ee9 100644 --- a/smb-core/src/lib.rs +++ b/smb-core/src/lib.rs @@ -5,6 +5,7 @@ use uuid::Uuid; use error::SMBError; pub mod error; +pub mod logging; pub mod nt_status; @@ -31,18 +32,12 @@ impl SMBVecByteSize for Vec { fn smb_byte_size_vec(&self, align: usize, start: usize) -> usize { let align = std::cmp::max(align, 1); self.iter().fold(start, |prev, x| { - if align > 1 { - // println!("Start position for item at {prev} with align {align}"); - } let size = x.smb_byte_size(); let aligned_start = if prev % align == 0 { prev } else { prev + (align - prev % align) }; - if align > 1 { - // println!("adj Start position for item at {aligned_start} with align {align} and size {size}"); - } aligned_start + size }) - start } @@ -96,7 +91,6 @@ pub trait SMBEnumFromBytes { impl SMBVecFromBytesCnt for Vec { fn smb_from_bytes_vec_cnt(input: &[u8], align: usize, count: usize) -> SMBParseResult<&[u8], Self> where Self: Sized { - // println!("attempting to parse {:?}", count); let mut remaining = input; let mut done_cnt = 0; let mut msg_vec = Vec::::new(); diff --git a/smb-core/src/logging.rs b/smb-core/src/logging.rs new file mode 100644 index 0000000..71c49ed --- /dev/null +++ b/smb-core/src/logging.rs @@ -0,0 +1,58 @@ +/// Feature-gated logging macros. +/// +/// When the `tracing` feature is enabled, these re-export the corresponding +/// macros from the `tracing` crate. When disabled, they compile to no-ops. + +#[cfg(feature = "tracing")] +pub use tracing::{trace, debug, info, warn, error, info_span, debug_span, trace_span}; + +#[cfg(not(feature = "tracing"))] +#[macro_export] +macro_rules! trace { + ($($t:tt)*) => {()}; +} + +#[cfg(not(feature = "tracing"))] +#[macro_export] +macro_rules! debug { + ($($t:tt)*) => {()}; +} + +#[cfg(not(feature = "tracing"))] +#[macro_export] +macro_rules! info { + ($($t:tt)*) => {()}; +} + +#[cfg(not(feature = "tracing"))] +#[macro_export] +macro_rules! warn { + ($($t:tt)*) => {()}; +} + +#[cfg(not(feature = "tracing"))] +#[macro_export] +macro_rules! error { + ($($t:tt)*) => {()}; +} + +#[cfg(not(feature = "tracing"))] +#[macro_export] +macro_rules! info_span { + ($($t:tt)*) => {()}; +} + +#[cfg(not(feature = "tracing"))] +#[macro_export] +macro_rules! debug_span { + ($($t:tt)*) => {()}; +} + +#[cfg(not(feature = "tracing"))] +#[macro_export] +macro_rules! trace_span { + ($($t:tt)*) => {()}; +} + +#[cfg(not(feature = "tracing"))] +pub use crate::{trace, debug, info, warn, error, info_span, debug_span, trace_span}; diff --git a/smb-derive/src/attrs.rs b/smb-derive/src/attrs.rs index 66f84a4..d5f4e4e 100644 --- a/smb-derive/src/attrs.rs +++ b/smb-derive/src/attrs.rs @@ -58,7 +58,6 @@ impl DirectInner { return Err(::smb_core::error::SMBError::payload_too_small(#start as usize, input.len())); } let (remaining, #name): (&[u8], #ty) = ::smb_core::SMBFromBytes::smb_from_bytes(&input[#start..])?; - // println!("value of item: {:?}", #name); } } else { quote! { let #name = current_pos; } @@ -375,7 +374,6 @@ impl Vector { } else { self.count.smb_from_bytes(spanned, "item_count") }; - // println!("Count: {}", vec_count_or_len); let align = self.align; let offset = self.offset.smb_from_bytes(spanned, "item_offset"); let parser = if self.count == AttributeInfo::default() { @@ -389,7 +387,6 @@ impl Vector { }; let _name_str = name.to_string(); quote_spanned! { spanned.span() => - // println!("cnt/len parse for {:?}", #_name_str); #vec_count_or_len if #align > 0 && current_pos % #align != 0 { current_pos += #align - (current_pos % #align); @@ -437,14 +434,8 @@ impl Vector { let start_pos = current_pos; for entry in #raw_token.iter() { let item_bytes = ::smb_core::SMBToBytes::smb_to_bytes(entry); - // if (#align > 0) { - // println!("item with align {} initial starting pos {}, item bytes: {:?}", #align, current_pos, item_bytes); - // } current_pos = get_aligned_pos(#align, current_pos); item[current_pos..(current_pos + item_bytes.len())].copy_from_slice(&item_bytes); - // if (#align > 0) { - // println!("adding item with align {} at starting pos {}, item bytes: {:?}", #align, current_pos, item_bytes); - // } current_pos += item_bytes.len(); } let byte_size = current_pos - start_pos; @@ -543,14 +534,8 @@ impl SMBString { #string_to_bytes for entry in token_vec { let item_bytes = ::smb_core::SMBToBytes::smb_to_bytes(&entry); - // if (#align > 0) { - // println!("item with align {} initial starting pos {}, item bytes: {:?}", #align, current_pos, item_bytes); - // } // current_pos = get_aligned_pos(#align, current_pos); item[current_pos..(current_pos + item_bytes.len())].copy_from_slice(&item_bytes); - // if (#align > 0) { - // println!("adding item with align {} at starting pos {}, item bytes: {:?}", #align, current_pos, item_bytes); - // } current_pos += item_bytes.len(); } } diff --git a/smb-derive/src/field.rs b/smb-derive/src/field.rs index 4614b54..fe533ef 100644 --- a/smb-derive/src/field.rs +++ b/smb-derive/src/field.rs @@ -66,9 +66,7 @@ impl<'a, T: Spanned> SMBField<'a, T> { let _name_str = name.to_string(); let all_bytes = self.val_type.iter().map(|field_ty| field_ty.smb_from_bytes(name, field, ty)); quote! { - // println!("parse for {:?}", #_name_str); #(#all_bytes)* - // println!("end parse for {:?}", #name_str); } } @@ -356,7 +354,6 @@ impl FromAttributes for SMBFieldType { } else if let Ok(string) = SMBString::from_attributes(attrs) { Ok(SMBFieldType::String(string)) } else if let Ok(smb_enum) = SMBEnum::from_attributes(attrs) { - // println!("Got enum: {:?}", smb_enum); Ok(SMBFieldType::Enum(smb_enum)) } else if let Ok(skip) = Skip::from_attributes(attrs) { Ok(SMBFieldType::Skip(skip)) diff --git a/smb-derive/src/field_mapping.rs b/smb-derive/src/field_mapping.rs index 1b6a091..ba9bd16 100644 --- a/smb-derive/src/field_mapping.rs +++ b/smb-derive/src/field_mapping.rs @@ -135,11 +135,8 @@ pub(crate) fn get_num_enum_mapping(input: &DeriveInput, parent_attrs: Vec Result>, SMBDeriveError> { info.variants.iter().map(|variant| { - // println!("attrs: {:?}", variant.attrs); let discriminators = Discriminator::from_attributes(&variant.attrs).map(|d| d.values.iter().map(|val| val | d.flag).collect()) .map_err(|_e| SMBDeriveError::MissingField)?; - - // println!("Discs: {:?}", discriminators); get_struct_field_mapping(&variant.fields, vec![SMBFieldType::from_attributes(&variant.attrs).unwrap()], discriminators, Some(variant.ident.clone())) }).collect() } @@ -270,7 +267,6 @@ pub(crate) fn smb_from_bytes { quote! { #(#recurse)* - // println!("Size: {}", current_pos); Ok((remaining, Self { #(#names,)* })) @@ -288,9 +284,7 @@ pub(crate) fn smb_from_bytes SMBResult<()> { + #[cfg(feature = "tracing")] + { + use tracing_subscriber::EnvFilter; + tracing_subscriber::fmt() + .with_env_filter( + EnvFilter::try_from_default_env() + .unwrap_or_else(|_| EnvFilter::new("info")), + ) + .init(); + } // let share = SMBFileSystemShare::<_, _, _, Box>::root("TEST".into(), file_allowed, get_file_perms); let port: u16 = std::env::var("SMB_PORT") .ok() @@ -37,7 +48,7 @@ async fn main() -> SMBResult<()> { ], false)) .listener_address(addr).await?; let server = builder.build()?; - println!("here"); + info!(port, "SMB server starting"); server.start().await } @@ -50,7 +61,7 @@ fn main() -> anyhow::Result<()> { .add_share("test", share) .listener_address("127.0.0.1:50122")?; let mut server = builder.build()?; - println!("here"); + info!("SMB server starting"); server.start() } diff --git a/smb/src/protocol/body/create/request_context.rs b/smb/src/protocol/body/create/request_context.rs index be5b91d..337bca0 100644 --- a/smb/src/protocol/body/create/request_context.rs +++ b/smb/src/protocol/body/create/request_context.rs @@ -82,9 +82,9 @@ impl SMBByteSize for CreateRequestContext { impl SMBFromBytes for CreateRequestContext { fn smb_from_bytes(input: &[u8]) -> SMBParseResult<&[u8], Self> where Self: Sized { - println!("parsing wrapper"); + smb_core::logging::trace!("parsing create request context wrapper"); let (remaining, wrapper) = CreateContextWrapper::smb_from_bytes(input)?; - println!("got wrapper: {:?}", wrapper); + smb_core::logging::trace!(?wrapper, "parsed create request context wrapper"); let context = match wrapper.name.as_slice() { EA_BUFFER_TAG => create_ctx_smb_from_bytes!( diff --git a/smb/src/protocol/body/create/response_context.rs b/smb/src/protocol/body/create/response_context.rs index ef8c737..abf9082 100644 --- a/smb/src/protocol/body/create/response_context.rs +++ b/smb/src/protocol/body/create/response_context.rs @@ -49,10 +49,10 @@ impl SMBByteSize for CreateResponseContext { impl SMBFromBytes for CreateResponseContext { fn smb_from_bytes(input: &[u8]) -> SMBParseResult<&[u8], Self> where Self: Sized { - println!("parsing wrapper"); + smb_core::logging::trace!("parsing create response context wrapper"); let (remaining, wrapper) = CreateContextWrapper::smb_from_bytes(input)?; - println!("got ctx wrapper: {:02x?}", wrapper); + smb_core::logging::trace!(?wrapper, "parsed create response context wrapper"); let context = match wrapper.name.as_slice() { DURABLE_HANDLE_RESPONSE_TAG => create_ctx_smb_from_bytes!( Self::DurableHandleResponse, diff --git a/smb/src/protocol/body/negotiate/context.rs b/smb/src/protocol/body/negotiate/context.rs index 9b4f98b..934db90 100644 --- a/smb/src/protocol/body/negotiate/context.rs +++ b/smb/src/protocol/body/negotiate/context.rs @@ -91,7 +91,7 @@ impl SMBFromBytes for NegotiateContext { let (remaining, ctx_type) = u16::smb_from_bytes(input)?; let (_, ctx_len) = u16::smb_from_bytes(remaining)?; - println!("type {:?}, len {}", ctx_type, ctx_len); + smb_core::logging::trace!(ctx_type, ctx_len, "parsing negotiate context"); match ctx_type { PRE_AUTH_INTEGRITY_CAPABILITIES_TAG => ctx_smb_from_bytes_enumify!( diff --git a/smb/src/protocol/body/tree_connect/buffer.rs b/smb/src/protocol/body/tree_connect/buffer.rs index c1c4db4..857aa31 100644 --- a/smb/src/protocol/body/tree_connect/buffer.rs +++ b/smb/src/protocol/body/tree_connect/buffer.rs @@ -33,7 +33,7 @@ impl SMBTreeConnectBuffer { SMBTreeConnectBuffer::Extension(x) => &x.path_name }; let idx = path_str.rfind('\\'); - println!("Idx: {:?}", idx); + smb_core::logging::trace!(?idx, "parsing share name from path"); if let Some(idx) = idx { &path_str[(idx + 1)..] } else { diff --git a/smb/src/protocol/message.rs b/smb/src/protocol/message.rs index 0bb0498..9b417df 100644 --- a/smb/src/protocol/message.rs +++ b/smb/src/protocol/message.rs @@ -20,6 +20,7 @@ use sha2::Sha256; use smb_core::{SMBFromBytes, SMBParseResult, SMBResult, SMBToBytes}; use smb_core::error::SMBError; +use smb_core::logging::trace; use crate::byte_helper::u16_to_bytes; use crate::protocol::body::{Body, LegacySMBBody, SMBBody}; @@ -94,8 +95,7 @@ impl> Message for SMBMessage { fn parse(bytes: &[u8]) -> SMBParseResult<&[u8], Self> { let (remaining, header) = S::smb_from_bytes(bytes)?; - println!("header: {:?}", header); - println!("remaining: {:?}", remaining); + trace!(?header, remaining_len = remaining.len(), "parsed message header"); let discriminator_code = (header.command_code().into()) | ((header.sender() as u64) << 16); let (remaining, body) = T::smb_enum_from_bytes(remaining, discriminator_code)?; Ok((remaining, Self { header, body })) diff --git a/smb/src/server/connection.rs b/smb/src/server/connection.rs index acd2e39..24edb92 100644 --- a/smb/src/server/connection.rs +++ b/smb/src/server/connection.rs @@ -12,6 +12,7 @@ use uuid::Uuid; use smb_core::{SMBResult, SMBToBytes}; use smb_core::error::SMBError; +use smb_core::logging::{trace, debug, info, warn, error}; use smb_core::nt_status::NTStatus; use crate::protocol::body::capabilities::Capabilities; @@ -221,14 +222,15 @@ impl> SMBConnect where Arc>: SMBLockedMessageHandler { pub async fn start_message_handler(stream: &mut SMBSocketConnection, mut connection: Arc>>, update_channel: Sender) -> SMBResult<()> { let (read, write) = stream.streams(); - println!("Start message handler"); + info!("starting message handler"); let mut messages = read.messages(); while let Some(incoming) = messages.next().await { - println!("Got message: {:?}", incoming); + debug!(command = ?incoming.header.command, mid = incoming.header.message_id, "received message"); + trace!(?incoming, "full incoming message"); // If the body couldn't be parsed, the stream returns an ErrorResponse body. // Send it back directly without dispatching to handle_message. if matches!(&incoming.body, SMBBody::ErrorResponse(_)) { - println!("Incoming has ErrorResponse body (unparseable request), sending error reply"); + warn!(command = ?incoming.header.command, "unparseable request body, sending error reply"); let status = NTStatus::try_from(incoming.header.channel_sequence) .unwrap_or(NTStatus::NotSupported); let mut response = Self::build_error_response(&incoming, status); @@ -249,21 +251,23 @@ impl> SMBConnect Self::sign_message(&mut response, &key, dialect); } } - println!("Writing error response {:?}", response); + debug!(command = ?response.header.command, status = ?status, "sending error response"); + trace!(?response, "full error response"); let sent = write.write_message(&response).await?; let _ = update_channel.send(SMBServerDiagnosticsUpdate::default().bytes_sent(sent as u64)).await; continue; } let result = connection.handle_message(&incoming).await; - println!("After handler: {:?}", result); + debug!(ok = result.is_ok(), "handler completed"); let mut response = match result { Ok(msg) => msg, Err(SMBError::ResponseError(ref resp_err)) => { let status = resp_err.status(); + debug!(?status, "handler returned response error"); Self::build_error_response(&incoming, status) } Err(e) => { - println!("Non-response error: {:?}, sending NOT_SUPPORTED", e); + error!(?e, "non-response error, sending NOT_SUPPORTED"); Self::build_error_response(&incoming, NTStatus::NotSupported) } }; @@ -285,7 +289,8 @@ impl> SMBConnect Self::sign_message(&mut response, &key, dialect); } } - println!("Writing message {:?}", response); + debug!(command = ?response.header.command, mid = response.header.message_id, "sending response"); + trace!(?response, "full outgoing response"); let sent = write.write_message(&response).await?; let _ = update_channel.send(SMBServerDiagnosticsUpdate::default().bytes_sent(sent as u64)).await; } @@ -315,12 +320,11 @@ impl> SMBConnect // The SMB2 message starts at offset 4 (after the 4-byte NetBIOS header) let smb2_offset = 4; let smb2_len = bytes.len() - smb2_offset; - println!("Signing: dialect={:?}, key={:02x?}, smb2_len={}, header_bytes={:02x?}", - dialect, signing_key, smb2_len, &bytes[smb2_offset..std::cmp::min(smb2_offset+64, bytes.len())]); + trace!(?dialect, key_len = signing_key.len(), smb2_len, "signing message"); if let Ok(sig) = crate::util::crypto::smb2::calculate_signature( signing_key, dialect, &bytes, smb2_offset, smb2_len ) { - println!("Computed signature: {:02x?}", &sig[..std::cmp::min(16, sig.len())]); + trace!(signature = ?&sig[..std::cmp::min(16, sig.len())], "computed signature"); let len = std::cmp::min(16, sig.len()); message.header.signature[..len].copy_from_slice(&sig[..len]); } @@ -485,11 +489,11 @@ impl>; async fn inner(&self, message: &SMBMessageType) -> Option>> { - println!("Getting inner for message {:?}", message); + debug!(command = ?message.header.command, sid = message.header.session_id, "resolving inner handler"); let read = self.read().await; let server = read.server.upgrade()?; let server_rd = server.read().await; - println!("Getting session"); + trace!(sid = message.header.session_id, "looking up session"); // TODO if let SMBBody::SessionSetupRequest(req) = &message.body { read.get_session(&server_rd, &message.header, req.flags()) diff --git a/smb/src/server/message_handler.rs b/smb/src/server/message_handler.rs index d537ecd..92ffb97 100644 --- a/smb/src/server/message_handler.rs +++ b/smb/src/server/message_handler.rs @@ -1,6 +1,7 @@ use std::future::Future; use smb_core::error::SMBError; +use smb_core::logging::{trace, debug, warn}; use smb_core::nt_status::NTStatus; use smb_core::SMBResult; @@ -49,7 +50,7 @@ pub trait SMBLockedMessageHandlerBase { fn inner(&self, message: &SMBMessageType) -> impl Future>; fn handle_message_inner(&mut self, message: &SMBMessageType) -> impl Future>> { - println!("in inner handler for msg: {:?}", message); + debug!(command = ?message.header.command, mid = message.header.message_id, "dispatching to handler"); async { match &message.body { SMBBody::NegotiateRequest(req) => self.handle_negotiate(&message.header, req).await, @@ -102,7 +103,7 @@ pub trait SMBLockedMessageHandlerBase { } fn handle_create(&mut self, header: &SMBSyncHeader, message: &SMBCreateRequest) -> impl Future>> { - println!("passing msg to next handler"); + debug!("create request, passing to next handler"); async { Ok(SMBHandlerState::Next(None)) } } @@ -170,18 +171,25 @@ pub trait SMBLockedMessageHandler: SMBLockedMessageHandlerBase { impl SMBLockedMessageHandler for H where H::Inner: SMBLockedMessageHandler { async fn handle_message(&mut self, message: &SMBMessageType) -> SMBResult { - println!("Got message in handler: {:?}", message); + debug!(command = ?message.header.command, mid = message.header.message_id, "handling message in chain"); let state = self.handle_message_inner(message).await?; match state { - SMBHandlerState::Finished(msg) => Ok(msg), - SMBHandlerState::Next(Some(mut handler)) => handler - .handle_message(message) - .await, - SMBHandlerState::Next(None) => self.inner(message).await - .ok_or(SMBError::server_error("Invalid handler defined"))? - .handle_message(message) - .await, + SMBHandlerState::Finished(msg) => { + trace!("handler produced final response"); + Ok(msg) + }, + SMBHandlerState::Next(Some(mut handler)) => { + trace!("delegating to explicit next handler"); + handler.handle_message(message).await + }, + SMBHandlerState::Next(None) => { + trace!("delegating to inner handler"); + self.inner(message).await + .ok_or(SMBError::server_error("Invalid handler defined"))? + .handle_message(message) + .await + }, } } } diff --git a/smb/src/server/mod.rs b/smb/src/server/mod.rs index f515e80..a76e1a8 100644 --- a/smb/src/server/mod.rs +++ b/smb/src/server/mod.rs @@ -10,6 +10,7 @@ use tokio_stream::StreamExt; use uuid::Uuid; use smb_core::error::SMBError; +use smb_core::logging::{info, debug, warn}; use smb_core::SMBResult; use crate::protocol::body::dialect::SMBDialect; @@ -377,19 +378,24 @@ impl + 'static, Auth: A let listener = { self.read().await.local_listener.clone() }; + info!("SMB server accepting connections"); while let Some(connection) = listener.lock().await.connections().next().await { - println!("got connection"); let smb_connection = SMBConnection::try_from((connection, Arc::downgrade(self)))?; let name = smb_connection.client_name().to_string(); + info!(client = %name, "accepted new connection"); let socket = smb_connection.underlying_socket(); let wrapped_connection = Arc::new(RwLock::new(smb_connection)); { - self.write().await.connection_list.insert(name, Arc::downgrade(&wrapped_connection)); + self.write().await.connection_list.insert(name.clone(), Arc::downgrade(&wrapped_connection)); } let update_channel = rx.clone(); tokio::spawn(async move { + debug!(client = %name, "starting message handler"); let mut stream = socket.lock().await; - let _ = SMBConnection::start_message_handler::(&mut stream, wrapped_connection, update_channel).await; + match SMBConnection::start_message_handler::(&mut stream, wrapped_connection, update_channel).await { + Ok(()) => debug!("message handler completed"), + Err(ref e) => warn!(?e, "message handler exited with error"), + } }); } diff --git a/smb/src/server/session.rs b/smb/src/server/session.rs index 3ba16bb..1ea8b02 100644 --- a/smb/src/server/session.rs +++ b/smb/src/server/session.rs @@ -14,6 +14,7 @@ use sha2::Sha256; use tokio::sync::RwLock; use smb_core::error::SMBError; +use smb_core::logging::{trace, debug, info, warn}; use smb_core::nt_status::NTStatus; use smb_core::SMBResult; use crate::protocol::body::create::file_id::SMBFileId; @@ -130,7 +131,7 @@ impl SMBSession { } } fn generate_keys(&mut self, dialect: SMBDialect, cipher_id: EncryptionCipher) { - println!("in keygen"); + debug!(?dialect, ?cipher_id, "generating session keys"); let key_length = match cipher_id { EncryptionCipher::AES256GCM | AES256CCM => 32, _ => 16 @@ -152,14 +153,14 @@ impl SMBSession { _ => self.session_key.clone().to_vec(), }; - println!("skey: {:02x?}, signing key: {:02x?}", self.session_key, self.signing_key); + trace!(session_key = ?self.session_key, signing_key = ?self.signing_key, "derived signing key"); let (application_key_label, application_key_context): (&str, &[u8]) = match dialect { SMBDialect::V3_1_1 => ("SMBAppKey", &self.preauth_integrity_hash_value), _ => ("SMB2APP", "SmbRpc".as_bytes()) }; self.application_key = generate_key(&self.session_key, application_key_label, application_key_context, key_length); - println!("signing: {:?}, application: {:?}", self.signing_key, self.application_key); + trace!(signing_key_len = self.signing_key.len(), application_key_len = self.application_key.len(), "key generation complete"); } fn get_next_map_id(map: &HashMap) -> K { let mut i = K::min_val(); @@ -175,7 +176,7 @@ impl SMBSession { } fn generate_key(secure_key: &[u8], label: &str, context: &[u8], output_len: usize) -> Vec { - println!("key len: {:?}, label: {:02x?}, ctx: {:02x?}", secure_key.len(), label, context); + trace!(key_len = secure_key.len(), label, context_len = context.len(), output_len, "deriving key via KDF"); let mac = >::new_from_slice(secure_key) .map_err(|_| SMBError::crypto_error("Invalid Key Length")).unwrap(); let label_bytes = [ @@ -191,7 +192,7 @@ impl>> SMBLockedMessageHandlerBase for Arc>; async fn inner(&self, message: &SMBMessageType) -> Option { let write = self.write().await; - println!("Getting tree connect for message: {:?}", message); + debug!(tid = message.header.tree_id, command = ?message.header.command, "looking up tree connect"); write.tree_connect_table.get(&message.header.tree_id) .map(Arc::clone) } @@ -206,7 +207,8 @@ impl>> SMBLockedMessageHandlerBase for Arc::new(status, msg); diff --git a/smb/src/server/share/file_system.rs b/smb/src/server/share/file_system.rs index 8771506..25d4417 100644 --- a/smb/src/server/share/file_system.rs +++ b/smb/src/server/share/file_system.rs @@ -6,6 +6,7 @@ use std::marker::PhantomData; use std::time::{SystemTime, UNIX_EPOCH}; use smb_core::error::SMBError; +use smb_core::logging::debug; use smb_core::SMBResult; use crate::protocol::body::create::disposition::SMBCreateDisposition; @@ -174,7 +175,7 @@ impl + ResourceHandle + resource, path: path.into(), }; - println!("Created fs handle: {:?}", handle); + debug!(?handle, "created filesystem handle"); Ok(handle.into()) } diff --git a/smb/src/server/tree_connect.rs b/smb/src/server/tree_connect.rs index a67dc66..46bb0bd 100644 --- a/smb/src/server/tree_connect.rs +++ b/smb/src/server/tree_connect.rs @@ -6,6 +6,7 @@ use tokio::sync::RwLock; use smb_core::{SMBByteSize, SMBResult}; use smb_core::error::SMBError; +use smb_core::logging::{debug, trace}; use crate::protocol::body::create::{SMBCreateRequest, SMBCreateResponse}; use crate::protocol::body::create::file_id::SMBFileId; @@ -72,9 +73,9 @@ impl SMBLockedMessageHandlerBase for Arc> { let file_id = open.read().await.file_id(); session.write().await.set_previous_file_id(file_id); } - println!("In tree connect create"); + debug!("tree connect create handled"); let header = header.create_response_header(header.channel_sequence, header.session_id, header.tree_id); - println!("Creat resp bs: {}", response.smb_byte_size()); + trace!(response_size = response.smb_byte_size(), "create response built"); Ok(SMBHandlerState::Finished(SMBMessage::new(header, response))) } } diff --git a/smb/src/socket/message_stream/mod.rs b/smb/src/socket/message_stream/mod.rs index 082375b..bcc5e53 100644 --- a/smb/src/socket/message_stream/mod.rs +++ b/smb/src/socket/message_stream/mod.rs @@ -4,14 +4,13 @@ use tokio_util::sync::ReusableBoxFuture; use smb_core::{SMBFromBytes, SMBParseResult, SMBResult}; use smb_core::error::SMBError; +use smb_core::logging::{trace, warn}; use crate::protocol::body::{LegacySMBBody, SMBBody}; use crate::protocol::body::error::SMBErrorResponse; use crate::protocol::header::{Header, LegacySMBHeader, SMBSyncHeader}; use crate::protocol::message::{Message, SMBMessage}; -// use crate::socket::message_stream::stream_async::SMBMessageStream; - #[cfg(not(feature = "async"))] mod stream_sync; #[cfg(feature = "async")] @@ -29,11 +28,10 @@ pub trait SMBReadStream: SMBStream { #[cfg(feature = "async")] fn messages(&mut self) -> SMBMessageStream where Self: Sized; fn read_message_inner(buffer: &[u8]) -> SMBParseResult<&[u8], SMBMessage> { - println!("in inner read"); + trace!(buf_len = buffer.len(), "parsing message from buffer"); if let Some(pos) = buffer.iter().position(|x| *x == b'S') { - println!("found s at pos: {}", pos); if buffer[(pos)..].starts_with(b"SMB") { - println!("found smb"); + trace!(smb_offset = pos - 1, "found SMB header"); let smb_start = pos - 1; let result = SMBMessage::::parse(&buffer[smb_start..]); return match result { @@ -47,7 +45,7 @@ pub trait SMBReadStream: SMBStream { // Body parse failed — try header-only parse and return an ErrorResponse // so the connection handler can send a proper error back to the client if let Ok((remaining, mut header)) = SMBSyncHeader::smb_from_bytes(&buffer[smb_start..]) { - println!("Header-only parse succeeded for command {:?}, returning ErrorResponse", header.command); + warn!(command = ?header.command, "body parse failed, returning ErrorResponse"); header.channel_sequence = smb_core::nt_status::NTStatus::NotSupported as u32; let body = SMBBody::ErrorResponse(SMBErrorResponse::new()); Ok((&buffer[buffer.len()..], SMBMessage::new(header, body))) diff --git a/smb/src/socket/message_stream/stream_async.rs b/smb/src/socket/message_stream/stream_async.rs index 3e09b25..1666a42 100644 --- a/smb/src/socket/message_stream/stream_async.rs +++ b/smb/src/socket/message_stream/stream_async.rs @@ -8,6 +8,7 @@ use tokio_util::sync::ReusableBoxFuture; use smb_core::{SMBParseResult, SMBResult}; use smb_core::error::SMBError; +use smb_core::logging::{trace, debug, warn}; use crate::protocol::body::SMBBody; use crate::protocol::header::SMBSyncHeader; @@ -19,10 +20,10 @@ async fn make_future(mut iterator: SMBMessageIterator<'_, T>) match iterator.reader.read_message(&mut iterator.buffer).await { Ok(msg) => break Ok(msg), Err(SMBError::PayloadTooSmall(x)) => { - println!("Buffer too small: {:?}", iterator.buffer); + trace!(buf_len = iterator.buffer.len(), "buffer too small, reading more data"); } Err(e) => { - println!("Other error: {:?}, buf: {:02x?}", e, iterator.buffer); + warn!(?e, "message read error"); break Err(e); } } @@ -33,7 +34,8 @@ async fn make_future(mut iterator: SMBMessageIterator<'_, T>) } else { Err(res.err().unwrap()) }; - println!("got msg: {:?}. bytes remaining: {:02x?}", msg_res, iterator.buffer); + debug!(ok = msg_res.is_ok(), remaining = iterator.buffer.len(), "message read complete"); + trace!(?msg_res, "parsed message result"); (msg_res, iterator) } @@ -57,7 +59,7 @@ impl SMBWriteStream for Writer where Writer: AsyncWriteExt + Unpin + Sen impl SMBReadStream for Reader where Reader: AsyncReadExt + Unpin + Send + Sync + SMBStream { async fn read_message<'a>(&'a mut self, existing: &'a mut Vec) -> SMBParseResult<&'a [u8], SMBMessage> { - println!("read called w/ existing buffer: {:02x?}", existing); + trace!(buf_len = existing.len(), "read_message called"); if let Ok((remaining, res)) = Self::read_message_inner(existing) { return Ok((&existing[(existing.len() - remaining.len())..], res)); } diff --git a/smb/src/util/auth/ntlm/ntlm_authenticate_message.rs b/smb/src/util/auth/ntlm/ntlm_authenticate_message.rs index 7b46028..ab4208c 100644 --- a/smb/src/util/auth/ntlm/ntlm_authenticate_message.rs +++ b/smb/src/util/auth/ntlm/ntlm_authenticate_message.rs @@ -115,7 +115,7 @@ impl NTLMAuthenticateMessageBody { context.work_station = Some(self.work_station.clone()); context.version = Some("6.1.7200".into()); // TODO FIX - println!("flags: {:?}, item: {:?}", self.negotiate_flags, &self); + smb_core::logging::trace!(?self.negotiate_flags, "NTLM authenticate message"); if self.negotiate_flags.contains(NTLMNegotiateFlags::ANONYMOUS) { return if guest_supported { context.guest = Some(true); diff --git a/smb/src/util/auth/spnego/der_utils.rs b/smb/src/util/auth/spnego/der_utils.rs index 82c9b68..be616a1 100644 --- a/smb/src/util/auth/spnego/der_utils.rs +++ b/smb/src/util/auth/spnego/der_utils.rs @@ -58,7 +58,7 @@ pub fn parse_length(buffer: &[u8]) -> IResult<&[u8], usize> { pub fn parse_field_with_len(buffer: &[u8]) -> IResult<&[u8], &[u8]> { parse_length(buffer).and_then(|(remaining, len)| { - println!("len: {len}"); + smb_core::logging::trace!(len, "parsed DER field length"); take(len)(remaining) }) } diff --git a/smb/src/util/auth/spnego/spnego_token.rs b/smb/src/util/auth/spnego/spnego_token.rs index 7976d52..af95fd5 100644 --- a/smb/src/util/auth/spnego/spnego_token.rs +++ b/smb/src/util/auth/spnego/spnego_token.rs @@ -44,7 +44,7 @@ impl SPNEGOToken { Self::parse_inner(bytes).map_err(|e| SMBError::parse_error(e.to_owned())) } fn parse_inner(bytes: &[u8]) -> IResult<&[u8], Self> { - println!("bytes: {:?},", bytes); + smb_core::logging::trace!(buf_len = bytes.len(), "parsing SPNEGO token"); let (remaining, tag) = le_u8(bytes)?; match tag { APPLICATION_TAG => { @@ -59,7 +59,7 @@ impl SPNEGOToken { return Err(Error(nom::error::Error::new(remaining, ErrorKind::Fail))); } let (remaining, tag) = le_u8(remaining)?; - println!("TAG: {}", tag); + smb_core::logging::trace!(tag, "SPNEGO inner tag"); match tag { NEG_TOKEN_INIT_TAG => { let (remaining, body) = SPNEGOTokenInitBody::parse(remaining)?; diff --git a/smb/src/util/auth/spnego/spnego_token_response.rs b/smb/src/util/auth/spnego/spnego_token_response.rs index dec657b..84b2682 100644 --- a/smb/src/util/auth/spnego/spnego_token_response.rs +++ b/smb/src/util/auth/spnego/spnego_token_response.rs @@ -94,7 +94,7 @@ impl SPNEGOTokenResponseBody { let mut mech_list_mic = None; while !sequence.is_empty() { - println!("SEQ: {:?}", sequence); + smb_core::logging::trace!(remaining_len = sequence.len(), "parsing SPNEGO response sequence field"); (sequence, tag) = le_u8(sequence)?; match tag { NEG_STATE_TAG => { From 14e4e8190fe8fedea22ad28fbfb5958931acf274 Mon Sep 17 00:00:00 2001 From: Tejas Mehta Date: Sun, 8 Feb 2026 16:36:33 -0500 Subject: [PATCH 2/3] import all logging macros, don't fully qualify --- smb/src/protocol/body/create/request_context.rs | 5 +++-- smb/src/protocol/body/create/response_context.rs | 5 +++-- smb/src/protocol/body/negotiate/context.rs | 3 ++- smb/src/protocol/body/tree_connect/buffer.rs | 3 ++- smb/src/util/auth/ntlm/ntlm_authenticate_message.rs | 4 +++- smb/src/util/auth/spnego/der_utils.rs | 4 +++- smb/src/util/auth/spnego/spnego_token.rs | 5 +++-- smb/src/util/auth/spnego/spnego_token_response.rs | 3 ++- 8 files changed, 21 insertions(+), 11 deletions(-) diff --git a/smb/src/protocol/body/create/request_context.rs b/smb/src/protocol/body/create/request_context.rs index 337bca0..4637074 100644 --- a/smb/src/protocol/body/create/request_context.rs +++ b/smb/src/protocol/body/create/request_context.rs @@ -7,6 +7,7 @@ use uuid::Uuid; use smb_core::{SMBByteSize, SMBFromBytes, SMBParseResult, SMBToBytes}; use smb_core::error::SMBError; +use smb_core::logging::trace; use smb_derive::{SMBByteSize, SMBFromBytes, SMBToBytes}; use crate::protocol::body::create::context_helper::{create_ctx_smb_byte_size, create_ctx_smb_from_bytes, create_ctx_smb_to_bytes, CreateContextWrapper, impl_tag_for_ctx}; @@ -82,9 +83,9 @@ impl SMBByteSize for CreateRequestContext { impl SMBFromBytes for CreateRequestContext { fn smb_from_bytes(input: &[u8]) -> SMBParseResult<&[u8], Self> where Self: Sized { - smb_core::logging::trace!("parsing create request context wrapper"); + trace!("parsing create request context wrapper"); let (remaining, wrapper) = CreateContextWrapper::smb_from_bytes(input)?; - smb_core::logging::trace!(?wrapper, "parsed create request context wrapper"); + trace!(?wrapper, "parsed create request context wrapper"); let context = match wrapper.name.as_slice() { EA_BUFFER_TAG => create_ctx_smb_from_bytes!( diff --git a/smb/src/protocol/body/create/response_context.rs b/smb/src/protocol/body/create/response_context.rs index abf9082..f15a145 100644 --- a/smb/src/protocol/body/create/response_context.rs +++ b/smb/src/protocol/body/create/response_context.rs @@ -5,6 +5,7 @@ use serde::{Deserialize, Serialize}; use smb_core::{SMBByteSize, SMBFromBytes, SMBParseResult, SMBToBytes}; use smb_core::error::SMBError; +use smb_core::logging::trace; use smb_core::nt_status::NTStatus; use smb_derive::{SMBByteSize, SMBFromBytes, SMBToBytes}; @@ -49,10 +50,10 @@ impl SMBByteSize for CreateResponseContext { impl SMBFromBytes for CreateResponseContext { fn smb_from_bytes(input: &[u8]) -> SMBParseResult<&[u8], Self> where Self: Sized { - smb_core::logging::trace!("parsing create response context wrapper"); + trace!("parsing create response context wrapper"); let (remaining, wrapper) = CreateContextWrapper::smb_from_bytes(input)?; - smb_core::logging::trace!(?wrapper, "parsed create response context wrapper"); + trace!(?wrapper, "parsed create response context wrapper"); let context = match wrapper.name.as_slice() { DURABLE_HANDLE_RESPONSE_TAG => create_ctx_smb_from_bytes!( Self::DurableHandleResponse, diff --git a/smb/src/protocol/body/negotiate/context.rs b/smb/src/protocol/body/negotiate/context.rs index 934db90..520de7b 100644 --- a/smb/src/protocol/body/negotiate/context.rs +++ b/smb/src/protocol/body/negotiate/context.rs @@ -8,6 +8,7 @@ use serde::{Deserialize, Serialize}; use smb_core::{SMBByteSize, SMBFromBytes, SMBParseResult, SMBResult, SMBToBytes}; use smb_core::error::SMBError; +use smb_core::logging::trace; use smb_core::nt_status::NTStatus; use smb_derive::{SMBByteSize, SMBFromBytes, SMBToBytes}; @@ -91,7 +92,7 @@ impl SMBFromBytes for NegotiateContext { let (remaining, ctx_type) = u16::smb_from_bytes(input)?; let (_, ctx_len) = u16::smb_from_bytes(remaining)?; - smb_core::logging::trace!(ctx_type, ctx_len, "parsing negotiate context"); + trace!(ctx_type, ctx_len, "parsing negotiate context"); match ctx_type { PRE_AUTH_INTEGRITY_CAPABILITIES_TAG => ctx_smb_from_bytes_enumify!( diff --git a/smb/src/protocol/body/tree_connect/buffer.rs b/smb/src/protocol/body/tree_connect/buffer.rs index 857aa31..3357868 100644 --- a/smb/src/protocol/body/tree_connect/buffer.rs +++ b/smb/src/protocol/body/tree_connect/buffer.rs @@ -2,6 +2,7 @@ use std::marker::PhantomData; use serde::{Deserialize, Serialize}; +use smb_core::logging::trace; use smb_derive::{SMBByteSize, SMBEnumFromBytes, SMBFromBytes, SMBToBytes}; use crate::protocol::body::tree_connect::context::SMBTreeConnectContext; @@ -33,7 +34,7 @@ impl SMBTreeConnectBuffer { SMBTreeConnectBuffer::Extension(x) => &x.path_name }; let idx = path_str.rfind('\\'); - smb_core::logging::trace!(?idx, "parsing share name from path"); + trace!(?idx, "parsing share name from path"); if let Some(idx) = idx { &path_str[(idx + 1)..] } else { diff --git a/smb/src/util/auth/ntlm/ntlm_authenticate_message.rs b/smb/src/util/auth/ntlm/ntlm_authenticate_message.rs index ab4208c..d915584 100644 --- a/smb/src/util/auth/ntlm/ntlm_authenticate_message.rs +++ b/smb/src/util/auth/ntlm/ntlm_authenticate_message.rs @@ -8,6 +8,8 @@ use rc4::{Key, Rc4, StreamCipher}; use rc4::consts::U16; use serde::{Deserialize, Serialize}; +use smb_core::logging::trace; + use crate::util::auth::ntlm::ntlm_auth_provider::NTLMAuthContext; use crate::util::auth::ntlm::ntlm_message::{NTLMNegotiateFlags, parse_ntlm_buffer_fields}; use crate::util::auth::user::User; @@ -115,7 +117,7 @@ impl NTLMAuthenticateMessageBody { context.work_station = Some(self.work_station.clone()); context.version = Some("6.1.7200".into()); // TODO FIX - smb_core::logging::trace!(?self.negotiate_flags, "NTLM authenticate message"); + trace!(?self.negotiate_flags, "NTLM authenticate message"); if self.negotiate_flags.contains(NTLMNegotiateFlags::ANONYMOUS) { return if guest_supported { context.guest = Some(true); diff --git a/smb/src/util/auth/spnego/der_utils.rs b/smb/src/util/auth/spnego/der_utils.rs index be616a1..3198ae5 100644 --- a/smb/src/util/auth/spnego/der_utils.rs +++ b/smb/src/util/auth/spnego/der_utils.rs @@ -6,6 +6,8 @@ use nom::IResult; use nom::multi::fold_many_m_n; use nom::number::complete::le_u8; +use smb_core::logging::trace; + pub const NEG_TOKEN_INIT_TAG: u8 = 0xA0; pub const NEG_TOKEN_RESP_TAG: u8 = 0xA1; @@ -58,7 +60,7 @@ pub fn parse_length(buffer: &[u8]) -> IResult<&[u8], usize> { pub fn parse_field_with_len(buffer: &[u8]) -> IResult<&[u8], &[u8]> { parse_length(buffer).and_then(|(remaining, len)| { - smb_core::logging::trace!(len, "parsed DER field length"); + trace!(len, "parsed DER field length"); take(len)(remaining) }) } diff --git a/smb/src/util/auth/spnego/spnego_token.rs b/smb/src/util/auth/spnego/spnego_token.rs index af95fd5..a357a88 100644 --- a/smb/src/util/auth/spnego/spnego_token.rs +++ b/smb/src/util/auth/spnego/spnego_token.rs @@ -7,6 +7,7 @@ use serde::{Deserialize, Serialize}; use smb_core::{SMBParseResult, SMBResult}; use smb_core::error::SMBError; +use smb_core::logging::trace; use smb_core::nt_status::NTStatus; use crate::util::auth::{AuthMessage, AuthProvider}; @@ -44,7 +45,7 @@ impl SPNEGOToken { Self::parse_inner(bytes).map_err(|e| SMBError::parse_error(e.to_owned())) } fn parse_inner(bytes: &[u8]) -> IResult<&[u8], Self> { - smb_core::logging::trace!(buf_len = bytes.len(), "parsing SPNEGO token"); + trace!(buf_len = bytes.len(), "parsing SPNEGO token"); let (remaining, tag) = le_u8(bytes)?; match tag { APPLICATION_TAG => { @@ -59,7 +60,7 @@ impl SPNEGOToken { return Err(Error(nom::error::Error::new(remaining, ErrorKind::Fail))); } let (remaining, tag) = le_u8(remaining)?; - smb_core::logging::trace!(tag, "SPNEGO inner tag"); + trace!(tag, "SPNEGO inner tag"); match tag { NEG_TOKEN_INIT_TAG => { let (remaining, body) = SPNEGOTokenInitBody::parse(remaining)?; diff --git a/smb/src/util/auth/spnego/spnego_token_response.rs b/smb/src/util/auth/spnego/spnego_token_response.rs index 84b2682..d942241 100644 --- a/smb/src/util/auth/spnego/spnego_token_response.rs +++ b/smb/src/util/auth/spnego/spnego_token_response.rs @@ -6,6 +6,7 @@ use nom::number::complete::le_u8; use num_enum::TryFromPrimitive; use serde::{Deserialize, Serialize}; +use smb_core::logging::trace; use smb_core::nt_status::NTStatus; use crate::util::auth::{AuthMessage, AuthProvider}; @@ -94,7 +95,7 @@ impl SPNEGOTokenResponseBody { let mut mech_list_mic = None; while !sequence.is_empty() { - smb_core::logging::trace!(remaining_len = sequence.len(), "parsing SPNEGO response sequence field"); + trace!(remaining_len = sequence.len(), "parsing SPNEGO response sequence field"); (sequence, tag) = le_u8(sequence)?; match tag { NEG_STATE_TAG => { From 6ff2e689362762aa79e636a8d2a0c724c0e04493 Mon Sep 17 00:00:00 2001 From: Tejas Mehta Date: Sun, 8 Feb 2026 16:41:14 -0500 Subject: [PATCH 3/3] fix small test --- smb/src/protocol/body/filetime.rs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/smb/src/protocol/body/filetime.rs b/smb/src/protocol/body/filetime.rs index e0aef6b..60d91c4 100644 --- a/smb/src/protocol/body/filetime.rs +++ b/smb/src/protocol/body/filetime.rs @@ -40,7 +40,7 @@ impl FileTime { pub fn to_unix(&self) -> u64 { let bytes = self.as_bytes(); - bytes_to_u64(&bytes) + bytes_to_u64(&bytes) - TIME_SINCE_1601_AND_EPOCH } pub fn as_bytes(&self) -> Vec {