diff --git a/src/native/etw_types.rs b/src/native/etw_types.rs index ade1791..572e516 100644 --- a/src/native/etw_types.rs +++ b/src/native/etw_types.rs @@ -9,7 +9,7 @@ use crate::provider::event_filter::EventFilterDescriptor; use crate::provider::TraceFlags; use crate::trace::{CallbackData, TraceProperties, TraceTrait}; -use std::ffi::c_void; +use std::ffi::{c_void, OsString}; use std::fmt::Formatter; use std::marker::PhantomData; use std::sync::Arc; @@ -20,6 +20,7 @@ use windows::Win32::System::Diagnostics::Etw; use windows::Win32::System::Diagnostics::Etw::EVENT_FILTER_DESCRIPTOR; use widestring::{U16CStr, U16CString}; + mod event_record; pub use event_record::EventRecord; @@ -225,6 +226,11 @@ impl EventTraceProperties { pub fn trace_name_array(&self) -> &[u16] { &self.wide_trace_name } + pub fn name(&self) -> OsString { + widestring::U16CStr::from_slice_truncate(&self.wide_trace_name) + .map(|ws| ws.to_os_string()) + .unwrap_or(OsString::from("")) + } } /// Newtype wrapper over an [EVENT_TRACE_LOGFILEW] diff --git a/src/trace.rs b/src/trace.rs index 07bcc8e..bfb0ac9 100644 --- a/src/trace.rs +++ b/src/trace.rs @@ -1,6 +1,7 @@ //! ETW Tracing/Session abstraction //! //! Provides both a Kernel and User trace that allows to start an ETW session +use std::ffi::OsString; use std::marker::PhantomData; use std::sync::atomic::{AtomicUsize, Ordering}; use std::sync::Arc; @@ -117,6 +118,7 @@ pub trait TraceTrait: private::PrivateTraceTrait + Sized { fn trace_handle(&self) -> TraceHandle; // These utilities should be implemented for every trace + fn trace_name(&self) -> OsString; fn events_handled(&self) -> usize; // The following are default implementations, that work on both user and kernel traces @@ -152,6 +154,10 @@ impl TraceTrait for UserTrace { self.trace_handle } + fn trace_name(&self) -> OsString { + self.properties.name() + } + fn events_handled(&self) -> usize { self.callback_data.events_handled() } @@ -167,6 +173,10 @@ impl TraceTrait for KernelTrace { self.trace_handle } + fn trace_name(&self) -> OsString { + self.properties.name() + } + fn events_handled(&self) -> usize { self.callback_data.events_handled() } diff --git a/tests/trace_lifetime.rs b/tests/trace_lifetime.rs new file mode 100644 index 0000000..ce62639 --- /dev/null +++ b/tests/trace_lifetime.rs @@ -0,0 +1,152 @@ +//! Test that traces are started and stopped as expected + +use std::process::Command; + +use ferrisetw::provider::Provider; +use ferrisetw::native::etw_types::EventRecord; +use ferrisetw::schema_locator::SchemaLocator; +use ferrisetw::trace::UserTrace; +use ferrisetw::trace::TraceTrait; + + +#[derive(Clone, Copy, Debug)] +enum HowToProcess { + StartOnly, + ProcessFromHandle, + StartAndProcess, +} + +#[test] +fn trace_lifetime() { + // List of (names to request, ASCII part to look for) + const NAME_EXAMPLES: [(&str, &str); 4] = [ + ("simple-trace-name", "simple-trace-name"), + ("998877", "998877"), + ("My Ütf-8 tråce", "tf-8 tr"), + ("My Ütf-8 tråce name, that has quite a løøøøøøøøøøøøøøøøøøøøøng name, 😎 a very λονɣ name indeed (which is even longer than TRACE_NAME_MAX_CHARS). My Ütf-8 tråce name, that has quite a løøøøøøøøøøøøøøøøøøøøøng name, 😎 a very λονɣ name indeed (which is even longer than TRACE_NAME_MAX_CHARS).", "that has quite a"), + ]; + + const HOW_TO_PROCESS: [HowToProcess; 3] = [ + HowToProcess::StartOnly, + HowToProcess::ProcessFromHandle, + HowToProcess::StartAndProcess, + ]; + + // Setup: make sure no trace is still running from an older interrupted test + for (requested_trace_name, _ascii_part_to_look_for) in NAME_EXAMPLES { + let _output = Command::new("logman") + .arg("stop") + .arg("-ets") + .arg(requested_trace_name) + .output() + .unwrap(); + } + + for provider_count in 0..2 { + for (requested_trace_name, ascii_part_to_look_for) in NAME_EXAMPLES { + for explicit_stop in [true, false] { + for how_to_process in HOW_TO_PROCESS { + test_wordpad_trace( + provider_count, + requested_trace_name, + ascii_part_to_look_for, + explicit_stop, + how_to_process); + + // Regardless of whether we explicitly stopped it, trace has been dropped and must no longer run + assert_trace_exists(&ascii_part_to_look_for, false); + } + } + } + } +} + +fn test_wordpad_trace( + provider_count: usize, + requested_trace_name: &str, + ascii_part_of_the_trace_name: &str, + explicit_stop: bool, + how_to_process: HowToProcess +) { + println!("Testing a trace with {} providers, processed as {:?}, stopped:{}, name contains {}...", provider_count, how_to_process, explicit_stop, ascii_part_of_the_trace_name); + + // Create a provider + let mut provider_builder = Provider + ::by_guid("54FFD262-99FE-4576-96E7-1ADB500370DC"); // Microsoft-Windows-Wordpad + for _i in 0..provider_count { + provider_builder = provider_builder.add_callback(|_record: &EventRecord, _locator: &SchemaLocator| {}) + } + let wordpad_provider = provider_builder.build(); + assert_trace_exists(requested_trace_name, false); + + + // Create a trace + let trace_builder = UserTrace::new() + .named(String::from(requested_trace_name)) + .enable(wordpad_provider); + + let trace = match how_to_process { + HowToProcess::StartOnly => { + let (trace, _handle) = trace_builder.start().unwrap(); + trace // the trace is running, but not processing anything + }, + HowToProcess::ProcessFromHandle => { + let (trace, handle) = trace_builder.start().unwrap(); + std::thread::spawn(move || UserTrace::process_from_handle(handle)); + trace + }, + HowToProcess::StartAndProcess => { + let trace = trace_builder.start_and_process().unwrap(); + trace + } + }; + + let actual_trace_name = trace.trace_name().to_string_lossy().to_string(); + assert!(actual_trace_name.contains(ascii_part_of_the_trace_name)); + assert_trace_exists(ascii_part_of_the_trace_name, true); + + if explicit_stop { + trace.stop().unwrap(); + assert_trace_exists(ascii_part_of_the_trace_name, false); + } +} + +/// Call `logman` and check if the expected trace is part of the output +/// +/// This is limited to the ASCII part of the trace name, because Windows really sucks when it comes to encodings from sub processes (codepage issues, etc.) +#[track_caller] +fn assert_trace_exists(ascii_part_of_the_trace_name: &str, expected: bool) -> bool { + let output_u8 = Command::new("logman") + .arg("query") + .arg("-ets") + .output() + .unwrap() + .stdout; + + let output = String::from_utf8_lossy(&output_u8); + + // let current_codepage = unsafe { + // windows::Win32::Globalization::GetACP() + // }; + // let current_encoding = codepage::to_encoding(current_codepage as u16).unwrap(); + // let (output, _, _) = current_encoding.decode(&output_u8); + + let res = output + .split('\n') + .any(|line| { + let val = line.contains(&ascii_part_of_the_trace_name); + // if val { + // println!(" = {}", line); + // } else { + // println!(" . {}", line); + // } + val + }); + + if res != expected { + println!("logman output: {}", output); + assert!(false); + } + + res +}