From 5c28ee4bc284541d19e70b6e00e4d1a57079c224 Mon Sep 17 00:00:00 2001 From: daladim Date: Mon, 17 Oct 2022 14:30:45 +0200 Subject: [PATCH 1/7] Merged EventTraceProperties into TraceInfo This commit does not compile, but will make it possible for a following commit to remove the not-so-idiomatic fill_info() --- src/native/etw_types.rs | 129 +++++++++++++++++++--------------------- src/native/evntrace.rs | 33 ++++------ 2 files changed, 74 insertions(+), 88 deletions(-) diff --git a/src/native/etw_types.rs b/src/native/etw_types.rs index 04d8103..0294e81 100644 --- a/src/native/etw_types.rs +++ b/src/native/etw_types.rs @@ -134,95 +134,90 @@ impl From for u32 { } } -/// Newtype wrapper over an [EVENT_TRACE_PROPERTIES] -/// -/// [EVENT_TRACE_PROPERTIES]: https://microsoft.github.io/windows-docs-rs/doc/bindings/Windows/Win32/Etw/struct.EVENT_TRACE_PROPERTIES.html -#[repr(C)] -#[derive(Clone, Copy)] -pub struct EventTraceProperties(Etw::EVENT_TRACE_PROPERTIES); - -impl std::fmt::Debug for EventTraceProperties { - fn fmt(&self, _f: &mut Formatter<'_>) -> std::fmt::Result { - todo!() - } -} - -impl Default for EventTraceProperties { - fn default() -> Self { - unsafe { std::mem::zeroed::() } - } -} - -impl std::ops::Deref for EventTraceProperties { - type Target = Etw::EVENT_TRACE_PROPERTIES; - - fn deref(&self) -> &self::Etw::EVENT_TRACE_PROPERTIES { - &self.0 - } -} - -impl std::ops::DerefMut for EventTraceProperties { - fn deref_mut(&mut self) -> &mut Self::Target { - &mut self.0 - } -} -/// Complete Trace Properties struct +/// Wrapper over an [EVENT_TRACE_PROPERTIES](https://docs.microsoft.com/en-us/windows/win32/api/evntrace/ns-evntrace-event_trace_properties), and its allocated companion members /// /// The [EventTraceProperties] struct contains the information about a tracing session, this struct /// also needs two buffers right after it to hold the log file name and the session name. This struct /// provides the full definition of the properties plus the the allocation for both names -/// -/// See: [EVENT_TRACE_PROPERTIES](https://docs.microsoft.com/en-us/windows/win32/api/evntrace/ns-evntrace-event_trace_properties) #[repr(C)] -#[derive(Clone, Copy, Debug)] -pub struct TraceInfo { - pub properties: EventTraceProperties, +#[derive(Clone, Copy)] +pub struct EventTraceProperties { + etw_trace_properties: Etw::EVENT_TRACE_PROPERTIES, trace_name: [u8; MAX_PATH as usize], - log_file_name: [u8; MAX_PATH as usize], + log_file_name: [u8; MAX_PATH as usize], // not used currently, but this may be useful when resolving https://github.com/n4r1b/ferrisetw/issues/7 } -impl TraceInfo { - pub(crate) fn fill( - &mut self, + +impl std::fmt::Debug for EventTraceProperties { + fn fmt(&self, f: &mut Formatter<'_>) -> std::fmt::Result { + write!(f, "") + } +} + +impl EventTraceProperties { + pub(crate) fn new( trace_name: &str, trace_properties: &TraceProperties, providers: &[Provider], - ) where - T: TraceTrait, + ) -> Self + where + T: TraceTrait { - self.properties.0.Wnode.BufferSize = std::mem::size_of::() as u32; - self.properties.0.Wnode.Guid = T::trace_guid(); - self.properties.0.Wnode.Flags = Etw::WNODE_FLAG_TRACED_GUID; - self.properties.0.Wnode.ClientContext = 1; // QPC clock resolution - self.properties.0.BufferSize = trace_properties.buffer_size; - self.properties.0.MinimumBuffers = trace_properties.min_buffer; - self.properties.0.MaximumBuffers = trace_properties.max_buffer; - self.properties.0.FlushTimer = trace_properties.flush_timer; + let mut etw_trace_properties = Etw::EVENT_TRACE_PROPERTIES::default(); + + etw_trace_properties.Wnode.BufferSize = std::mem::size_of::() as u32; + etw_trace_properties.Wnode.Guid = T::trace_guid(); + etw_trace_properties.Wnode.Flags = Etw::WNODE_FLAG_TRACED_GUID; + etw_trace_properties.Wnode.ClientContext = 1; // QPC clock resolution + etw_trace_properties.BufferSize = trace_properties.buffer_size; + etw_trace_properties.MinimumBuffers = trace_properties.min_buffer; + etw_trace_properties.MaximumBuffers = trace_properties.max_buffer; + etw_trace_properties.FlushTimer = trace_properties.flush_timer; if trace_properties.log_file_mode != 0 { - self.properties.0.LogFileMode = trace_properties.log_file_mode; + etw_trace_properties.LogFileMode = trace_properties.log_file_mode; } else { - self.properties.0.LogFileMode = + etw_trace_properties.LogFileMode = u32::from(LoggingMode::RealTime) | u32::from(LoggingMode::NoPerProcBuffering); } - self.properties.0.LogFileMode |= T::augmented_file_mode(); - self.properties.0.EnableFlags = Etw::EVENT_TRACE_FLAG(T::enable_flags(providers)); + etw_trace_properties.LogFileMode |= T::augmented_file_mode(); + etw_trace_properties.EnableFlags = Etw::EVENT_TRACE_FLAG(T::enable_flags(providers)); + + // etw_trace_properties.LogFileNameOffset must be 0, but this will change when https://github.com/n4r1b/ferrisetw/issues/7 is resolved + // > If you do not want to log events to a log file (for example, if you specify EVENT_TRACE_REAL_TIME_MODE only), set LogFileNameOffset to 0. + // (https://learn.microsoft.com/en-us/windows/win32/api/evntrace/ns-evntrace-event_trace_properties) + etw_trace_properties.LoggerNameOffset = offset_of!(EventTraceProperties, log_file_name) as u32; + + // https://learn.microsoft.com/en-us/windows/win32/api/evntrace/ns-evntrace-event_trace_properties#remarks + // > You do not copy the session name to the offset. The StartTrace function copies the name for you. + // + // Let's do it anyway, even though that's not required + let mut s = Self { + etw_trace_properties, + trace_name: [0; MAX_PATH as usize], + log_file_name: [0; MAX_PATH as usize], + }; + s.trace_name[..trace_name.len()].copy_from_slice(trace_name.as_bytes()); + + s + } - self.properties.0.LoggerNameOffset = offset_of!(TraceInfo, log_file_name) as u32; - self.trace_name[..trace_name.len()].copy_from_slice(trace_name.as_bytes()) + /// Gets a pointer to the wrapped [Etw::EVENT_TRACE_PROPERTIES] + /// + /// # Safety + /// + /// The API enforces this points to an allocated, valid `EVENT_TRACE_PROPERTIES` instance. + /// As evey other mutable raw pointer, you should not use it in case someone else is keeping a reference to this object. + /// + /// Note that `OpenTraceA` **will** modify its content on output. + pub unsafe fn as_mut_ptr(&mut self) -> *mut Etw::EVENT_TRACE_PROPERTIES { + &mut self.etw_trace_properties as *mut Etw::EVENT_TRACE_PROPERTIES } -} -impl Default for TraceInfo { - fn default() -> Self { - let properties = EventTraceProperties::default(); - TraceInfo { - properties, - trace_name: [0; 260], - log_file_name: [0; 260], - } + pub fn trace_name_array(&self) -> &[u8] { + &self.trace_name } } diff --git a/src/native/evntrace.rs b/src/native/evntrace.rs index aa11459..4423d27 100644 --- a/src/native/evntrace.rs +++ b/src/native/evntrace.rs @@ -74,15 +74,18 @@ extern "system" fn trace_callback_thunk(p_record: *mut Etw::EVENT_RECORD) { #[derive(Debug, Clone)] pub(crate) struct NativeEtw { - info: TraceInfo, + info: EventTraceProperties, session_handle: TraceHandle, registration_handle: TraceHandle, } impl NativeEtw { - pub(crate) fn new() -> Self { + pub(crate) fn new(name: &str, properties: &TraceProperties, providers: &[Provider]) -> Self + where + T: TraceTrait, + { NativeEtw { - info: TraceInfo::default(), + info: EventTraceProperties::new::(name, properties, providers), session_handle: INVALID_TRACE_HANDLE, registration_handle: INVALID_TRACE_HANDLE, } @@ -92,18 +95,6 @@ impl NativeEtw { self.session_handle } - // Not a big fan of this... - pub(crate) fn fill_info( - &mut self, - name: &str, - properties: &TraceProperties, - providers: &[Provider], - ) where - T: TraceTrait, - { - self.info.fill::(name, properties, providers); - } - pub(crate) fn start(&mut self) -> EvntraceNativeResult<()> { if self.session_handle == INVALID_TRACE_HANDLE { return Err(EvntraceNativeError::InvalidHandle); @@ -146,11 +137,11 @@ impl NativeEtw { } pub(crate) fn register_trace(&mut self, trace_data: &TraceData) -> EvntraceNativeResult<()> { - if let Err(err) = self.start_trace(trace_data) { + if let Err(err) = self.start_trace() { if matches!(err, EvntraceNativeError::AlreadyExist) { // TODO: Check need admin errors self.stop_trace(trace_data)?; - self.start_trace(trace_data)?; + self.start_trace()?; } else { return Err(err); } @@ -158,12 +149,12 @@ impl NativeEtw { Ok(()) } - fn start_trace(&mut self, trace_data: &TraceData) -> EvntraceNativeResult<()> { + fn start_trace(&mut self) -> EvntraceNativeResult<()> { unsafe { let status = Etw::StartTraceA( &mut self.registration_handle, - PCSTR::from_raw(trace_data.name.as_ptr()), - &mut *self.info.properties, + PCSTR::from_raw(self.info.trace_name_array().as_ptr()), + self.info.as_mut_ptr(), ); if status == ERROR_ALREADY_EXISTS.0 { @@ -234,7 +225,7 @@ impl NativeEtw { Etw::ControlTraceA( 0, PCSTR::from_raw(trace_data.name.as_ptr()), - &mut *self.info.properties, + self.info.as_mut_ptr(), control_code, ) }; From bde7f5f46956edeedb0fc39ad3789bacb9c8573e Mon Sep 17 00:00:00 2001 From: daladim Date: Mon, 17 Oct 2022 11:51:59 +0200 Subject: [PATCH 2/7] Using OpenTraceW rather than OpenTraceA --- src/native/etw_types.rs | 43 +++++++++++++++++++++-------------------- src/native/evntrace.rs | 2 +- 2 files changed, 23 insertions(+), 22 deletions(-) diff --git a/src/native/etw_types.rs b/src/native/etw_types.rs index 0294e81..614fb4e 100644 --- a/src/native/etw_types.rs +++ b/src/native/etw_types.rs @@ -13,10 +13,11 @@ use std::ffi::c_void; use std::fmt::Formatter; use std::marker::PhantomData; use windows::core::GUID; -use windows::core::PSTR; +use windows::core::PWSTR; use windows::Win32::Foundation::MAX_PATH; use windows::Win32::System::Diagnostics::Etw; use windows::Win32::System::Diagnostics::Etw::EVENT_FILTER_DESCRIPTOR; +use widestring::ucstring::U16CString; mod event_record; pub use event_record::EventRecord; @@ -221,47 +222,47 @@ impl EventTraceProperties { } } -/// Newtype wrapper over an [EVENT_TRACE_LOGFILEA] +/// Newtype wrapper over an [EVENT_TRACE_LOGFILEW] /// -/// [EVENT_TRACE_LOGFILEA]: https://microsoft.github.io/windows-docs-rs/doc/bindings/Windows/Win32/Etw/struct.EVENT_TRACE_LOGFILEA.html +/// [EVENT_TRACE_LOGFILEW]: https://microsoft.github.io/windows-docs-rs/doc/windows/Win32/System/Diagnostics/Etw/struct.EVENT_TRACE_LOGFILEW.html #[repr(C)] -#[derive(Clone, Copy)] +#[derive(Clone)] pub struct EventTraceLogfile<'tracedata> { - native: Etw::EVENT_TRACE_LOGFILEA, + native: Etw::EVENT_TRACE_LOGFILEW, + wide_logger_name: U16CString, lifetime: PhantomData<&'tracedata TraceData>, } impl<'tracedata> EventTraceLogfile<'tracedata> { /// Create a new instance pub fn create(trace_data: &'tracedata Box, callback: unsafe extern "system" fn(*mut Etw::EVENT_RECORD)) -> Self { - let mut log_file = EventTraceLogfile::default(); + let mut native = Etw::EVENT_TRACE_LOGFILEW::default(); - let not_really_mut_ptr = trace_data.name.as_ptr() as *mut _; // That's kind-of fine because the logger name is _not supposed_ to be changed by Windows APIs - log_file.native.LoggerName = PSTR(not_really_mut_ptr); - log_file.native.Anonymous1.ProcessTraceMode = + let mut wide_logger_name = U16CString::from_str_truncate(&trace_data.name); + native.LoggerName = PWSTR(wide_logger_name.as_mut_ptr()); + native.Anonymous1.ProcessTraceMode = u32::from(ProcessTraceMode::RealTime) | u32::from(ProcessTraceMode::EventRecord); - log_file.native.Anonymous2.EventRecordCallback = Some(callback); + native.Anonymous2.EventRecordCallback = Some(callback); let not_really_mut_ptr = trace_data.as_ref() as *const TraceData as *const c_void as *mut c_void; // That's kind-of fine because the user context is _not supposed_ to be changed by Windows APIs - log_file.native.Context = not_really_mut_ptr; + native.Context = not_really_mut_ptr; - log_file + Self { + native, + wide_logger_name, + lifetime: PhantomData, + } } /// Retrieve the windows-rs compatible pointer to the contained `EVENT_TRACE_LOGFILEA` /// /// # Safety /// - /// This pointer is valid as long as [`Self`] is alive (and not modified elsewhere) - pub unsafe fn as_mut_ptr(&mut self) -> *mut Etw::EVENT_TRACE_LOGFILEA { - &mut self.native as *mut Etw::EVENT_TRACE_LOGFILEA - } -} - -impl<'tracedata> Default for EventTraceLogfile<'tracedata> { - fn default() -> Self { - unsafe { std::mem::zeroed::() } + /// This pointer is valid as long as [`Self`] is alive (and not modified elsewhere)
+ /// Note that `OpenTraceW` **will** modify its content on output, and thus you should make sure to be the only user of this instance. + pub(crate) unsafe fn as_mut_ptr(&mut self) -> *mut Etw::EVENT_TRACE_LOGFILEW { + &mut self.native as *mut Etw::EVENT_TRACE_LOGFILEW } } diff --git a/src/native/evntrace.rs b/src/native/evntrace.rs index 4423d27..3d7e23e 100644 --- a/src/native/evntrace.rs +++ b/src/native/evntrace.rs @@ -177,7 +177,7 @@ impl NativeEtw { // // > On success, OpenTrace will update the structure with information from the opened file or session. // https://learn.microsoft.com/en-us/windows/win32/api/evntrace/nf-evntrace-opentracea - Etw::OpenTraceA(log_file.as_mut_ptr()) + Etw::OpenTraceW(log_file.as_mut_ptr()) }; if self.session_handle == INVALID_TRACE_HANDLE { From efa0a04bdcb59f13fa3b10b2962c6af6416aba2f Mon Sep 17 00:00:00 2001 From: daladim Date: Mon, 17 Oct 2022 14:24:48 +0200 Subject: [PATCH 3/7] Using StartTraceW rather than StartTraceA Also, this commit: * fixes a possible panic when trying to write an arbitrary-length String to a u8 array * better checks the error conditions for StartTraceW (a null handle should be considered invalid) --- src/native/etw_types.rs | 30 ++++++++++++++++++++---------- src/native/evntrace.rs | 36 +++++++++++++++++++++++------------- 2 files changed, 43 insertions(+), 23 deletions(-) diff --git a/src/native/etw_types.rs b/src/native/etw_types.rs index 614fb4e..02ef624 100644 --- a/src/native/etw_types.rs +++ b/src/native/etw_types.rs @@ -14,7 +14,6 @@ use std::fmt::Formatter; use std::marker::PhantomData; use windows::core::GUID; use windows::core::PWSTR; -use windows::Win32::Foundation::MAX_PATH; use windows::Win32::System::Diagnostics::Etw; use windows::Win32::System::Diagnostics::Etw::EVENT_FILTER_DESCRIPTOR; use widestring::ucstring::U16CString; @@ -31,6 +30,8 @@ pub(crate) type EvenTraceControl = Etw::EVENT_TRACE_CONTROL; pub const INVALID_TRACE_HANDLE: TraceHandle = u64::MAX; +pub const TRACE_NAME_MAX_CHARS: usize = 200; // Microsoft documentation says the limit is 1024, but do not trust us. Experience shows that traces with names longer than ~240 character silently fail. + /// This enum is /// /// Re-defining it here, because all these values are not defined in windows-rs (yet?) @@ -145,18 +146,25 @@ impl From for u32 { #[derive(Clone, Copy)] pub struct EventTraceProperties { etw_trace_properties: Etw::EVENT_TRACE_PROPERTIES, - trace_name: [u8; MAX_PATH as usize], - log_file_name: [u8; MAX_PATH as usize], // not used currently, but this may be useful when resolving https://github.com/n4r1b/ferrisetw/issues/7 + wide_trace_name: [u16; TRACE_NAME_MAX_CHARS+1], // The +1 leaves space for the final null widechar. + wide_log_file_name: [u16; TRACE_NAME_MAX_CHARS+1], // The +1 leaves space for the final null widechar. Not used currently, but this may be useful when resolving https://github.com/n4r1b/ferrisetw/issues/7 } impl std::fmt::Debug for EventTraceProperties { fn fmt(&self, f: &mut Formatter<'_>) -> std::fmt::Result { - write!(f, "") + let name = U16CString::from_vec_truncate(self.wide_trace_name).to_string_lossy(); + f.debug_struct("EventTraceProperties") + .field("name", &name) + .finish() } } impl EventTraceProperties { + /// Create a new instance + /// + /// # Notes + /// `trace_name` is limited to 200 characters. pub(crate) fn new( trace_name: &str, trace_properties: &TraceProperties, @@ -189,7 +197,7 @@ impl EventTraceProperties { // etw_trace_properties.LogFileNameOffset must be 0, but this will change when https://github.com/n4r1b/ferrisetw/issues/7 is resolved // > If you do not want to log events to a log file (for example, if you specify EVENT_TRACE_REAL_TIME_MODE only), set LogFileNameOffset to 0. // (https://learn.microsoft.com/en-us/windows/win32/api/evntrace/ns-evntrace-event_trace_properties) - etw_trace_properties.LoggerNameOffset = offset_of!(EventTraceProperties, log_file_name) as u32; + etw_trace_properties.LoggerNameOffset = offset_of!(EventTraceProperties, wide_log_file_name) as u32; // https://learn.microsoft.com/en-us/windows/win32/api/evntrace/ns-evntrace-event_trace_properties#remarks // > You do not copy the session name to the offset. The StartTrace function copies the name for you. @@ -197,10 +205,12 @@ impl EventTraceProperties { // Let's do it anyway, even though that's not required let mut s = Self { etw_trace_properties, - trace_name: [0; MAX_PATH as usize], - log_file_name: [0; MAX_PATH as usize], + wide_trace_name: [0u16; TRACE_NAME_MAX_CHARS+1], + wide_log_file_name: [0u16; TRACE_NAME_MAX_CHARS+1], }; - s.trace_name[..trace_name.len()].copy_from_slice(trace_name.as_bytes()); + let wide_trace_name = U16CString::from_str_truncate(trace_name); + let name_len = wide_trace_name.len().min(TRACE_NAME_MAX_CHARS); + s.wide_trace_name[..name_len].copy_from_slice(&wide_trace_name.as_slice()[..name_len]); s } @@ -217,8 +227,8 @@ impl EventTraceProperties { &mut self.etw_trace_properties as *mut Etw::EVENT_TRACE_PROPERTIES } - pub fn trace_name_array(&self) -> &[u8] { - &self.trace_name + pub fn trace_name_array(&self) -> &[u16] { + &self.wide_trace_name } } diff --git a/src/native/evntrace.rs b/src/native/evntrace.rs index 3d7e23e..5c90964 100644 --- a/src/native/evntrace.rs +++ b/src/native/evntrace.rs @@ -7,7 +7,7 @@ //! with the crate use std::panic::AssertUnwindSafe; -use windows::core::{GUID, PCSTR}; +use windows::core::{GUID, PCWSTR}; use windows::Win32::Foundation::FILETIME; use windows::Win32::System::Diagnostics::Etw; use windows::Win32::System::Diagnostics::Etw::TRACE_QUERY_INFO_CLASS; @@ -150,20 +150,30 @@ impl NativeEtw { } fn start_trace(&mut self) -> EvntraceNativeResult<()> { - unsafe { - let status = Etw::StartTraceA( + let status = unsafe { + // Safety: + // * first argument points to a valid and allocated address (this is an output and will be modified) + // * second argument is a valid, null terminated widestring (note that it will be copied to the EventTraceProperties...from where it already comes. This will probably be overwritten by Windows, but heck.) + // * third argument is a valid, allocated EVENT_TRACE_PROPERTIES (and will be mutated) + // * Note: the string (that will be overwritten to itself) ends with a null widechar before the end of its buffer (see EventTraceProperties::new()) + Etw::StartTraceW( &mut self.registration_handle, - PCSTR::from_raw(self.info.trace_name_array().as_ptr()), + PCWSTR::from_raw(self.info.trace_name_array().as_ptr()), self.info.as_mut_ptr(), - ); - - if status == ERROR_ALREADY_EXISTS.0 { - return Err(EvntraceNativeError::AlreadyExist); - } else if status != 0 { - return Err(EvntraceNativeError::IoError( - std::io::Error::from_raw_os_error(status as i32), - )); - } + ) + }; + + if status == ERROR_ALREADY_EXISTS.0 { + return Err(EvntraceNativeError::AlreadyExist); + } else if status != 0 { + return Err(EvntraceNativeError::IoError( + std::io::Error::from_raw_os_error(status as i32), + )); + } else if self.registration_handle == 0 { + // Because Microsoft says that + // > The session handle is 0 if the handle is not valid. + // (https://learn.microsoft.com/en-us/windows/win32/api/evntrace/nf-evntrace-starttracew) + return Err(EvntraceNativeError::InvalidHandle); } Ok(()) } From 3beb6f83fb1a58ebfc3cb4bf5f7a488f703ae414 Mon Sep 17 00:00:00 2001 From: daladim Date: Mon, 17 Oct 2022 15:04:16 +0200 Subject: [PATCH 4/7] Using ControlTraceW rather than ControlTraceA --- src/native/evntrace.rs | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/src/native/evntrace.rs b/src/native/evntrace.rs index 5c90964..d3c93d9 100644 --- a/src/native/evntrace.rs +++ b/src/native/evntrace.rs @@ -231,10 +231,12 @@ impl NativeEtw { ) -> EvntraceNativeResult<()> { let status = unsafe { // Safety: + // * the PCWSTR points to a valid, null-terminated widestring // * depending on the control code, the `Properties` can be mutated - Etw::ControlTraceA( + // note that the PCWSTR also points to this mutable instance, but the PCWSTR is an input-only (hence constant) parameter + Etw::ControlTraceW( 0, - PCSTR::from_raw(trace_data.name.as_ptr()), + PCWSTR::from_raw(self.info.trace_name_array().as_ptr()), self.info.as_mut_ptr(), control_code, ) From e446b3f2ab5a08eaed29d866729b73d4279458da Mon Sep 17 00:00:00 2001 From: daladim Date: Mon, 17 Oct 2022 15:14:12 +0200 Subject: [PATCH 5/7] Trace now has a Builder This largely refactors trace.rs and evntrace.rs * evntrace now solely contains safe wrappers over Windows API functions, without any internal state (struct NativeEtw has been removed) that's the duty of trace.rs to handle these API correctly and in the right order. * Traces instances are now created with a Builder pattern, to clearly mark which fields may be mutable and which will stay constant. This will make it very easy to fix races in issue #45 Also, as minor improvements: * the builder now enforces the trace name is truncated to TRACE_NAME_MAX_CHARS, so that both EVENT_TRACE_LOGFILEW and EVENT_TRACE_PROPERTIES have consistently truncated logger names * TraceData is renamed CallbackData. That's mainly a matter of taste, even though it makes its intent clearer, and thus makes it easier to review the `unsafe` blocks * errors from evntrace are now better forwarded to callers * checks for invalid handles from the Windows API has been made more explicit * the public API for traces (and trace builder) is now simplified, and hides some of the "really weird" (to say the least) design choices of ETW. Distinction between open/start/process is now clearer to the user Also, the `process` now exists in different flavours, that do not all hide the thread spawning. This offers more control to the end user. * Traces can explictly be closed, and are closed if still open on Drop (maybe that was the case in ferrisetw 0.1, I'm not sure) * This removes the distinction between TraceTrait and TraceBaseTrait Sorry, I did not manage to split this large commit into smaller chunks. It's probably easier to read only the result of it rather than the diffs, which do not make much sense since most of evntrace.rs and trace.rs are now diffs. --- examples/dns.rs | 9 +- examples/kernel_trace.rs | 6 +- examples/multiple_providers.rs | 7 +- examples/user_trace.rs | 14 +- src/lib.rs | 10 +- src/native/etw_types.rs | 36 +- src/native/etw_types/event_record.rs | 2 +- src/native/evntrace.rs | 391 ++++++++++--------- src/provider.rs | 1 - src/trace.rs | 550 ++++++++++++++------------- tests/dns.rs | 15 +- tests/kernel_trace.rs | 3 +- 12 files changed, 536 insertions(+), 508 deletions(-) diff --git a/examples/dns.rs b/examples/dns.rs index 7a411fd..3f12ae1 100644 --- a/examples/dns.rs +++ b/examples/dns.rs @@ -9,7 +9,6 @@ use ferrisetw::schema_locator::SchemaLocator; use ferrisetw::native::etw_types::EventRecord; use ferrisetw::trace::UserTrace; use ferrisetw::parser::TryParse; -use ferrisetw::trace::TraceBaseTrait; use ferrisetw::schema::Schema; @@ -74,16 +73,16 @@ fn main() { .trace_flags(TraceFlags::EVENT_ENABLE_PROPERTY_PROCESS_START_KEY) .build(); - let mut trace = UserTrace::new() + let trace = UserTrace::new() .enable(dns_provider) - .start() + .start_and_process() .unwrap(); println!("ID Status Options Ty Name Results"); - std::thread::sleep(Duration::new(120, 0)); - trace.stop(); + std::thread::sleep(Duration::new(20, 0)); + trace.stop().unwrap(); // This is not required, as it will automatically be stopped on Drop println!("Done: {:?} events", N_EVENTS); } diff --git a/examples/kernel_trace.rs b/examples/kernel_trace.rs index 0d59282..9cc639e 100644 --- a/examples/kernel_trace.rs +++ b/examples/kernel_trace.rs @@ -31,12 +31,12 @@ fn main() { .add_callback(image_load_callback) .build(); - let mut trace = KernelTrace::new() + let kernel_trace = KernelTrace::new() .named(String::from("MyKernelProvider")) .enable(provider) - .start() + .start_and_process() .unwrap(); std::thread::sleep(Duration::new(20, 0)); - trace.stop(); + kernel_trace.stop().unwrap(); // This is not required, as it will automatically be stopped on Drop } diff --git a/examples/multiple_providers.rs b/examples/multiple_providers.rs index 214ef40..65d99d0 100644 --- a/examples/multiple_providers.rs +++ b/examples/multiple_providers.rs @@ -60,12 +60,13 @@ fn main() { .add_callback(registry_callback) .build(); - let mut trace = UserTrace::new() + let user_trace = UserTrace::new() .enable(process_provider) .enable(tcpip_provider) - .start() + .start_and_process() .unwrap(); std::thread::sleep(Duration::new(10, 0)); - trace.stop(); + + user_trace.stop().unwrap(); // optional. Simply dropping user_trace has the same effect } diff --git a/examples/user_trace.rs b/examples/user_trace.rs index ae946da..3bcb066 100644 --- a/examples/user_trace.rs +++ b/examples/user_trace.rs @@ -33,12 +33,22 @@ fn main() { .add_callback(process_callback) .build(); - let mut trace = UserTrace::new() + let (_user_trace, handle) = UserTrace::new() .named(String::from("MyProvider")) .enable(process_provider) .start() .unwrap(); + // This example uses `process_from_handle` rather than the more convient `start_and_process`, because why not. + std::thread::spawn(move || { + let status = UserTrace::process_from_handle(handle); + // This code will be executed when the trace stops. Examples: + // * when it is dropped + // * when it is manually stopped (either by user_trace.stop, or by the `logman stop -ets MyProvider` command) + println!("Trace ended with status {:?}", status); + }); + std::thread::sleep(Duration::new(20, 0)); - trace.stop(); + + // user_trace will be dropped (and stopped) here } diff --git a/src/lib.rs b/src/lib.rs index 3d4a592..dee47a8 100644 --- a/src/lib.rs +++ b/src/lib.rs @@ -50,7 +50,7 @@ //! use ferrisetw::parser::Parser; //! use ferrisetw::parser::TryParse; //! use ferrisetw::provider::Provider; -//! use ferrisetw::trace::{UserTrace, TraceTrait, TraceBaseTrait}; +//! use ferrisetw::trace::{UserTrace, TraceTrait}; //! //! fn process_callback(record: &EventRecord, schema_locator: &SchemaLocator) { //! // Within the callback we first locate the proper Schema for the event @@ -84,12 +84,14 @@ //! .build(); //! //! // We start a trace session for the previously registered provider -//! // This call will spawn a new thread which listens to the events +//! // Callbacks will be run in a separate thread. //! let mut trace = UserTrace::new() //! .named(String::from("MyProvider")) //! .enable(process_provider) -//! // .enable(other_provider) // it is possible to enable multiple providers on the same trace -//! .start() +//! // .enable(other_provider) // It is possible to enable multiple providers on the same trace. +//! .start_and_process() // This call will spawn the thread for you. +//! // See the doc for alternative ways of processing the trace, +//! // with more or less flexibility regarding this spawned thread. //! .unwrap(); //! //! std::thread::sleep(std::time::Duration::from_secs(3)); diff --git a/src/native/etw_types.rs b/src/native/etw_types.rs index 02ef624..deecdfc 100644 --- a/src/native/etw_types.rs +++ b/src/native/etw_types.rs @@ -7,8 +7,8 @@ //! In most cases a user of the crate won't have to deal with this and can directly obtain the data //! needed by using the functions exposed by the modules at the crate level use crate::provider::event_filter::EventFilterDescriptor; -use crate::provider::{Provider, TraceFlags}; -use crate::trace::{TraceData, TraceProperties, TraceTrait}; +use crate::provider::TraceFlags; +use crate::trace::{CallbackData, TraceProperties, TraceTrait}; use std::ffi::c_void; use std::fmt::Formatter; use std::marker::PhantomData; @@ -16,7 +16,7 @@ use windows::core::GUID; use windows::core::PWSTR; use windows::Win32::System::Diagnostics::Etw; use windows::Win32::System::Diagnostics::Etw::EVENT_FILTER_DESCRIPTOR; -use widestring::ucstring::U16CString; +use widestring::{U16CStr, U16CString}; mod event_record; pub use event_record::EventRecord; @@ -24,12 +24,6 @@ pub use event_record::EventRecord; mod extended_data; pub use extended_data::{ExtendedDataItem, EventHeaderExtendedDataItem}; -// typedef ULONG64 TRACEHANDLE, *PTRACEHANDLE; -pub(crate) type TraceHandle = u64; -pub(crate) type EvenTraceControl = Etw::EVENT_TRACE_CONTROL; - -pub const INVALID_TRACE_HANDLE: TraceHandle = u64::MAX; - pub const TRACE_NAME_MAX_CHARS: usize = 200; // Microsoft documentation says the limit is 1024, but do not trust us. Experience shows that traces with names longer than ~240 character silently fail. /// This enum is @@ -166,9 +160,9 @@ impl EventTraceProperties { /// # Notes /// `trace_name` is limited to 200 characters. pub(crate) fn new( - trace_name: &str, + trace_name: &U16CStr, trace_properties: &TraceProperties, - providers: &[Provider], + enable_flags: Etw::EVENT_TRACE_FLAG, ) -> Self where T: TraceTrait @@ -192,7 +186,7 @@ impl EventTraceProperties { } etw_trace_properties.LogFileMode |= T::augmented_file_mode(); - etw_trace_properties.EnableFlags = Etw::EVENT_TRACE_FLAG(T::enable_flags(providers)); + etw_trace_properties.EnableFlags = enable_flags; // etw_trace_properties.LogFileNameOffset must be 0, but this will change when https://github.com/n4r1b/ferrisetw/issues/7 is resolved // > If you do not want to log events to a log file (for example, if you specify EVENT_TRACE_REAL_TIME_MODE only), set LogFileNameOffset to 0. @@ -208,9 +202,8 @@ impl EventTraceProperties { wide_trace_name: [0u16; TRACE_NAME_MAX_CHARS+1], wide_log_file_name: [0u16; TRACE_NAME_MAX_CHARS+1], }; - let wide_trace_name = U16CString::from_str_truncate(trace_name); - let name_len = wide_trace_name.len().min(TRACE_NAME_MAX_CHARS); - s.wide_trace_name[..name_len].copy_from_slice(&wide_trace_name.as_slice()[..name_len]); + let name_len = trace_name.len().min(TRACE_NAME_MAX_CHARS); + s.wide_trace_name[..name_len].copy_from_slice(&trace_name.as_slice()[..name_len]); s } @@ -234,28 +227,29 @@ impl EventTraceProperties { /// Newtype wrapper over an [EVENT_TRACE_LOGFILEW] /// +/// Its lifetime is tied a to [`CallbackData`] because it contains raw pointers to it. +/// /// [EVENT_TRACE_LOGFILEW]: https://microsoft.github.io/windows-docs-rs/doc/windows/Win32/System/Diagnostics/Etw/struct.EVENT_TRACE_LOGFILEW.html #[repr(C)] #[derive(Clone)] -pub struct EventTraceLogfile<'tracedata> { +pub struct EventTraceLogfile<'callbackdata> { native: Etw::EVENT_TRACE_LOGFILEW, wide_logger_name: U16CString, - lifetime: PhantomData<&'tracedata TraceData>, + lifetime: PhantomData<&'callbackdata CallbackData>, } -impl<'tracedata> EventTraceLogfile<'tracedata> { +impl<'callbackdata> EventTraceLogfile<'callbackdata> { /// Create a new instance - pub fn create(trace_data: &'tracedata Box, callback: unsafe extern "system" fn(*mut Etw::EVENT_RECORD)) -> Self { + pub fn create(callback_data: &'callbackdata Box, mut wide_logger_name: U16CString, callback: unsafe extern "system" fn(*mut Etw::EVENT_RECORD)) -> Self { let mut native = Etw::EVENT_TRACE_LOGFILEW::default(); - let mut wide_logger_name = U16CString::from_str_truncate(&trace_data.name); native.LoggerName = PWSTR(wide_logger_name.as_mut_ptr()); native.Anonymous1.ProcessTraceMode = u32::from(ProcessTraceMode::RealTime) | u32::from(ProcessTraceMode::EventRecord); native.Anonymous2.EventRecordCallback = Some(callback); - let not_really_mut_ptr = trace_data.as_ref() as *const TraceData as *const c_void as *mut c_void; // That's kind-of fine because the user context is _not supposed_ to be changed by Windows APIs + let not_really_mut_ptr = callback_data.as_ref() as *const CallbackData as *const c_void as *mut c_void; // That's kind-of fine because the user context is _not supposed_ to be changed by Windows APIs native.Context = not_really_mut_ptr; Self { diff --git a/src/native/etw_types/event_record.rs b/src/native/etw_types/event_record.rs index 467add0..42f8cbe 100644 --- a/src/native/etw_types/event_record.rs +++ b/src/native/etw_types/event_record.rs @@ -33,7 +33,7 @@ impl EventRecord { /// The `UserContext` field from the wrapped `EVENT_RECORD` /// - /// In this crate, it is always populated to point to a valid [`TraceData`](crate::trace::TraceData) + /// In this crate, it is always populated to point to a valid [`CallbackData`](crate::trace::CallbackData) pub fn user_context(&self) -> *const std::ffi::c_void { self.0.UserContext as *const _ } diff --git a/src/native/evntrace.rs b/src/native/evntrace.rs index d3c93d9..54e95cd 100644 --- a/src/native/evntrace.rs +++ b/src/native/evntrace.rs @@ -1,17 +1,19 @@ -//! Native API - Event Tracing evntrace header +//! Safe wrappers for the native ETW API //! -//! The `evntrace` module is an abstraction layer for the Windows evntrace library. This module act as a -//! internal API that holds all `unsafe` calls to functions exported by the `evntrace` Windows library. -//! -//! This module shouldn't be accessed directly. Modules from the crate level provide a safe API to interact -//! with the crate +//! This module makes sure the calls are safe memory-wise, but does not attempt to ensure they are called in the right order.
+//! Thus, you should prefer using `UserTrace`s, `KernelTrace`s and `TraceBuilder`s, that will ensure these API are correctly used. use std::panic::AssertUnwindSafe; -use windows::core::{GUID, PCWSTR}; +use widestring::{U16CString, U16CStr}; +use windows::Win32::Foundation::WIN32_ERROR; +use windows::Win32::System::Diagnostics::Etw::EVENT_CONTROL_CODE_ENABLE_PROVIDER; +use windows::core::GUID; +use windows::core::PCWSTR; use windows::Win32::Foundation::FILETIME; use windows::Win32::System::Diagnostics::Etw; use windows::Win32::System::Diagnostics::Etw::TRACE_QUERY_INFO_CLASS; use windows::Win32::System::SystemInformation::GetSystemTimeAsFileTime; +use windows::Win32::Foundation::ERROR_SUCCESS; use windows::Win32::Foundation::ERROR_ALREADY_EXISTS; use windows::Win32::Foundation::ERROR_CTX_CLOSE_PENDING; use windows::Win32::Foundation::ERROR_WMI_INSTANCE_NOT_FOUND; @@ -19,8 +21,11 @@ use windows::Win32::Foundation::ERROR_WMI_INSTANCE_NOT_FOUND; use super::etw_types::*; use crate::provider::Provider; -use crate::trace::{TraceData, TraceProperties, TraceTrait}; -use crate::traits::*; +use crate::provider::event_filter::EventFilterDescriptor; +use crate::trace::{CallbackData, TraceProperties, TraceTrait}; + +pub type TraceHandle = u64; +pub type ControlHandle = u64; /// Evntrace native module errors #[derive(Debug)] @@ -33,16 +38,9 @@ pub enum EvntraceNativeError { IoError(std::io::Error), } -impl LastOsError for EvntraceNativeError {} - -impl From for EvntraceNativeError { - fn from(err: std::io::Error) -> Self { - EvntraceNativeError::IoError(err) - } -} - pub(crate) type EvntraceNativeResult = Result; +/// This will be called by the ETW framework whenever an ETW event is available extern "system" fn trace_callback_thunk(p_record: *mut Etw::EVENT_RECORD) { match std::panic::catch_unwind(AssertUnwindSafe(|| { let record_from_ptr = unsafe { @@ -51,12 +49,15 @@ extern "system" fn trace_callback_thunk(p_record: *mut Etw::EVENT_RECORD) { }; if let Some(event_record) = record_from_ptr { - let p_user_context = event_record.user_context().cast::(); + let p_user_context = event_record.user_context().cast::(); let user_context = unsafe { // Safety: - // * the API of this create guarantees this points to a `TraceData` already allocated and created - // * TODO (#45): the API of this crate does not yet guarantee this `TraceData` is not mutated during the trace (e.g. modifying the list of providers) (although this may not be critical memory-safety-wise) - // * TODO (#45): the API of this create does not yet guarantee this `TraceData` has not been dropped + // * the API of this create guarantees this points to a `CallbackData` already allocated and created + // * TODO (#45): the API of this create does not yet guarantee this `CallbackData` has not been dropped + // * the API of this crate guarantees this `CallbackData` is not mutated from another thread during the trace: + // * we're the only one to change CallbackData::events_handled (and that's an atomic, so it's fine) + // * the list of Providers is a constant (may change in the future with #54) + // * the schema_locator only has interior mutability p_user_context.as_ref() }; if let Some(user_context) = user_context { @@ -72,210 +73,208 @@ extern "system" fn trace_callback_thunk(p_record: *mut Etw::EVENT_RECORD) { } } -#[derive(Debug, Clone)] -pub(crate) struct NativeEtw { - info: EventTraceProperties, - session_handle: TraceHandle, - registration_handle: TraceHandle, +fn filter_invalid_trace_handles(h: TraceHandle) -> Option { + // See https://learn.microsoft.com/en-us/windows/win32/api/evntrace/nf-evntrace-opentracew#return-value + // We're conservative and we always filter out u32::MAX, although it could be valid on 64-bit setups. + // But it turns out runtime detection of the current OS bitness is not that easy. Plus, it is not clear whether this depends on how the architecture the binary is compiled for, or the actual OS architecture. + if h == u64::MAX || h == u32::MAX as u64 { + None + } else { + Some(h) + } } -impl NativeEtw { - pub(crate) fn new(name: &str, properties: &TraceProperties, providers: &[Provider]) -> Self - where - T: TraceTrait, - { - NativeEtw { - info: EventTraceProperties::new::(name, properties, providers), - session_handle: INVALID_TRACE_HANDLE, - registration_handle: INVALID_TRACE_HANDLE, - } +fn filter_invalid_control_handle(h: ControlHandle) -> Option { + // The control handle is 0 if the handle is not valid. + // (https://learn.microsoft.com/en-us/windows/win32/api/evntrace/nf-evntrace-starttracew) + if h == 0 { + None + } else { + Some(h) } +} - pub(crate) fn session_handle(&self) -> TraceHandle { - self.session_handle +/// Create a new session. +/// +/// This builds an `EventTraceProperties`, calls `StartTraceW` and returns the built `EventTraceProperties` as well as the trace ControlHandle +pub fn start_trace(trace_name: &U16CStr, trace_properties: &TraceProperties, enable_flags: Etw::EVENT_TRACE_FLAG) -> EvntraceNativeResult<(EventTraceProperties, ControlHandle)> +where + T: TraceTrait +{ + let mut properties = EventTraceProperties::new::(trace_name, trace_properties, enable_flags); + + let mut control_handle = ControlHandle::default(); + let status = unsafe { + // Safety: + // * first argument points to a valid and allocated address (this is an output and will be modified) + // * second argument is a valid, null terminated widestring (note that it will be copied to the EventTraceProperties...from where it already comes. This will probably be overwritten by Windows, but heck.) + // * third argument is a valid, allocated EVENT_TRACE_PROPERTIES (and will be mutated) + // * Note: the string (that will be overwritten to itself) ends with a null widechar before the end of its buffer (see EventTraceProperties::new()) + Etw::StartTraceW( + &mut control_handle, + PCWSTR::from_raw(properties.trace_name_array().as_ptr()), + properties.as_mut_ptr(), + ) + }; + + if status == ERROR_ALREADY_EXISTS.0 { + return Err(EvntraceNativeError::AlreadyExist); + } else if status != 0 { + return Err(EvntraceNativeError::IoError( + std::io::Error::from_raw_os_error(status as i32), + )); } - pub(crate) fn start(&mut self) -> EvntraceNativeResult<()> { - if self.session_handle == INVALID_TRACE_HANDLE { - return Err(EvntraceNativeError::InvalidHandle); - } - self.process() + match filter_invalid_control_handle(control_handle) { + None => Err(EvntraceNativeError::InvalidHandle), + Some(handle) => Ok((properties, handle)), } +} - pub(crate) fn open<'a>( - &mut self, - trace_data: &'a Box, - ) -> EvntraceNativeResult> { - self.open_trace(trace_data) - } - pub(crate) fn stop(&mut self, trace_data: &TraceData) -> EvntraceNativeResult<()> { - self.stop_trace(trace_data)?; - self.close_trace()?; - Ok(()) +/// Subscribe to a started trace +/// +/// Microsoft calls this "opening" the trace (and this calls `OpenTraceW`) +pub fn open_trace(trace_name: U16CString, callback_data: &Box) -> EvntraceNativeResult { + let mut log_file = EventTraceLogfile::create(&callback_data, trace_name, trace_callback_thunk); + + let trace_handle = unsafe { + // This function modifies the data pointed to by log_file. + // This is fine because there is currently no other ref `self` (the current function takes a `&mut self`, and `self` is not used anywhere else in the current function) + // + // > On success, OpenTrace will update the structure with information from the opened file or session. + // https://learn.microsoft.com/en-us/windows/win32/api/evntrace/nf-evntrace-opentracea + Etw::OpenTraceW(log_file.as_mut_ptr()) + }; + + if filter_invalid_trace_handles(trace_handle).is_none() { + Err(EvntraceNativeError::IoError(std::io::Error::last_os_error())) + } else { + Ok(trace_handle) } +} - pub(crate) fn process(&mut self) -> EvntraceNativeResult<()> { - if self.session_handle == INVALID_TRACE_HANDLE { - return Err(EvntraceNativeError::InvalidHandle); - } - - let clone_handle = self.session_handle; - std::thread::spawn(move || { - let mut now = FILETIME::default(); - unsafe { - GetSystemTimeAsFileTime(&mut now); - - Etw::ProcessTrace(&[clone_handle], &now, std::ptr::null_mut()); - // if Etw::ProcessTrace(&[clone_handlee], &mut now, std::ptr::null_mut()) != 0 { - // return Err(EvntraceNativeError::IoError(std::io::Error::last_os_error())); - // } - } - }); - - Ok(()) - } +/// Attach a provider to a trace +pub fn enable_provider(control_handle: ControlHandle, provider: &Provider) -> EvntraceNativeResult<()> { + match filter_invalid_control_handle(control_handle) { + None => Err(EvntraceNativeError::InvalidHandle), + Some(handle) => { + let owned_event_filter_descriptors: Vec = provider.filters() + .iter() + .filter_map(|filter| filter.to_event_filter_descriptor().ok()) // Silently ignoring invalid filters (basically, empty ones) + .collect(); + + let parameters = + EnableTraceParameters::create(provider.guid(), provider.trace_flags(), &owned_event_filter_descriptors); + + let res = unsafe { + Etw::EnableTraceEx2( + handle, + &provider.guid() as *const GUID, + EVENT_CONTROL_CODE_ENABLE_PROVIDER.0, + provider.level(), + provider.any(), + provider.all(), + 0, + parameters.as_ptr(), + ) + }; - pub(crate) fn register_trace(&mut self, trace_data: &TraceData) -> EvntraceNativeResult<()> { - if let Err(err) = self.start_trace() { - if matches!(err, EvntraceNativeError::AlreadyExist) { - // TODO: Check need admin errors - self.stop_trace(trace_data)?; - self.start_trace()?; + if res == ERROR_SUCCESS.0 { + Ok(()) } else { - return Err(err); + Err( + EvntraceNativeError::IoError( + std::io::Error::from_raw_os_error(res as i32) + ) + ) } } - Ok(()) - } - - fn start_trace(&mut self) -> EvntraceNativeResult<()> { - let status = unsafe { - // Safety: - // * first argument points to a valid and allocated address (this is an output and will be modified) - // * second argument is a valid, null terminated widestring (note that it will be copied to the EventTraceProperties...from where it already comes. This will probably be overwritten by Windows, but heck.) - // * third argument is a valid, allocated EVENT_TRACE_PROPERTIES (and will be mutated) - // * Note: the string (that will be overwritten to itself) ends with a null widechar before the end of its buffer (see EventTraceProperties::new()) - Etw::StartTraceW( - &mut self.registration_handle, - PCWSTR::from_raw(self.info.trace_name_array().as_ptr()), - self.info.as_mut_ptr(), - ) - }; - - if status == ERROR_ALREADY_EXISTS.0 { - return Err(EvntraceNativeError::AlreadyExist); - } else if status != 0 { - return Err(EvntraceNativeError::IoError( - std::io::Error::from_raw_os_error(status as i32), - )); - } else if self.registration_handle == 0 { - // Because Microsoft says that - // > The session handle is 0 if the handle is not valid. - // (https://learn.microsoft.com/en-us/windows/win32/api/evntrace/nf-evntrace-starttracew) - return Err(EvntraceNativeError::InvalidHandle); - } - Ok(()) } +} - fn open_trace<'a>(&mut self, trace_data: &'a Box) -> EvntraceNativeResult> { - let mut log_file = EventTraceLogfile::create(trace_data, trace_callback_thunk); - - self.session_handle = unsafe { - // This function modifies the data pointed to by log_file. - // This is fine because there is currently no other ref `self` (the current function takes a `&mut self`, and `self` is not used anywhere else in the current function) - // - // > On success, OpenTrace will update the structure with information from the opened file or session. - // https://learn.microsoft.com/en-us/windows/win32/api/evntrace/nf-evntrace-opentracea - Etw::OpenTraceW(log_file.as_mut_ptr()) +/// Start processing a trace (this call is blocking until the trace is stopped) +/// +/// You probably want to spawn a thread that will block on this call. +pub fn process_trace(trace_handle: TraceHandle) -> EvntraceNativeResult<()> { + if filter_invalid_trace_handles(trace_handle).is_none() { + return Err(EvntraceNativeError::InvalidHandle); + } else { + let mut now = FILETIME::default(); + let result = unsafe { + GetSystemTimeAsFileTime(&mut now); + Etw::ProcessTrace(&[trace_handle], &mut now, std::ptr::null_mut()) }; - if self.session_handle == INVALID_TRACE_HANDLE { - return Err(EvntraceNativeError::IoError(std::io::Error::last_os_error())); + if result == ERROR_SUCCESS.0 { + Ok(()) + } else { + Err(EvntraceNativeError::IoError(std::io::Error::from_raw_os_error(result as i32))) } - - Ok(log_file) } +} - fn stop_trace(&mut self, trace_data: &TraceData) -> EvntraceNativeResult<()> { - self.control_trace( - trace_data, - windows::Win32::System::Diagnostics::Etw::EVENT_TRACE_CONTROL_STOP, - )?; - Ok(()) - } +/// Call `ControlTraceW` on the trace +/// +/// # Notes +/// +/// In case you want to close the trace, you probably want to drop the instance rather than calling `control(EVENT_TRACE_CONTROL_STOP)` yourself, +/// because closing the trace makes the trace handle invalid. +/// A closed trace could theoretically(?) be re-used, but the trace handle should be re-created, so `open` should be called again. +pub fn control_trace( + properties: &mut EventTraceProperties, + control_handle: ControlHandle, + control_code: Etw::EVENT_TRACE_CONTROL, +) -> EvntraceNativeResult<()> { + match filter_invalid_control_handle(control_handle) { + None => return Err(EvntraceNativeError::InvalidHandle), + Some(handle) => { + let status = unsafe { + // Safety: + // * the trace handle is valid (by construction) + // * depending on the control code, the `Properties` can be mutated. This is fine because properties is declared as `&mut` in this function, which means no other Rust function has a reference to it, and the mutation can only happen in the call to `ControlTraceW`, which returns immediately. + Etw::ControlTraceW( + handle, + PCWSTR::null(), + properties.as_mut_ptr(), + control_code, + ) + }; - fn close_trace(&mut self) -> EvntraceNativeResult<()> { - if self.session_handle == INVALID_TRACE_HANDLE { - return Err(EvntraceNativeError::InvalidHandle); - } + if status != 0 && status != ERROR_WMI_INSTANCE_NOT_FOUND.0 { + return Err(EvntraceNativeError::IoError( + std::io::Error::from_raw_os_error(status as i32), + )); + } - let status = unsafe { - // Safety: the handle is valid - Etw::CloseTrace(self.session_handle) - }; - if status != 0 && status != ERROR_CTX_CLOSE_PENDING.0 { - return Err(EvntraceNativeError::IoError( - std::io::Error::from_raw_os_error(status as i32), - )); + Ok(()) } - - self.session_handle = INVALID_TRACE_HANDLE; - Ok(()) } +} - fn control_trace( - &mut self, - trace_data: &TraceData, - control_code: EvenTraceControl, - ) -> EvntraceNativeResult<()> { - let status = unsafe { - // Safety: - // * the PCWSTR points to a valid, null-terminated widestring - // * depending on the control code, the `Properties` can be mutated - // note that the PCWSTR also points to this mutable instance, but the PCWSTR is an input-only (hence constant) parameter - Etw::ControlTraceW( - 0, - PCWSTR::from_raw(self.info.trace_name_array().as_ptr()), - self.info.as_mut_ptr(), - control_code, - ) - }; - - if status != 0 && status != ERROR_WMI_INSTANCE_NOT_FOUND.0 { - return Err(EvntraceNativeError::IoError( - std::io::Error::from_raw_os_error(status as i32), - )); - } - - Ok(()) - } +/// Close the trace +/// +/// It is suggested to stop the trace immediately after `close`ing it (that's what it done in the `impl Drop`), because I'm not sure how sensible it is to call other methods (apart from `stop`) afterwards +/// +/// In case ETW reports there are still events in the queue that are still to trigger callbacks, this returns Ok(true).
+/// If no further event callback will be invoked, this returns Ok(false)
+/// On error, this returns an `Err` +pub fn close_trace(trace_handle: TraceHandle) -> EvntraceNativeResult { + match filter_invalid_trace_handles(trace_handle) { + None => Err(EvntraceNativeError::InvalidHandle), + Some(handle) => { + let status = unsafe { + Etw::CloseTrace(handle) + }; - pub(crate) fn enable_trace( - &self, - guid: GUID, - any: u64, - all: u64, - level: u8, - parameters: EnableTraceParameters, - ) -> EvntraceNativeResult<()> { - match unsafe { - Etw::EnableTraceEx2( - self.registration_handle, - &guid, - 1, // Fixme: EVENT_CONTROL_CODE_ENABLE_PROVIDER - level, - any, - all, - 0, - parameters.as_ptr(), - ) - } { - 0 => Ok(()), - e => Err(EvntraceNativeError::IoError( - std::io::Error::from_raw_os_error(e as i32), - )), + match WIN32_ERROR(status) { + ERROR_SUCCESS => Ok(false), + ERROR_CTX_CLOSE_PENDING => Ok(true), + status @ _ => Err(EvntraceNativeError::IoError( + std::io::Error::from_raw_os_error(status.0 as i32), + )) } + }, } } diff --git a/src/provider.rs b/src/provider.rs index e19b347..361678d 100644 --- a/src/provider.rs +++ b/src/provider.rs @@ -480,7 +480,6 @@ impl ProviderBuilder { /// /// # Example /// ``` - /// # use crate::ferrisetw::trace::TraceBaseTrait; /// # use ferrisetw::provider::Provider; /// # use ferrisetw::trace::UserTrace; /// # use ferrisetw::native::etw_types::EventRecord; diff --git a/src/trace.rs b/src/trace.rs index 7a5d65b..a04affd 100644 --- a/src/trace.rs +++ b/src/trace.rs @@ -1,16 +1,20 @@ //! ETW Tracing/Session abstraction //! //! Provides both a Kernel and User trace that allows to start an ETW session +use std::marker::PhantomData; use std::sync::atomic::{AtomicUsize, Ordering}; -use super::traits::*; -use crate::native::etw_types::{EnableTraceParameters, EventRecord, INVALID_TRACE_HANDLE}; +use self::private::PrivateTraceTrait; + +use crate::native::etw_types::{EventRecord, EventTraceProperties}; use crate::native::{evntrace, version_helper}; +use crate::native::evntrace::{ControlHandle, TraceHandle, start_trace, open_trace, process_trace, enable_provider, control_trace, close_trace}; use crate::provider::Provider; -use crate::provider::event_filter::EventFilterDescriptor; use crate::{provider, utils}; use crate::schema_locator::SchemaLocator; use windows::core::GUID; +use windows::Win32::System::Diagnostics::Etw; +use widestring::U16CString; const KERNEL_LOGGER_NAME: &str = "NT Kernel Logger"; const SYSTEM_TRACE_CONTROL_GUID: &str = "9e814aad-3204-11d2-9a82-006008a86939"; @@ -27,8 +31,6 @@ pub enum TraceError { IoError(std::io::Error), } -impl LastOsError for TraceError {} - impl From for TraceError { fn from(err: std::io::Error) -> Self { TraceError::IoError(err) @@ -45,7 +47,7 @@ type TraceResult = Result; /// Trace Properties struct /// -/// Keeps the ETW session configuration settings +/// These are some configuration settings that will be included in an [`EVENT_TRACE_PROPERTIES`](https://learn.microsoft.com/en-us/windows/win32/api/evntrace/ns-evntrace-event_trace_properties) /// /// [More info](https://docs.microsoft.com/en-us/message-analyzer/specifying-advanced-etw-session-configuration-settings#configuring-the-etw-session) #[derive(Debug, Copy, Clone, Default)] @@ -62,43 +64,34 @@ pub struct TraceProperties { pub log_file_mode: u32, } -/// Struct which holds the Trace data -/// -/// This struct will hold the main data required to handle an ETW Session +/// Data used by callbacks when the trace is running +// NOTE: this structure is accessed in an unsafe block in a separate thread (see the `trace_callback_thunk` function) +// Thus, this struct must not be mutated (outside of interior mutability and/or using Mutex and other synchronization mechanisms) when the associated trace is running. #[derive(Debug, Default)] -pub struct TraceData { - /// Represents the trace name - pub name: String, - /// Represents the [TraceProperties] - pub properties: TraceProperties, - /// Represents the current events handled +pub struct CallbackData { + /// Represents how many events have been handled so far events_handled: AtomicUsize, - /// List of Providers associated with the Trace + /// List of Providers associated with the Trace. This also owns the callback closures and their state providers: Vec, schema_locator: SchemaLocator, - // buffers_read : isize } -impl TraceData { +impl CallbackData { fn new() -> Self { - let name = format!("n4r1b-trace-{}", utils::rand_string()); - TraceData { - name, + Self { events_handled: AtomicUsize::new(0), - properties: TraceProperties::default(), providers: Vec::new(), schema_locator: SchemaLocator::new(), } } - /// How many events have been handled so far + /// How many events have been handled since this instance was created pub fn events_handled(&self) -> usize { self.events_handled.load(Ordering::Relaxed) } - // TODO: Should be void??? - fn insert_provider(&mut self, provider: provider::Provider) { - self.providers.push(provider); + pub fn provider_flags(&self) -> Etw::EVENT_TRACE_FLAG { + Etw::EVENT_TRACE_FLAG(T::enable_flags(&self.providers)) } pub(crate) fn on_event(&self, record: &EventRecord) { @@ -114,251 +107,219 @@ impl TraceData { } } -/// Base trait for a Trace -/// -/// This trait define the general methods required to control an ETW Session -pub trait TraceBaseTrait { - /// Internal function to set TraceName. See [TraceTrait::named] - fn set_trace_name(&mut self, name: &str); - /// Sets the ETW session configuration properties - /// - /// # Example - /// ``` - /// # use ferrisetw::trace::{UserTrace, TraceProperties, TraceBaseTrait}; - /// let mut props = TraceProperties::default(); - /// props.flush_timer = 60; - /// let my_trace = UserTrace::new().set_trace_properties(props); - /// ``` - fn set_trace_properties(self, props: TraceProperties) -> Self; - /// Enables a [Provider] for the Trace - /// - /// # Remarks - /// Multiple providers can be enabled for the same trace, as long as they are from the same CPU privilege - /// - /// # Example - /// ``` - /// # use ferrisetw::trace::{UserTrace, TraceBaseTrait}; - /// # use ferrisetw::provider::Provider; - /// let provider = Provider::by_guid("1EDEEE53-0AFE-4609-B846-D8C0B2075B1F") - /// .add_callback(|record, schema| { println!("{}", record.process_id()); }) - /// .build(); - /// let my_trace = UserTrace::new().enable(provider); - /// ``` - fn enable(self, provider: provider::Provider) -> Self; - /// Opens a Trace session - fn open(self) -> TraceResult - where - Self: Sized; - /// Starts a Trace session (which includes `open`ing and `process`ing the trace) - /// - /// # Note - /// This function will spawn a new thread, ETW blocks the thread listening to events, so we need - /// a new thread to which delegate this process. - fn start(self) -> TraceResult - where - Self: Sized; - /// Start processing a Trace session - /// - /// # Note - /// This function will spawn the new thread which starts listening for events. - /// - /// See [ProcessTrace](https://docs.microsoft.com/en-us/windows/win32/api/evntrace/nf-evntrace-processtrace#remarks) - fn process(self) -> TraceResult - where - Self: Sized; - /// Stops a Trace session - /// - /// # Note - /// Since a call to `start` will block thread and in case we want to execute it within a thread - /// we would -- for now -- have to move it to the context of the new thread, this function is - /// called from the [Drop] implementation. - /// - /// This function will log if it fails - fn stop(&mut self); -} +/// Trait for common methods to user and kernel traces +pub trait TraceTrait: private::PrivateTraceTrait + Sized { + // This differs between UserTrace and KernelTrace + fn trace_guid() -> GUID; -// Hyper Macro to create an impl of the BaseTrace for the Kernel and User Trace -macro_rules! impl_base_trace { - (for $($t: ty),+) => { - $(impl TraceBaseTrait for $t { - fn set_trace_name(&mut self, name: &str) { - self.data.name = name.to_string(); - } + // This must be implemented for every trace, as this getter is needed by other methods from this trait + fn trace_handle(&self) -> TraceHandle; - fn set_trace_properties(mut self, props: TraceProperties) -> Self { - self.data.properties = props; - self - } + // These utilities should be implemented for every trace + fn events_handled(&self) -> usize; - fn enable(mut self, provider: provider::Provider) -> Self { - self.data.insert_provider(provider); - self - } + // The following are default implementations, that work on both user and kernel traces - fn open(mut self) -> TraceResult { - self.data.events_handled.store(0, Ordering::Relaxed); + /// This is blocking and starts triggerring the callbacks. + /// + /// Because this call is blocking, you probably want to call this from a background thread.
+ /// See [`TraceBuilder::start`] for alternative and more convenient ways to start a trace. + fn process(&mut self) -> TraceResult<()> { + process_trace(self.trace_handle()) + .map_err(|e| e.into()) + } - // Populate self.info - self.etw.fill_info::<$t>(&self.data.name, &self.data.properties, &self.data.providers); - // Call StartTrace(..., self.info.properties) - self.etw.register_trace(&self.data)?; - // Call EnableTraceEx2 for each provider - <$t>::enable_provider(&self); - self.etw.open(&self.data)?; + /// Process a trace given its handle. + /// + /// See [`TraceBuilder::start`] for alternative and more convenient ways to start a trace. + fn process_from_handle(handle: TraceHandle) -> TraceResult<()> { + process_trace(handle) + .map_err(|e| e.into()) + } - Ok(self) - } + /// Stops the trace + /// + /// This consumes the trace, that can no longer be used afterwards. + /// The same result is achieved by dropping `Self` + fn stop(mut self) -> TraceResult<()> { + self.non_consuming_stop() + } +} - fn start(mut self) -> TraceResult { - self.data.events_handled.store(0, Ordering::Relaxed); - - if let Err(err) = self.etw.start() { - match err { - evntrace::EvntraceNativeError::InvalidHandle => { - return self.open()?.process(); - }, - _=> return Err(TraceError::EtwNativeError(err)), - }; - }; - Ok(self) - } +impl TraceTrait for UserTrace { + fn trace_handle(&self) -> TraceHandle { + self.trace_handle + } - fn stop(&mut self) { - if let Err(err) = self.etw.stop(&self.data) { - println!("Error stopping trace: {:?}", err); - } - } + fn events_handled(&self) -> usize { + self.callback_data.events_handled() + } - fn process(mut self) -> TraceResult { - self.data.events_handled.store(0, Ordering::Relaxed); - self.etw.process()?; + fn trace_guid() -> GUID { + GUID::new().unwrap_or(GUID::zeroed()) + } +} - Ok(self) - } +// TODO: Implement enable_provider function for providers that require call to TraceSetInformation with extended PERFINFO_GROUPMASK +impl TraceTrait for KernelTrace { + fn trace_handle(&self) -> TraceHandle { + self.trace_handle + } + + fn events_handled(&self) -> usize { + self.callback_data.events_handled() + } - // query_stats - // set_default_event_callback - // buffers_processed - })* + fn trace_guid() -> GUID { + if version_helper::is_win8_or_greater() { + GUID::new().unwrap_or(GUID::zeroed()) + } else { + GUID::from(SYSTEM_TRACE_CONTROL_GUID) + } } } -/// User Trace struct + + + +/// A user trace session +/// +/// To stop the session, you can drop this instance #[derive(Debug)] pub struct UserTrace { - // This is `Box`ed so that it does not move around the stack in case the `UserTrace` is moved - // This is important, because we give a pointer to it to Windows, so that it passes it back to us on callbacks - data: Box, - etw: evntrace::NativeEtw, + properties: EventTraceProperties, + control_handle: ControlHandle, + trace_handle: TraceHandle, + // CallbackData is + // * `Boxed`, so that the `UserTrace` can be moved around the stack (e.g. returned by a function) but the pointers to the `CallbackData` given to Windows ETW API stay valid + callback_data: Box, } -/// Kernel Trace struct +/// A kernel trace session +/// +/// To stop the session, you can drop this instance #[derive(Debug)] pub struct KernelTrace { - // This is `Box`ed so that it does not move around the stack in case the `UserTrace` is moved - // This is important, because we give a pointer to it to Windows, so that it passes it back to us on callbacks - data: Box, - etw: evntrace::NativeEtw, + properties: EventTraceProperties, + control_handle: ControlHandle, + trace_handle: TraceHandle, + // CallbackData is + // * `Boxed`, so that the `UserTrace` can be moved around the stack (e.g. returned by a function) but the pointers to the `CallbackData` given to Windows ETW API stay valid + callback_data: Box, } -impl_base_trace!(for UserTrace, KernelTrace); - -/// Specific trait for a Trace +/// Provides a way to crate Trace objects. /// -/// This trait defines the specific methods that differentiate from a Kernel to a User Trace -pub trait TraceTrait: TraceBaseTrait { - /// Set the trace name - /// - /// # Remarks - /// If this function is not called during the process of building the trace a random name will be generated - fn named(self, name: String) -> Self; - fn enable_provider(&self) {} - fn augmented_file_mode() -> u32 { - 0 - } - fn enable_flags(_providers: &[Provider]) -> u32 { - 0 - } - fn trace_guid() -> GUID { - GUID::new().unwrap_or(GUID::zeroed()) - } +/// These builders are created using [`UserTrace::new`] or [`KernelTrace::new`] +pub struct TraceBuilder { + name: String, + properties: TraceProperties, + callback_data: CallbackData, + trace_kind: PhantomData, } impl UserTrace { /// Create a UserTrace builder - pub fn new() -> Self { - let data = Box::new(TraceData::new()); - UserTrace { - data, - etw: evntrace::NativeEtw::new(), + pub fn new() -> TraceBuilder { + let name = format!("n4r1b-trace-{}", utils::rand_string()); + TraceBuilder { + name, + callback_data: CallbackData::new(), + properties: TraceProperties::default(), + trace_kind: PhantomData, } } + + /// Stops the trace + /// + /// This consumes the trace, that can no longer be used afterwards. + /// The same result is achieved by dropping `Self` + pub fn stop(mut self) -> TraceResult<()> { + self.non_consuming_stop() + } } impl KernelTrace { /// Create a KernelTrace builder - pub fn new() -> Self { - let data = Box::new(TraceData::new()); - - let mut kt = KernelTrace { - data, - etw: evntrace::NativeEtw::new(), + pub fn new() -> TraceBuilder { + let builder = TraceBuilder { + name: String::new(), + callback_data: CallbackData::new(), + properties: TraceProperties::default(), + trace_kind: PhantomData, }; + // Not all names are valid. Let's use the setter to check them for us + builder.named(format!("n4r1b-trace-{}", utils::rand_string())) + } - if !version_helper::is_win8_or_greater() { - kt.set_trace_name(KERNEL_LOGGER_NAME); - } + /// Stops the trace + /// + /// This consumes the trace, that can no longer be used afterwards. + /// The same result is achieved by dropping `Self` + pub fn stop(mut self) -> TraceResult<()> { + self.non_consuming_stop() + } +} + +mod private { + //! The only reason for this private module is to have a "private" trait in an otherwise publicly exported type (`TraceBuilder`) + //! + //! See + use super::*; - kt + #[derive(Debug, PartialEq, Eq)] + pub enum TraceKind { + User, + Kernel, + } + + pub trait PrivateTraceTrait { + const TRACE_KIND: TraceKind; + fn build(properties: EventTraceProperties, control_handle: ControlHandle, trace_handle: TraceHandle, callback_data: Box) -> Self; + fn augmented_file_mode() -> u32; + fn enable_flags(_providers: &[Provider]) -> u32; + // This function aims at de-deduplicating code called by `impl Drop` and `Trace::stop`. + // It is basically [`Self::stop`], without consuming self (because the `impl Drop` only has a `&mut self`, not a `self`) + fn non_consuming_stop(&mut self) -> TraceResult<()>; } } -impl TraceTrait for UserTrace { - /// See [TraceTrait::named] - fn named(mut self, name: String) -> Self { - if !name.is_empty() { - self.set_trace_name(&name); +impl private::PrivateTraceTrait for UserTrace { + const TRACE_KIND: private::TraceKind = private::TraceKind::User; + + fn build(properties: EventTraceProperties, control_handle: ControlHandle, trace_handle: TraceHandle, callback_data: Box) -> Self { + UserTrace { + properties, + control_handle, + trace_handle, + callback_data, } + } - self + fn augmented_file_mode() -> u32 { + 0 + } + fn enable_flags(_providers: &[Provider]) -> u32 { + 0 } - // TODO: Should this fail??? - // TODO: Add option to enable same provider twice with different flags - #[allow(unused_must_use)] - fn enable_provider(&self) { - for prov in &self.data.providers { - let owned_event_filter_descriptors: Vec = prov.filters() - .iter() - .filter_map(|filter| filter.to_event_filter_descriptor().ok()) // Silently ignoring invalid filters (basically, empty ones) - .collect(); - - let parameters = - EnableTraceParameters::create(prov.guid(), prov.trace_flags(), &owned_event_filter_descriptors); - - // Fixme: return error if this fails - self.etw.enable_trace( - prov.guid(), - prov.any(), - prov.all(), - prov.level(), - parameters, - ); - } + fn non_consuming_stop(&mut self) -> TraceResult<()> { + close_trace(self.trace_handle)?; + control_trace(&mut self.properties, self.control_handle, Etw::EVENT_TRACE_CONTROL_STOP)?; + Ok(()) } } -// TODO: Implement enable_provider function for providers that require call to TraceSetInformation with extended PERFINFO_GROUPMASK -impl TraceTrait for KernelTrace { - /// See [TraceTrait::named] - /// - /// # Remarks - /// On Windows Versions older than Win8 this method won't change the trace name. In those versions the trace name need to be set to "NT Kernel Logger", that's handled by the module - fn named(mut self, name: String) -> Self { - if !name.is_empty() && version_helper::is_win8_or_greater() { - self.set_trace_name(&name); +impl private::PrivateTraceTrait for KernelTrace { + const TRACE_KIND: private::TraceKind = private::TraceKind::Kernel; + + fn build(properties: EventTraceProperties, control_handle: ControlHandle, trace_handle: TraceHandle, callback_data: Box) -> Self { + KernelTrace { + properties, + control_handle, + trace_handle, + callback_data, } - self } fn augmented_file_mode() -> u32 { @@ -373,65 +334,124 @@ impl TraceTrait for KernelTrace { providers.iter().fold(0, |acc, x| acc | x.kernel_flags()) } - fn trace_guid() -> GUID { - if version_helper::is_win8_or_greater() { - GUID::new().unwrap_or(GUID::zeroed()) + fn non_consuming_stop(&mut self) -> TraceResult<()> { + close_trace(self.trace_handle)?; + control_trace(&mut self.properties, self.control_handle, Etw::EVENT_TRACE_CONTROL_STOP)?; + Ok(()) + } +} + +impl TraceBuilder { + /// Define the trace name + /// + /// For kernel traces on Windows Versions older than Win8, this method won't change the trace name. In those versions the trace name will be set to "NT Kernel Logger" + pub fn named(mut self, name: String) -> Self { + if T::TRACE_KIND == private::TraceKind::Kernel && version_helper::is_win8_or_greater() == false { + self.name = String::from(KERNEL_LOGGER_NAME); } else { - GUID::from(SYSTEM_TRACE_CONTROL_GUID) + self.name = name; + }; + + self + } + + /// Define several low-level properties of the trace at once. + /// + /// These are part of [`EVENT_TRACE_PROPERTIES`](https://learn.microsoft.com/en-us/windows/win32/api/evntrace/ns-evntrace-event_trace_properties) + pub fn set_trace_properties(mut self, props: TraceProperties) -> Self { + self.properties = props; + self + } + + /// Enable a Provider for this trace + /// + /// This will invoke the provider's callback whenever an event is available + /// + /// # Note + /// Windows API seems to support removing providers, or changing its properties when the session is processing events (see ) /// Currently, this crate only supports defining Providers and their settings when building the trace, because it is easier to ensure memory-safety this way. + /// It probably would be possible to support changing Providers when the trace is processing, but this is left as a TODO (see ) + pub fn enable(mut self, provider: Provider) -> Self { + self.callback_data.providers.push(provider); + self + } + + /// Build the `UserTrace` and start the trace session + /// + /// Internally, this calls the `StartTraceW`, `EnableTraceEx2` and `OpenTraceW`. + /// + /// To start receiving events, you'll still have to call either: + /// * Worst option: `process()` on the returned `T`. This will block the current thread until the trace is stopped.
+ /// This means you'll probably want to call this on a spawned thread, where the `T` must be moved to. This will prevent you from re-using it from the another thread.
+ /// This means you will not be able to explicitly stop the trace, because you'll no longer have a `T` to drop or to call `stop` on. The trace will stop when the program exits, or when the ETW API hits an error.
+ /// * Most powerful option: `T::process_from_handle()` with the returned [`TraceHandle`].
+ /// This will block, so this also has to be run in a spawned thread. But, as this does not "consume" the `T`, you'll be able to call `stop` on it (or to drop it) to explicitly close the trace. Stopping a trace will make the `process` function return. + /// * Easiest option: [`TraceBuilder::start_and_process()`].
+ /// This convenience function spawns a thread for you, call [`TraceBuilder::start`] on the trace, and returns immediately.
+ /// This option returns a `T`, so you can explicitly stop the trace, but there is no way to get the status code of the ProcessTrace API. + pub fn start(self) -> TraceResult<(T, TraceHandle)> { + let trace_wide_name = U16CString::from_str_truncate(self.name); + let mut trace_wide_vec = trace_wide_name.into_vec(); + trace_wide_vec.truncate(crate::native::etw_types::TRACE_NAME_MAX_CHARS); + let trace_wide_name = U16CString::from_vec_truncate(trace_wide_vec); + + let callback_data = Box::new(self.callback_data); + let flags = callback_data.provider_flags::(); + let (full_properties, control_handle) = start_trace::( + &trace_wide_name, + &self.properties, + flags)?; + + // TODO: For kernel traces, implement enable_provider function for providers that require call to TraceSetInformation with extended PERFINFO_GROUPMASK + + if T::TRACE_KIND == private::TraceKind::User { + for prov in &callback_data.providers { + enable_provider(control_handle, prov)?; + } } + + let trace_handle = open_trace(trace_wide_name, &callback_data)?; + + Ok((T::build( + full_properties, + control_handle, + trace_handle, + callback_data, + ), + trace_handle) + ) + } + + /// Convenience method that calls [`TraceBuilder::start`] then `process` + /// + /// # Notes + /// * See the documentation of [`TraceBuilder::start`] for more info + /// * `process` is called on a spawned thread, and thus this method does not give any way to retrieve the error of `process` (if any) + pub fn start_and_process(self) -> TraceResult { + let (trace, trace_handle) = self.start()?; + + std::thread::spawn(move || UserTrace::process_from_handle(trace_handle)); + + Ok(trace) } } -/// On drop the ETW session will be stopped if not stopped before -// TODO: log if it fails?? -#[allow(unused_must_use)] impl Drop for UserTrace { fn drop(&mut self) { - if self.etw.session_handle() != INVALID_TRACE_HANDLE { - self.stop(); - } + let _ignored_error_in_drop = self.non_consuming_stop(); } } -/// On drop the ETW session will be stopped if not stopped before -#[allow(unused_must_use)] impl Drop for KernelTrace { fn drop(&mut self) { - if self.etw.session_handle() != INVALID_TRACE_HANDLE { - self.stop(); - } + let _ignored_error_in_drop = self.non_consuming_stop(); } } + #[cfg(test)] mod test { use super::*; - #[test] - fn test_set_properties() { - let prop = TraceProperties { - buffer_size: 10, - min_buffer: 1, - max_buffer: 20, - flush_timer: 60, - log_file_mode: 5, - }; - let trace = UserTrace::new().set_trace_properties(prop); - - assert_eq!(trace.data.properties.buffer_size, 10); - assert_eq!(trace.data.properties.min_buffer, 1); - assert_eq!(trace.data.properties.max_buffer, 20); - assert_eq!(trace.data.properties.flush_timer, 60); - assert_eq!(trace.data.properties.log_file_mode, 5); - } - - #[test] - fn test_set_name() { - let trace = UserTrace::new().named(String::from("TestName")); - - assert_eq!(trace.data.name, "TestName"); - } - #[test] fn test_enable_multiple_providers() { let prov = Provider::by_guid("22fb2cd6-0e7b-422b-a0c7-2fad1fd0e716").build(); @@ -439,6 +459,6 @@ mod test { let trace = UserTrace::new().enable(prov).enable(prov1); - assert_eq!(trace.data.providers.len(), 2); + assert_eq!(trace.callback_data.providers.len(), 2); } } diff --git a/tests/dns.rs b/tests/dns.rs index 91e7347..c21bbbc 100644 --- a/tests/dns.rs +++ b/tests/dns.rs @@ -6,7 +6,8 @@ use std::process::Command; use ferrisetw::provider::{Provider, EventFilter}; use ferrisetw::native::etw_types::EventRecord; use ferrisetw::schema_locator::SchemaLocator; -use ferrisetw::trace::{UserTrace, TraceBaseTrait}; +use ferrisetw::trace::UserTrace; +use ferrisetw::trace::TraceTrait; use ferrisetw::parser::{Parser, TryParse}; mod utils; @@ -45,14 +46,16 @@ fn simple_user_dns_trace() { }) .build(); - let mut _dns_trace = UserTrace::new() + let dns_trace = UserTrace::new() .enable(dns_provider) - .start() + .start_and_process() .unwrap(); generate_dns_events(); passed.assert_passed(); + assert!(dns_trace.events_handled() > 0); + dns_trace.stop().unwrap(); println!("simple_user_dns_trace passed"); } @@ -77,15 +80,17 @@ fn test_event_id_filter() { }) .build(); - let mut _dns_trace = UserTrace::new() + let _trace = UserTrace::new() .enable(dns_provider) - .start() + .start_and_process() .unwrap(); generate_dns_events(); passed1.assert_passed(); passed2.assert_passed(); + // Not calling .stop() here, let's just rely on the `impl Drop` + println!("test_event_id_filter passed"); } diff --git a/tests/kernel_trace.rs b/tests/kernel_trace.rs index 668695e..af52430 100644 --- a/tests/kernel_trace.rs +++ b/tests/kernel_trace.rs @@ -5,7 +5,6 @@ use std::time::Duration; use ferrisetw::provider::{Provider, EventFilter}; use ferrisetw::native::etw_types::EventRecord; use ferrisetw::schema_locator::SchemaLocator; -use ferrisetw::trace::TraceBaseTrait; use ferrisetw::parser::{Parser, TryParse}; use ferrisetw::trace::KernelTrace; use ferrisetw::provider::kernel_providers; @@ -54,7 +53,7 @@ fn simple_kernel_trace_trace() { let mut _kernel_trace = KernelTrace::new() .enable(kernel_provider) - .start() + .start_and_process() .unwrap(); generate_image_load_events(); From 9cd993d8671bceb8e8ec154bac2f71b1f605ab19 Mon Sep 17 00:00:00 2001 From: daladim Date: Wed, 19 Oct 2022 17:10:22 +0200 Subject: [PATCH 6/7] Dropping CallbackData at the right time Wrapping it into an Arc ensures we're not dropping it when the trace is stopped, but we're waiting for the potential callbacks to terminate first This fixes "Race 2" in #45 (https://github.com/n4r1b/ferrisetw/issues/45) --- src/native/etw_types.rs | 6 ++++-- src/native/evntrace.rs | 10 +++++++--- src/trace.rs | 15 +++++++++------ 3 files changed, 20 insertions(+), 11 deletions(-) diff --git a/src/native/etw_types.rs b/src/native/etw_types.rs index deecdfc..2930971 100644 --- a/src/native/etw_types.rs +++ b/src/native/etw_types.rs @@ -12,6 +12,8 @@ use crate::trace::{CallbackData, TraceProperties, TraceTrait}; use std::ffi::c_void; use std::fmt::Formatter; use std::marker::PhantomData; +use std::sync::Arc; + use windows::core::GUID; use windows::core::PWSTR; use windows::Win32::System::Diagnostics::Etw; @@ -240,7 +242,7 @@ pub struct EventTraceLogfile<'callbackdata> { impl<'callbackdata> EventTraceLogfile<'callbackdata> { /// Create a new instance - pub fn create(callback_data: &'callbackdata Box, mut wide_logger_name: U16CString, callback: unsafe extern "system" fn(*mut Etw::EVENT_RECORD)) -> Self { + pub fn create(callback_data: &'callbackdata Box>, mut wide_logger_name: U16CString, callback: unsafe extern "system" fn(*mut Etw::EVENT_RECORD)) -> Self { let mut native = Etw::EVENT_TRACE_LOGFILEW::default(); native.LoggerName = PWSTR(wide_logger_name.as_mut_ptr()); @@ -249,7 +251,7 @@ impl<'callbackdata> EventTraceLogfile<'callbackdata> { native.Anonymous2.EventRecordCallback = Some(callback); - let not_really_mut_ptr = callback_data.as_ref() as *const CallbackData as *const c_void as *mut c_void; // That's kind-of fine because the user context is _not supposed_ to be changed by Windows APIs + let not_really_mut_ptr = callback_data.as_ref() as *const Arc as *const c_void as *mut c_void; // That's kind-of fine because the user context is _not supposed_ to be changed by Windows APIs native.Context = not_really_mut_ptr; Self { diff --git a/src/native/evntrace.rs b/src/native/evntrace.rs index 54e95cd..327ec25 100644 --- a/src/native/evntrace.rs +++ b/src/native/evntrace.rs @@ -3,6 +3,7 @@ //! This module makes sure the calls are safe memory-wise, but does not attempt to ensure they are called in the right order.
//! Thus, you should prefer using `UserTrace`s, `KernelTrace`s and `TraceBuilder`s, that will ensure these API are correctly used. use std::panic::AssertUnwindSafe; +use std::sync::Arc; use widestring::{U16CString, U16CStr}; use windows::Win32::Foundation::WIN32_ERROR; @@ -49,7 +50,7 @@ extern "system" fn trace_callback_thunk(p_record: *mut Etw::EVENT_RECORD) { }; if let Some(event_record) = record_from_ptr { - let p_user_context = event_record.user_context().cast::(); + let p_user_context = event_record.user_context().cast::>(); let user_context = unsafe { // Safety: // * the API of this create guarantees this points to a `CallbackData` already allocated and created @@ -61,7 +62,10 @@ extern "system" fn trace_callback_thunk(p_record: *mut Etw::EVENT_RECORD) { p_user_context.as_ref() }; if let Some(user_context) = user_context { - user_context.on_event(event_record); + // The UserContext is owned by the `Trace` object. When it is dropped, so will the UserContext. + // We clone it now, so that the original Arc can be safely dropped at all times, but the callback data (including the closure captured context) will still be alive until the callback ends. + let cloned_arc = Arc::clone(user_context); + cloned_arc.on_event(event_record); } } })) { @@ -135,7 +139,7 @@ where /// Subscribe to a started trace /// /// Microsoft calls this "opening" the trace (and this calls `OpenTraceW`) -pub fn open_trace(trace_name: U16CString, callback_data: &Box) -> EvntraceNativeResult { +pub fn open_trace(trace_name: U16CString, callback_data: &Box>) -> EvntraceNativeResult { let mut log_file = EventTraceLogfile::create(&callback_data, trace_name, trace_callback_thunk); let trace_handle = unsafe { diff --git a/src/trace.rs b/src/trace.rs index a04affd..e755b35 100644 --- a/src/trace.rs +++ b/src/trace.rs @@ -3,6 +3,7 @@ //! Provides both a Kernel and User trace that allows to start an ETW session use std::marker::PhantomData; use std::sync::atomic::{AtomicUsize, Ordering}; +use std::sync::Arc; use self::private::PrivateTraceTrait; @@ -191,8 +192,9 @@ pub struct UserTrace { control_handle: ControlHandle, trace_handle: TraceHandle, // CallbackData is + // * `Arc`ed, so that dropping a Trace while a callback is still running is not an issue // * `Boxed`, so that the `UserTrace` can be moved around the stack (e.g. returned by a function) but the pointers to the `CallbackData` given to Windows ETW API stay valid - callback_data: Box, + callback_data: Box>, } /// A kernel trace session @@ -204,8 +206,9 @@ pub struct KernelTrace { control_handle: ControlHandle, trace_handle: TraceHandle, // CallbackData is + // * `Arc`ed, so that dropping a Trace while a callback is still running is not an issue // * `Boxed`, so that the `UserTrace` can be moved around the stack (e.g. returned by a function) but the pointers to the `CallbackData` given to Windows ETW API stay valid - callback_data: Box, + callback_data: Box>, } /// Provides a way to crate Trace objects. @@ -275,7 +278,7 @@ mod private { pub trait PrivateTraceTrait { const TRACE_KIND: TraceKind; - fn build(properties: EventTraceProperties, control_handle: ControlHandle, trace_handle: TraceHandle, callback_data: Box) -> Self; + fn build(properties: EventTraceProperties, control_handle: ControlHandle, trace_handle: TraceHandle, callback_data: Box>) -> Self; fn augmented_file_mode() -> u32; fn enable_flags(_providers: &[Provider]) -> u32; // This function aims at de-deduplicating code called by `impl Drop` and `Trace::stop`. @@ -287,7 +290,7 @@ mod private { impl private::PrivateTraceTrait for UserTrace { const TRACE_KIND: private::TraceKind = private::TraceKind::User; - fn build(properties: EventTraceProperties, control_handle: ControlHandle, trace_handle: TraceHandle, callback_data: Box) -> Self { + fn build(properties: EventTraceProperties, control_handle: ControlHandle, trace_handle: TraceHandle, callback_data: Box>) -> Self { UserTrace { properties, control_handle, @@ -313,7 +316,7 @@ impl private::PrivateTraceTrait for UserTrace { impl private::PrivateTraceTrait for KernelTrace { const TRACE_KIND: private::TraceKind = private::TraceKind::Kernel; - fn build(properties: EventTraceProperties, control_handle: ControlHandle, trace_handle: TraceHandle, callback_data: Box) -> Self { + fn build(properties: EventTraceProperties, control_handle: ControlHandle, trace_handle: TraceHandle, callback_data: Box>) -> Self { KernelTrace { properties, control_handle, @@ -394,7 +397,7 @@ impl TraceBuilder { trace_wide_vec.truncate(crate::native::etw_types::TRACE_NAME_MAX_CHARS); let trace_wide_name = U16CString::from_vec_truncate(trace_wide_vec); - let callback_data = Box::new(self.callback_data); + let callback_data = Box::new(Arc::new(self.callback_data)); let flags = callback_data.provider_flags::(); let (full_properties, control_handle) = start_trace::( &trace_wide_name, From 76b4f254e00bf3dd0d778dc7fba95b6754a13b3f Mon Sep 17 00:00:00 2001 From: daladim Date: Fri, 21 Oct 2022 16:49:41 +0200 Subject: [PATCH 7/7] Ignoring callbacks invoked past the closing of the trace This fixes "Race 1" in #45 (https://github.com/n4r1b/ferrisetw/issues/45) --- src/native/etw_types.rs | 5 +++ src/native/evntrace.rs | 79 ++++++++++++++++++++++++++++++++++++----- src/trace.rs | 4 +-- 3 files changed, 77 insertions(+), 11 deletions(-) diff --git a/src/native/etw_types.rs b/src/native/etw_types.rs index 2930971..ade1791 100644 --- a/src/native/etw_types.rs +++ b/src/native/etw_types.rs @@ -270,6 +270,11 @@ impl<'callbackdata> EventTraceLogfile<'callbackdata> { pub(crate) unsafe fn as_mut_ptr(&mut self) -> *mut Etw::EVENT_TRACE_LOGFILEW { &mut self.native as *mut Etw::EVENT_TRACE_LOGFILEW } + + /// The current Context pointer. + pub fn context_ptr(&self) -> *const std::ffi::c_void { + self.native.Context + } } /// Newtype wrapper over an [ENABLE_TRACE_PARAMETERS] diff --git a/src/native/evntrace.rs b/src/native/evntrace.rs index 327ec25..84709ba 100644 --- a/src/native/evntrace.rs +++ b/src/native/evntrace.rs @@ -2,8 +2,13 @@ //! //! This module makes sure the calls are safe memory-wise, but does not attempt to ensure they are called in the right order.
//! Thus, you should prefer using `UserTrace`s, `KernelTrace`s and `TraceBuilder`s, that will ensure these API are correctly used. +use std::collections::HashSet; use std::panic::AssertUnwindSafe; use std::sync::Arc; +use std::sync::Mutex; +use std::ffi::c_void; + +use once_cell::sync::Lazy; use widestring::{U16CString, U16CStr}; use windows::Win32::Foundation::WIN32_ERROR; @@ -41,6 +46,49 @@ pub enum EvntraceNativeError { pub(crate) type EvntraceNativeResult = Result; +/// When a trace is closing, it is possible that every past events have not been processed yet. +/// These events will still be fed to the callback, **after** the trace has been closed +/// (see `ERROR_CTX_CLOSE_PENDING` in https://learn.microsoft.com/en-us/windows/win32/api/evntrace/nf-evntrace-closetrace#remarks) +/// Also, there is no way to tell which callback invocation is the last one. +/// +/// But, we would like to free memory used by the callbacks when we're done! +/// Since that is not possible, let's discard every callback run after we've called `CloseTrace`. +/// That's the purpose of this set. +/// +/// TODO: it _might_ be possible to know whether we've processed the last buffered event, as +/// ControlTraceW(EVENT_TRACE_CONTROL_QUERY) _might_ tell us if the buffers are empty or not. +/// In case the trace is in ERROR_CTX_CLOSE_PENDING state, we could call this after every +/// callback so that we know when to actually free memory used by the (now useless) callback. +/// Maybe also setting the BufferCallback in EVENT_TRACE_LOGFILEW may help us. +/// That's +static UNIQUE_VALID_CONTEXTS: UniqueValidContexts = UniqueValidContexts::new(); +struct UniqueValidContexts(Lazy>>); +enum ContextError{ + AlreadyExist +} + +impl UniqueValidContexts { + pub const fn new() -> Self { + Self(Lazy::new(|| Mutex::new(HashSet::new()))) + } + /// Insert if it did not exist previously + fn insert(&self, ctx_ptr: *const c_void) -> Result<(), ContextError> { + match self.0.lock().unwrap().insert(ctx_ptr as u64) { + true => Ok(()), + false => Err(ContextError::AlreadyExist), + } + } + + fn remove(&self, ctx_ptr: *const c_void) { + self.0.lock().unwrap().remove(&(ctx_ptr as u64)); + } + + pub fn is_valid(&self, ctx_ptr: *const c_void) -> bool { + self.0.lock().unwrap().contains(&(ctx_ptr as u64)) + } +} + + /// This will be called by the ETW framework whenever an ETW event is available extern "system" fn trace_callback_thunk(p_record: *mut Etw::EVENT_RECORD) { match std::panic::catch_unwind(AssertUnwindSafe(|| { @@ -50,21 +98,25 @@ extern "system" fn trace_callback_thunk(p_record: *mut Etw::EVENT_RECORD) { }; if let Some(event_record) = record_from_ptr { - let p_user_context = event_record.user_context().cast::>(); - let user_context = unsafe { + let p_user_context = event_record.user_context(); + if UNIQUE_VALID_CONTEXTS.is_valid(p_user_context) == false { + return; + } + let p_callback_data = p_user_context.cast::>(); + let callback_data = unsafe { // Safety: // * the API of this create guarantees this points to a `CallbackData` already allocated and created - // * TODO (#45): the API of this create does not yet guarantee this `CallbackData` has not been dropped + // * we've just checked using UNIQUE_VALID_CONTEXTS that this `CallbackData` has not been dropped // * the API of this crate guarantees this `CallbackData` is not mutated from another thread during the trace: // * we're the only one to change CallbackData::events_handled (and that's an atomic, so it's fine) // * the list of Providers is a constant (may change in the future with #54) // * the schema_locator only has interior mutability - p_user_context.as_ref() + p_callback_data.as_ref() }; - if let Some(user_context) = user_context { + if let Some(callback_data) = callback_data { // The UserContext is owned by the `Trace` object. When it is dropped, so will the UserContext. // We clone it now, so that the original Arc can be safely dropped at all times, but the callback data (including the closure captured context) will still be alive until the callback ends. - let cloned_arc = Arc::clone(user_context); + let cloned_arc = Arc::clone(callback_data); cloned_arc.on_event(event_record); } } @@ -140,7 +192,13 @@ where /// /// Microsoft calls this "opening" the trace (and this calls `OpenTraceW`) pub fn open_trace(trace_name: U16CString, callback_data: &Box>) -> EvntraceNativeResult { - let mut log_file = EventTraceLogfile::create(&callback_data, trace_name, trace_callback_thunk); + let mut log_file = EventTraceLogfile::create(callback_data, trace_name, trace_callback_thunk); + + if let Err(ContextError::AlreadyExist) = UNIQUE_VALID_CONTEXTS.insert(log_file.context_ptr()) { + // That's probably possible to get multiple handles to the same trace, by opening them multiple times. + // But that's left as a future TODO. Making things right and safe is difficult enough with a single opening of the trace already. + return Err(EvntraceNativeError::AlreadyExist); + } let trace_handle = unsafe { // This function modifies the data pointed to by log_file. @@ -263,10 +321,13 @@ pub fn control_trace( /// In case ETW reports there are still events in the queue that are still to trigger callbacks, this returns Ok(true).
/// If no further event callback will be invoked, this returns Ok(false)
/// On error, this returns an `Err` -pub fn close_trace(trace_handle: TraceHandle) -> EvntraceNativeResult { +pub fn close_trace(trace_handle: TraceHandle, callback_data: &Box>) -> EvntraceNativeResult { match filter_invalid_trace_handles(trace_handle) { None => Err(EvntraceNativeError::InvalidHandle), Some(handle) => { + // By contruction, only one Provider used this context in its callback. It is safe to remove it, it won't be used by anyone else. + UNIQUE_VALID_CONTEXTS.remove(callback_data.as_ref() as *const Arc as *const c_void); + let status = unsafe { Etw::CloseTrace(handle) }; @@ -288,7 +349,7 @@ pub(crate) fn query_info(class: TraceInformation, buf: &mut [u8]) -> EvntraceNat Etw::TraceQueryInformation( 0, TRACE_QUERY_INFO_CLASS(class as i32), - buf.as_mut_ptr() as *mut std::ffi::c_void, + buf.as_mut_ptr() as *mut c_void, buf.len() as u32, std::ptr::null_mut(), ) diff --git a/src/trace.rs b/src/trace.rs index e755b35..07bcc8e 100644 --- a/src/trace.rs +++ b/src/trace.rs @@ -307,7 +307,7 @@ impl private::PrivateTraceTrait for UserTrace { } fn non_consuming_stop(&mut self) -> TraceResult<()> { - close_trace(self.trace_handle)?; + close_trace(self.trace_handle, &self.callback_data)?; control_trace(&mut self.properties, self.control_handle, Etw::EVENT_TRACE_CONTROL_STOP)?; Ok(()) } @@ -338,7 +338,7 @@ impl private::PrivateTraceTrait for KernelTrace { } fn non_consuming_stop(&mut self) -> TraceResult<()> { - close_trace(self.trace_handle)?; + close_trace(self.trace_handle, &self.callback_data)?; control_trace(&mut self.properties, self.control_handle, Etw::EVENT_TRACE_CONTROL_STOP)?; Ok(()) }