From f21868984847e4a30e439951bb8729e24c753823 Mon Sep 17 00:00:00 2001 From: Kyle Sabo Date: Thu, 22 Aug 2024 01:59:30 -0700 Subject: [PATCH 1/4] Build returns a Result - LayerBuilder::build() now returns a Result rather than panics - Add new error type - Update samples - Remove global_filter feature - Global filter is now a runtime option: LayerBuilder::build_global_filter --- Cargo.toml | 2 +- benches/etw.rs | 2 +- benches/user_events.rs | 2 +- examples/basic.rs | 4 +- examples/etw_event.rs | 2 +- examples/instrument.rs | 2 +- examples/span.rs | 2 +- examples/stress.rs | 2 +- src/_details.rs | 1 - src/bin/main.rs | 4 +- src/error.rs | 11 +++++ src/layer.rs | 50 ++++++++-------------- src/lib.rs | 3 +- src/native/common_schema/etw_cs.rs | 11 +++-- src/native/common_schema/user_events_cs.rs | 14 +++--- src/native/etw.rs | 11 +++-- src/native/mod.rs | 4 +- src/native/noop.rs | 4 +- src/native/user_events.rs | 14 +++--- 19 files changed, 82 insertions(+), 63 deletions(-) create mode 100644 src/error.rs diff --git a/Cargo.toml b/Cargo.toml index 87c02b8..7c5391d 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -12,7 +12,6 @@ authors = ["Kyle Sabo", "Microsoft"] crate-type = ["rlib"] [features] -global_filter = [] common_schema = [] default = ["common_schema"] @@ -24,6 +23,7 @@ chrono = {version="0.4", default-features = false, features=["std"]} once_cell = ">=1.18" dashmap = "6" paste = "1" +thiserror = "1" [target.'cfg(not(target_os = "linux"))'.dependencies] tracelogging = ">= 1.2.0" diff --git a/benches/etw.rs b/benches/etw.rs index 8d3f832..d140f7c 100644 --- a/benches/etw.rs +++ b/benches/etw.rs @@ -11,7 +11,7 @@ use tracing_subscriber::{self, prelude::*}; pub fn etw_benchmark(c: &mut Criterion) { let builder = LayerBuilder::new("etw_bench"); let provider_id = builder.get_provider_id(); - let _subscriber = tracing_subscriber::registry().with(builder.build()).init(); + let _subscriber = tracing_subscriber::registry().with(builder.build().unwrap()).init(); let etw_session = SessionBuilder::new_file_mode( "tokio-tracing-etw-bench", diff --git a/benches/user_events.rs b/benches/user_events.rs index eef6fe0..49cbb3b 100644 --- a/benches/user_events.rs +++ b/benches/user_events.rs @@ -8,7 +8,7 @@ use tracing_subscriber::{self, prelude::*}; #[cfg(target_os = "linux")] pub fn user_events_benchmark(c: &mut Criterion) { let builder = LayerBuilder::new("user_events_bench"); - let _subscriber = tracing_subscriber::registry().with(builder.build()).init(); + let _subscriber = tracing_subscriber::registry().with(builder.build().unwrap()).init(); // Disabled provider // { diff --git a/examples/basic.rs b/examples/basic.rs index ca4094b..c9d564b 100644 --- a/examples/basic.rs +++ b/examples/basic.rs @@ -4,8 +4,8 @@ use tracing_subscriber::{self, fmt::format::FmtSpan, prelude::*}; fn main() { tracing_subscriber::registry() - .with(LayerBuilder::new("ExampleProvBasic").build()) // Collects everything - .with(LayerBuilder::new_common_schema_events("ExampleProvBasic_CS").build_with_target("geneva")) + .with(LayerBuilder::new("ExampleProvBasic").build().unwrap()) // Collects everything + .with(LayerBuilder::new_common_schema_events("ExampleProvBasic_CS").build_with_target("geneva").unwrap()) .with(tracing_subscriber::fmt::layer().with_span_events(FmtSpan::ACTIVE)) .init(); diff --git a/examples/etw_event.rs b/examples/etw_event.rs index 942647f..e794457 100644 --- a/examples/etw_event.rs +++ b/examples/etw_event.rs @@ -4,7 +4,7 @@ use tracing_subscriber::{self, fmt::format::FmtSpan, prelude::*}; fn main() { tracing_subscriber::registry() - .with(LayerBuilder::new_common_schema_events("ExampleProvEtwEvent_CS").build()) + .with(LayerBuilder::new_common_schema_events("ExampleProvEtwEvent_CS").build().unwrap()) .with(tracing_subscriber::fmt::layer().with_span_events(FmtSpan::ACTIVE)) .init(); diff --git a/examples/instrument.rs b/examples/instrument.rs index c7f3e5f..1ef3b64 100644 --- a/examples/instrument.rs +++ b/examples/instrument.rs @@ -9,7 +9,7 @@ fn test_function(x: u32, y: f64) -> f64 { fn main() { tracing_subscriber::registry() - .with(LayerBuilder::new("ExampleProvInstrument").build()) // Collects everything + .with(LayerBuilder::new("ExampleProvInstrument").build().unwrap()) // Collects everything .with(tracing_subscriber::fmt::layer().with_span_events(FmtSpan::ACTIVE)) .init(); diff --git a/examples/span.rs b/examples/span.rs index f1ad399..a24e08a 100644 --- a/examples/span.rs +++ b/examples/span.rs @@ -4,7 +4,7 @@ use tracing_subscriber::{self, fmt::format::FmtSpan, prelude::*}; fn main() { tracing_subscriber::registry() - .with(LayerBuilder::new_common_schema_events("ExampleProvSpan_CS").build()) + .with(LayerBuilder::new_common_schema_events("ExampleProvSpan_CS").build().unwrap()) .with(tracing_subscriber::fmt::layer().with_span_events(FmtSpan::ACTIVE)) .init(); diff --git a/examples/stress.rs b/examples/stress.rs index d0da996..14933e2 100644 --- a/examples/stress.rs +++ b/examples/stress.rs @@ -4,7 +4,7 @@ use tracing_subscriber::{self, prelude::*}; fn main() { tracing_subscriber::registry() - .with(LayerBuilder::new("ExampleProvEtwEventStress").build()) + .with(LayerBuilder::new("ExampleProvEtwEventStress").build().unwrap()) .init(); for i in 0..500000 { diff --git a/src/_details.rs b/src/_details.rs index 0d0b295..a90b267 100644 --- a/src/_details.rs +++ b/src/_details.rs @@ -28,7 +28,6 @@ where // This struct needs to be public as it implements the tracing_subscriber::Layer::Filter trait. #[doc(hidden)] -#[cfg(any(not(feature = "global_filter"), docsrs))] pub struct EtwFilter where Mode::Provider: crate::native::EventWriter + 'static diff --git a/src/bin/main.rs b/src/bin/main.rs index 8b69bbd..1c7a76e 100644 --- a/src/bin/main.rs +++ b/src/bin/main.rs @@ -9,8 +9,8 @@ use tracing_subscriber::{self, fmt::format::FmtSpan, prelude::*}; fn main() { tracing_subscriber::registry() - .with(LayerBuilder::new("test").build()) // Collects everything - .with(LayerBuilder::new_common_schema_events("test2").build_with_target("geneva")) + .with(LayerBuilder::new("test").build().unwrap()) // Collects everything + .with(LayerBuilder::new_common_schema_events("test2").build_with_target("geneva").unwrap()) .with(tracing_subscriber::fmt::layer().with_span_events(FmtSpan::ACTIVE)) .init(); diff --git a/src/error.rs b/src/error.rs new file mode 100644 index 0000000..611bfb0 --- /dev/null +++ b/src/error.rs @@ -0,0 +1,11 @@ +use thiserror::Error; + +#[derive(Error, Debug)] +pub enum EtwError { + #[error("Provider group GUID must not be zeroes")] + EmptyProviderGroupGuid, + #[error("Provider group names must be lower case ASCII or numeric digits: {0:?}")] + InvalidProviderGroupCharacters(String), + #[error("Linux provider names must be ASCII alphanumeric: {0:?}")] + InvalidProviderNameCharacters(String) +} diff --git a/src/layer.rs b/src/layer.rs index 8d56522..cd7ce87 100644 --- a/src/layer.rs +++ b/src/layer.rs @@ -12,11 +12,9 @@ use tracing_subscriber::filter::{combinator::And, FilterExt, Filtered, Targets}; use tracing_subscriber::layer::Filter; use tracing_subscriber::{registry::LookupSpan, Layer}; -#[cfg(any(not(feature = "global_filter"), docsrs))] -use crate::_details::EtwFilter; -use crate::_details::EtwLayer; +use crate::_details::{EtwFilter, EtwLayer}; use crate::native::{EventWriter, GuidWrapper, ProviderTypes}; -use crate::native; +use crate::{error::EtwError, native}; use crate::values::*; use crate::statics::*; @@ -128,12 +126,7 @@ where self } - fn validate_config(&self) { - match &self.provider_group { - None => (), - Some(value) => Mode::assert_valid(value) - } - + fn validate_config(&self) -> Result<(), EtwError> { #[cfg(target_os = "linux")] if self .provider_name @@ -141,11 +134,15 @@ where { // The perf command is very particular about the provider names it accepts. // The Linux kernel itself cares less, and other event consumers should also presumably not need this check. - //panic!("Linux provider names must be ASCII alphanumeric"); + return Err(EtwError::InvalidProviderNameCharacters(self.provider_name.clone())); + } + + match &self.provider_group { + None => Ok(()), + Some(value) => Mode::is_valid(value) } } - #[cfg(any(not(feature = "global_filter"), docsrs))] fn build_target_filter(&self, target: &'static str) -> Targets { let mut targets = Targets::new().with_target(&self.provider_name, LevelFilter::TRACE); @@ -181,7 +178,6 @@ where } } - #[cfg(not(feature = "global_filter"))] fn build_filter(&self, provider: Pin>) -> EtwFilter where S: Subscriber + for<'a> LookupSpan<'a>, @@ -195,50 +191,44 @@ where } } - #[cfg_attr(docsrs, doc(cfg(feature = "global_filter")))] - #[cfg(any(feature = "global_filter", docsrs))] - pub fn build(self) -> EtwLayer + pub fn build_global_filter(self) -> Result, EtwError> where S: Subscriber + for<'a> LookupSpan<'a>, Mode::Provider: EventWriter + 'static, { - self.validate_config(); + self.validate_config()?; - self.build_layer() + Ok(self.build_layer()) } #[allow(clippy::type_complexity)] - #[cfg_attr(docsrs, doc(cfg(not(feature = "global_filter"))))] - #[cfg(any(not(feature = "global_filter"), docsrs))] - pub fn build(self) -> Filtered, EtwFilter, S> + pub fn build(self) -> Result, EtwFilter, S>, EtwError> where S: Subscriber + for<'a> LookupSpan<'a>, Mode::Provider: EventWriter + 'static, { - self.validate_config(); + self.validate_config()?; let layer = self.build_layer(); let filter = self.build_filter(layer.provider.clone()); - layer.with_filter(filter) + Ok(layer.with_filter(filter)) } /// Constructs the configured layer with a target [tracing_subscriber::filter] applied. /// This can be used to target specific events to specific layers, and in effect allow /// specific events to be logged only from specific ETW/user_event providers. #[allow(clippy::type_complexity)] - #[cfg_attr(docsrs, doc(cfg(not(feature = "global_filter"))))] - #[cfg(any(not(feature = "global_filter"), docsrs))] pub fn build_with_target( self, target: &'static str, - ) -> Filtered, And, Targets, S>, S> + ) -> Result, And, Targets, S>, S>, EtwError> where S: Subscriber + for<'a> LookupSpan<'a>, Mode::Provider: EventWriter + 'static, { - self.validate_config(); + self.validate_config()?; let layer = self.build_layer(); @@ -246,11 +236,10 @@ where let targets = self.build_target_filter(target); - layer.with_filter(filter.and(targets)) + Ok(layer.with_filter(filter.and(targets))) } } -#[cfg(any(not(feature = "global_filter"), docsrs))] impl Filter for EtwFilter where S: Subscriber + for<'a> LookupSpan<'a>, @@ -335,7 +324,6 @@ where // Late init when the layer is attached to a subscriber } - #[cfg(any(feature = "global_filter", docsrs))] fn register_callsite( &self, metadata: &'static tracing::Metadata<'static>, @@ -360,7 +348,6 @@ where } } - #[cfg(any(feature = "global_filter", docsrs))] fn enabled( &self, metadata: &tracing::Metadata<'_>, @@ -376,7 +363,6 @@ where self.provider.enabled(metadata.level(), keyword) } - #[cfg(any(feature = "global_filter", docsrs))] fn event_enabled( &self, event: &tracing::Event<'_>, diff --git a/src/lib.rs b/src/lib.rs index 78814da..c385acb 100644 --- a/src/lib.rs +++ b/src/lib.rs @@ -48,7 +48,7 @@ //! use tracing_subscriber::{self, prelude::*}; //! //! tracing_subscriber::registry() -//! .with(tracing_etw::LayerBuilder::new("SampleProviderName").build()) +//! .with(tracing_etw::LayerBuilder::new("SampleProviderName").build().unwrap()) //! .init(); //! //! event!(Level::INFO, fieldB = b'x', fieldA = 7, "Event Message!"); @@ -85,6 +85,7 @@ mod statics; // Module holding internal details that need to be public but should not be directly used by consumers of the crate. #[doc(hidden)] pub mod _details; +pub mod error; pub use layer::LayerBuilder; diff --git a/src/native/common_schema/etw_cs.rs b/src/native/common_schema/etw_cs.rs index b728eb3..3802ae5 100644 --- a/src/native/common_schema/etw_cs.rs +++ b/src/native/common_schema/etw_cs.rs @@ -1,4 +1,4 @@ -use crate::values::*; +use crate::{error::EtwError, values::*}; use std::{ cell::RefCell, io::{Cursor, Write}, @@ -88,8 +88,13 @@ impl crate::native::ProviderTypes for CommonSchemaProvider { true } - fn assert_valid(value: &Self::ProviderGroupType) { - assert_ne!(value, &tracelogging_dynamic::Guid::zero(), "Provider group GUID must not be zeroes"); + fn is_valid(value: &Self::ProviderGroupType) -> Result<(), EtwError> { + if value == &crate::native::native_guid::zero() { + Err(EtwError::EmptyProviderGroupGuid) + } + else { + Ok(()) + } } } diff --git a/src/native/common_schema/user_events_cs.rs b/src/native/common_schema/user_events_cs.rs index 8e750dc..27c31cf 100644 --- a/src/native/common_schema/user_events_cs.rs +++ b/src/native/common_schema/user_events_cs.rs @@ -1,4 +1,5 @@ use crate::values::*; +use crate::error::EtwError; use eventheader::*; use eventheader_dynamic::EventBuilder; use std::{ @@ -57,11 +58,14 @@ impl crate::native::ProviderTypes for CommonSchemaProvider { false } - fn assert_valid(value: &Self::ProviderGroupType) { - assert!( - eventheader_dynamic::ProviderOptions::is_valid_option_value(value), - "Provider group names must be lower case ASCII or numeric digits" - ); + fn is_valid(value: &Self::ProviderGroupType) -> Result<(), EtwError> { + if !eventheader_dynamic::ProviderOptions::is_valid_option_value(value) { + Err(EtwError::InvalidProviderGroupCharacters(value.clone().into())) + } + else + { + Ok(()) + } } fn get_provider_group(value: &Self::ProviderGroupType) -> impl Into { diff --git a/src/native/etw.rs b/src/native/etw.rs index 55c410a..b810235 100644 --- a/src/native/etw.rs +++ b/src/native/etw.rs @@ -1,4 +1,4 @@ -use crate::values::*; +use crate::{error::EtwError, values::*}; use crate::statics::GLOBAL_ACTIVITY_SEED; use chrono::{Datelike, Timelike}; use std::{cell::RefCell, ops::DerefMut, pin::Pin, sync::Arc, time::SystemTime}; @@ -98,8 +98,13 @@ impl crate::native::ProviderTypes for Provider { true } - fn assert_valid(value: &Self::ProviderGroupType) { - assert_ne!(value, &crate::native::native_guid::zero(), "Provider group GUID must not be zeroes"); + fn is_valid(value: &Self::ProviderGroupType) -> Result<(), EtwError> { + if value == &crate::native::native_guid::zero() { + Err(EtwError::EmptyProviderGroupGuid) + } + else { + Ok(()) + } } } diff --git a/src/native/mod.rs b/src/native/mod.rs index e36a239..1d9cf21 100644 --- a/src/native/mod.rs +++ b/src/native/mod.rs @@ -35,6 +35,8 @@ pub(crate) use tracelogging_dynamic::Guid as native_guid; #[cfg(target_os = "linux")] pub(crate) use eventheader::Guid as native_guid; +use crate::error::EtwError; + #[doc(hidden)] #[derive(Copy, Clone)] pub struct GuidWrapper(u128); @@ -92,7 +94,7 @@ pub trait ProviderTypes { fn supports_enable_callback() -> bool; - fn assert_valid(value: &Self::ProviderGroupType); + fn is_valid(value: &Self::ProviderGroupType) -> Result<(), EtwError>; // The compiler can't see through a 'type' within a trait to tell // that it trivially matches a constraint unless we lower the constraint diff --git a/src/native/noop.rs b/src/native/noop.rs index 736927a..d257f4d 100644 --- a/src/native/noop.rs +++ b/src/native/noop.rs @@ -29,7 +29,9 @@ impl crate::native::ProviderTypes for Provider { false } - fn assert_valid(_: &Self::ProviderGroupType) {} + fn is_valid(value: &Self::ProviderGroupType) -> Result<(), EtwError> { + Ok(()) + } } impl crate::native::EventWriter for Provider { diff --git a/src/native/user_events.rs b/src/native/user_events.rs index fabee32..6f70f50 100644 --- a/src/native/user_events.rs +++ b/src/native/user_events.rs @@ -1,5 +1,6 @@ use crate::values::*; use crate::statics::GLOBAL_ACTIVITY_SEED; +use crate::error::EtwError; use eventheader::*; use eventheader_dynamic::EventBuilder; use std::{cell::RefCell, ops::DerefMut, pin::Pin, sync::Arc, time::SystemTime}; @@ -64,11 +65,14 @@ impl crate::native::ProviderTypes for Provider { false } - fn assert_valid(value: &Self::ProviderGroupType) { - assert!( - eventheader_dynamic::ProviderOptions::is_valid_option_value(value), - "Provider group names must be lower case ASCII or numeric digits" - ); + fn is_valid(value: &Self::ProviderGroupType) -> Result<(), EtwError> { + if !eventheader_dynamic::ProviderOptions::is_valid_option_value(value) { + Err(EtwError::InvalidProviderGroupCharacters(value.clone().into())) + } + else + { + Ok(()) + } } fn get_provider_group(value: &Self::ProviderGroupType) -> impl Into { From 6bd84d001f23f4c720da35c9a064190b59514ce3 Mon Sep 17 00:00:00 2001 From: Kyle Sabo Date: Fri, 23 Aug 2024 00:44:16 -0700 Subject: [PATCH 2/4] pr feedback --- src/error.rs | 6 ++++-- src/layer.rs | 25 ++++++++++++++++------ src/native/common_schema/user_events_cs.rs | 2 +- src/native/mod.rs | 2 +- src/native/user_events.rs | 2 +- 5 files changed, 25 insertions(+), 12 deletions(-) diff --git a/src/error.rs b/src/error.rs index 611bfb0..fb46e1e 100644 --- a/src/error.rs +++ b/src/error.rs @@ -2,10 +2,12 @@ use thiserror::Error; #[derive(Error, Debug)] pub enum EtwError { - #[error("Provider group GUID must not be zeroes")] + #[error("Provider group GUID must not be zeros")] EmptyProviderGroupGuid, #[error("Provider group names must be lower case ASCII or numeric digits: {0:?}")] InvalidProviderGroupCharacters(String), #[error("Linux provider names must be ASCII alphanumeric: {0:?}")] - InvalidProviderNameCharacters(String) + InvalidProviderNameCharacters(String), + #[error("Linux provider name and provider group must less than 234 characters combined. Current length: {0:?}")] + TooManyCharacters(usize) } diff --git a/src/layer.rs b/src/layer.rs index cd7ce87..ea2ac72 100644 --- a/src/layer.rs +++ b/src/layer.rs @@ -128,13 +128,24 @@ where fn validate_config(&self) -> Result<(), EtwError> { #[cfg(target_os = "linux")] - if self - .provider_name - .contains(|f: char| !f.is_ascii_alphanumeric()) { - // The perf command is very particular about the provider names it accepts. - // The Linux kernel itself cares less, and other event consumers should also presumably not need this check. - return Err(EtwError::InvalidProviderNameCharacters(self.provider_name.clone())); + if self + .provider_name + .contains(|f: char| !f.is_ascii_alphanumeric() && f != '_') + { + // The perf command is very particular about the provider names it accepts. + // The Linux kernel itself cares less, and other event consumers should also presumably not need this check. + return Err(EtwError::InvalidProviderNameCharacters(self.provider_name.clone())); + } + + let group_name_len = match &self.provider_group { + None => 0, + Some(ref name) => Mode::get_provider_group(&name).as_ref().len() + }; + + if self.provider_name.len() + group_name_len >= 234 { + return Err(EtwError::TooManyCharacters(self.provider_name.len() + group_name_len)); + } } match &self.provider_group { @@ -150,7 +161,7 @@ where match self.provider_group { None => {} Some(ref name) => { - targets = targets.with_target(Mode::get_provider_group(name), LevelFilter::TRACE); + targets = targets.with_target(Mode::get_provider_group(name).as_ref(), LevelFilter::TRACE); } } diff --git a/src/native/common_schema/user_events_cs.rs b/src/native/common_schema/user_events_cs.rs index 27c31cf..b6f9e87 100644 --- a/src/native/common_schema/user_events_cs.rs +++ b/src/native/common_schema/user_events_cs.rs @@ -68,7 +68,7 @@ impl crate::native::ProviderTypes for CommonSchemaProvider { } } - fn get_provider_group(value: &Self::ProviderGroupType) -> impl Into { + fn get_provider_group(value: &Self::ProviderGroupType) -> impl AsRef { value.clone() } } diff --git a/src/native/mod.rs b/src/native/mod.rs index 1d9cf21..6b81ece 100644 --- a/src/native/mod.rs +++ b/src/native/mod.rs @@ -100,7 +100,7 @@ pub trait ProviderTypes { // that it trivially matches a constraint unless we lower the constraint // checking into the impl, done here through constraint on the return type. #[cfg(target_os = "linux")] - fn get_provider_group(value: &Self::ProviderGroupType) -> impl Into; + fn get_provider_group(value: &Self::ProviderGroupType) -> impl AsRef; } #[doc(hidden)] diff --git a/src/native/user_events.rs b/src/native/user_events.rs index 6f70f50..bc98b70 100644 --- a/src/native/user_events.rs +++ b/src/native/user_events.rs @@ -75,7 +75,7 @@ impl crate::native::ProviderTypes for Provider { } } - fn get_provider_group(value: &Self::ProviderGroupType) -> impl Into { + fn get_provider_group(value: &Self::ProviderGroupType) -> impl AsRef { value.clone() } } From e75ae5e3abe79f8b7f883617aae2a4671ef03210 Mon Sep 17 00:00:00 2001 From: Kyle Sabo Date: Fri, 23 Aug 2024 22:15:27 -0700 Subject: [PATCH 3/4] Restore global_filter feature Split layer.rs into smaller files Make EtwLayer and EtwFilter more common --- Cargo.toml | 1 + src/_details.rs | 27 +- src/layer.rs | 614 ------------------------------------------- src/layer/filter.rs | 53 ++++ src/layer/layer.rs | 297 +++++++++++++++++++++ src/layer/mod.rs | 71 +++++ src/layer_builder.rs | 259 ++++++++++++++++++ src/lib.rs | 6 +- 8 files changed, 686 insertions(+), 642 deletions(-) delete mode 100644 src/layer.rs create mode 100644 src/layer/filter.rs create mode 100644 src/layer/layer.rs create mode 100644 src/layer/mod.rs create mode 100644 src/layer_builder.rs diff --git a/Cargo.toml b/Cargo.toml index 7c5391d..c694e67 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -12,6 +12,7 @@ authors = ["Kyle Sabo", "Microsoft"] crate-type = ["rlib"] [features] +global_filter = [] common_schema = [] default = ["common_schema"] diff --git a/src/_details.rs b/src/_details.rs index a90b267..87b0dfa 100644 --- a/src/_details.rs +++ b/src/_details.rs @@ -1,11 +1,9 @@ -// Module for internal structs that need to be publically accessible, +// Module for internal structs that need to be publicly accessible, // but should not be directly used by consumers of the crate. // // Implementations for these structs are contained in other files. -use std::{marker::PhantomData, pin::Pin, sync::Arc}; -use crate::native::ProviderTypes; // Public with public fields because the `etw_event!` macro needs to create it at invocation site. #[doc(hidden)] @@ -14,26 +12,3 @@ pub struct EventMetadata { pub identity: tracing::callsite::Identifier, pub event_tag: u32, } - -// This struct needs to be public as it implements the tracing_subscriber::Layer trait. -#[doc(hidden)] -pub struct EtwLayer -where - Mode::Provider: crate::native::EventWriter + 'static -{ - pub(crate) provider: Pin>, - pub(crate) default_keyword: u64, - pub(crate) _p: PhantomData, -} - -// This struct needs to be public as it implements the tracing_subscriber::Layer::Filter trait. -#[doc(hidden)] -pub struct EtwFilter -where - Mode::Provider: crate::native::EventWriter + 'static -{ - pub(crate) provider: Pin>, - pub(crate) default_keyword: u64, - pub(crate) _p: PhantomData, - pub(crate) _m: PhantomData, -} diff --git a/src/layer.rs b/src/layer.rs deleted file mode 100644 index ea2ac72..0000000 --- a/src/layer.rs +++ /dev/null @@ -1,614 +0,0 @@ -use std::marker::PhantomData; -use std::time::SystemTime; -#[allow(unused_imports)] -use std::{pin::Pin, sync::Arc}; - -#[allow(unused_imports)] // Many imports are used exclusively by feature-gated code -use tracing::metadata::LevelFilter; -use tracing::{span, Subscriber}; -#[allow(unused_imports)] -use tracing_subscriber::filter::{combinator::And, FilterExt, Filtered, Targets}; -#[allow(unused_imports)] -use tracing_subscriber::layer::Filter; -use tracing_subscriber::{registry::LookupSpan, Layer}; - -use crate::_details::{EtwFilter, EtwLayer}; -use crate::native::{EventWriter, GuidWrapper, ProviderTypes}; -use crate::{error::EtwError, native}; -use crate::values::*; -use crate::statics::*; - -/// Builds a [tracing_subscriber::Layer] that will logs events from a single -/// ETW or user_events provider. Use [LayerBuilder::new] to construct a new -/// builder for the given provider name. Use the `with_*` methods to set -/// additional properties for the provider, such as the keyword to use -/// for events (default: 1) or a specific provider GUID (default: a hash of -/// the provider name). -/// -/// Use [LayerBuilder::new_common_schema_events] to create a layer that -/// will log events in the Common Schema 4.0 mapping. Only use this if -/// you know that you need events in this format. -/// -/// Multiple `tracing_etw` layers can be created at the same time, -/// with different provider names/IDs, keywords, or output formats. -/// (Target filters)[tracing_subscriber::filter] can then be used to direct -/// specific events to specific layers. -pub struct LayerBuilder -where - Mode: ProviderTypes -{ - provider_name: String, - provider_id: GuidWrapper, - provider_group: Option, - default_keyword: u64, - _m: PhantomData, -} - -impl LayerBuilder { - #[allow(clippy::new_ret_no_self)] - pub fn new(name: &str) -> LayerBuilder { - LayerBuilder:: { - provider_name: name.to_owned(), - provider_id: GuidWrapper::from_name(name), - provider_group: None, - default_keyword: 1, - _m: PhantomData, - } - } -} - -impl LayerBuilder { - /// For advanced scenarios. - /// Emit events that follow the Common Schema 4.0 mapping. - /// Recommended only for compatibility with specialized event consumers. - /// Most ETW consumers will not benefit from events in this schema, and - /// may perform worse. Common Schema events are much slower to generate - /// and should not be enabled unless absolutely necessary. - #[cfg(any(feature = "common_schema", docsrs))] - pub fn new_common_schema_events( - name: &str, - ) -> LayerBuilder { - LayerBuilder:: { - provider_name: name.to_owned(), - provider_id: GuidWrapper::from_name(name), - provider_group: None, - default_keyword: 1, - _m: PhantomData, - } - } -} - -impl LayerBuilder -where - Mode: ProviderTypes + 'static, -{ - /// For advanced scenarios. - /// Assign a provider ID to the ETW provider rather than use - /// one generated from the provider name. - pub fn with_provider_id(mut self, guid: &G) -> Self - where - for<'a> &'a G: Into - { - self.provider_id = guid.into(); - self - } - - /// Get the current provider ID that will be used for the ETW provider. - /// This is a convenience function to help with tools that do not implement - /// the standard provider name to ID algorithm. - pub fn get_provider_id(&self) -> GuidWrapper { - self.provider_id.clone() - } - - - /// Set the keyword used for events that do not explicitly set a keyword. - /// - /// Events logged with the [crate::etw_event!] macro specify a keyword for the event. - /// Events and spans logged with the [tracing::event!], [tracing::span!], - /// or other similar `tracing` macros will use the default keyword. - /// - /// If this method is not called, the default keyword will be `1`. - /// - /// Keyword value `0` is special in ETW (but not user_events), and should - /// not be used. - pub fn with_default_keyword(mut self, kw: u64) -> Self { - self.default_keyword = kw; - self - } - - /// For advanced scenarios. - /// Set the provider group to join this provider to. - pub fn with_provider_group(mut self, group_id: &G) -> Self - where - for <'a> &'a G: Into, - { - self.provider_group = Some(group_id.into()); - self - } - - fn validate_config(&self) -> Result<(), EtwError> { - #[cfg(target_os = "linux")] - { - if self - .provider_name - .contains(|f: char| !f.is_ascii_alphanumeric() && f != '_') - { - // The perf command is very particular about the provider names it accepts. - // The Linux kernel itself cares less, and other event consumers should also presumably not need this check. - return Err(EtwError::InvalidProviderNameCharacters(self.provider_name.clone())); - } - - let group_name_len = match &self.provider_group { - None => 0, - Some(ref name) => Mode::get_provider_group(&name).as_ref().len() - }; - - if self.provider_name.len() + group_name_len >= 234 { - return Err(EtwError::TooManyCharacters(self.provider_name.len() + group_name_len)); - } - } - - match &self.provider_group { - None => Ok(()), - Some(value) => Mode::is_valid(value) - } - } - - fn build_target_filter(&self, target: &'static str) -> Targets { - let mut targets = Targets::new().with_target(&self.provider_name, LevelFilter::TRACE); - - #[cfg(target_os = "linux")] - match self.provider_group { - None => {} - Some(ref name) => { - targets = targets.with_target(Mode::get_provider_group(name).as_ref(), LevelFilter::TRACE); - } - } - - if !target.is_empty() { - targets = targets.with_target(target, LevelFilter::TRACE) - } - - targets - } - - fn build_layer(&self) -> EtwLayer - where - S: Subscriber + for<'a> LookupSpan<'a>, - Mode::Provider: EventWriter + 'static, - { - EtwLayer:: { - provider: Mode::Provider::new( - &self.provider_name, - &self.provider_id, - &self.provider_group, - self.default_keyword, - ), - default_keyword: self.default_keyword, - _p: PhantomData, - } - } - - fn build_filter(&self, provider: Pin>) -> EtwFilter - where - S: Subscriber + for<'a> LookupSpan<'a>, - Mode::Provider: EventWriter + 'static, - { - EtwFilter:: { - provider, - default_keyword: self.default_keyword, - _p: PhantomData, - _m: PhantomData - } - } - - pub fn build_global_filter(self) -> Result, EtwError> - where - S: Subscriber + for<'a> LookupSpan<'a>, - Mode::Provider: EventWriter + 'static, - { - self.validate_config()?; - - Ok(self.build_layer()) - } - - #[allow(clippy::type_complexity)] - pub fn build(self) -> Result, EtwFilter, S>, EtwError> - where - S: Subscriber + for<'a> LookupSpan<'a>, - Mode::Provider: EventWriter + 'static, - { - self.validate_config()?; - - let layer = self.build_layer(); - - let filter = self.build_filter(layer.provider.clone()); - - Ok(layer.with_filter(filter)) - } - - /// Constructs the configured layer with a target [tracing_subscriber::filter] applied. - /// This can be used to target specific events to specific layers, and in effect allow - /// specific events to be logged only from specific ETW/user_event providers. - #[allow(clippy::type_complexity)] - pub fn build_with_target( - self, - target: &'static str, - ) -> Result, And, Targets, S>, S>, EtwError> - where - S: Subscriber + for<'a> LookupSpan<'a>, - Mode::Provider: EventWriter + 'static, - { - self.validate_config()?; - - let layer = self.build_layer(); - - let filter = self.build_filter(layer.provider.clone()); - - let targets = self.build_target_filter(target); - - Ok(layer.with_filter(filter.and(targets))) - } -} - -impl Filter for EtwFilter -where - S: Subscriber + for<'a> LookupSpan<'a>, - Mode: ProviderTypes + 'static, - Mode::Provider: EventWriter + 'static, -{ - fn callsite_enabled( - &self, - metadata: &'static tracing::Metadata<'static>, - ) -> tracing::subscriber::Interest { - let etw_meta = EVENT_METADATA.get(&metadata.callsite()); - let keyword = if let Some(meta) = etw_meta { - meta.kw - } else { - self.default_keyword - }; - - if Mode::supports_enable_callback() { - if self.provider.enabled(metadata.level(), keyword) { - tracing::subscriber::Interest::always() - } else { - tracing::subscriber::Interest::never() - } - } else { - // Returning "sometimes" means the enabled function will be called every time an event or span is created from the callsite. - // This will let us perform a global "is enabled" check each time. - tracing::subscriber::Interest::sometimes() - } - } - - fn enabled( - &self, - metadata: &tracing::Metadata<'_>, - _cx: &tracing_subscriber::layer::Context<'_, S>, - ) -> bool { - let etw_meta = EVENT_METADATA.get(&metadata.callsite()); - let keyword = if let Some(meta) = etw_meta { - meta.kw - } else { - self.default_keyword - }; - - self.provider - .enabled(metadata.level(), keyword) - } - - fn event_enabled( - &self, - event: &tracing::Event<'_>, - _cx: &tracing_subscriber::layer::Context<'_, S>, - ) -> bool { - let etw_meta = EVENT_METADATA.get(&event.metadata().callsite()); - let keyword = if let Some(meta) = etw_meta { - meta.kw - } else { - self.default_keyword - }; - - self.provider - .enabled(event.metadata().level(), keyword) - } -} - -struct SpanData { - fields: Box<[FieldValueIndex]>, - activity_id: [u8; 16], // // if set, byte 0 is 1 and 64-bit span ID in the lower 8 bytes - related_activity_id: [u8; 16], // if set, byte 0 is 1 and 64-bit span ID in the lower 8 bytes - start_time: SystemTime, -} - -impl Layer for EtwLayer -where - S: Subscriber + for<'a> LookupSpan<'a>, - Mode: ProviderTypes + 'static, - Mode::Provider: EventWriter + 'static, -{ - fn on_register_dispatch(&self, _collector: &tracing::Dispatch) { - // Late init when the layer is installed as a subscriber - } - - fn on_layer(&mut self, _subscriber: &mut S) { - // Late init when the layer is attached to a subscriber - } - - fn register_callsite( - &self, - metadata: &'static tracing::Metadata<'static>, - ) -> tracing::subscriber::Interest { - let etw_meta = EVENT_METADATA.get(&metadata.callsite()); - let keyword = if let Some(meta) = etw_meta { - meta.kw - } else { - self.default_keyword - }; - - if Mode::supports_enable_callback() { - if self.provider.enabled(metadata.level(), keyword) { - tracing::subscriber::Interest::always() - } else { - tracing::subscriber::Interest::never() - } - } else { - // Returning "sometimes" means the enabled function will be called every time an event or span is created from the callsite. - // This will let us perform a global "is enabled" check each time. - tracing::subscriber::Interest::sometimes() - } - } - - fn enabled( - &self, - metadata: &tracing::Metadata<'_>, - _ctx: tracing_subscriber::layer::Context<'_, S>, - ) -> bool { - let etw_meta = EVENT_METADATA.get(&metadata.callsite()); - let keyword = if let Some(meta) = etw_meta { - meta.kw - } else { - self.default_keyword - }; - - self.provider.enabled(metadata.level(), keyword) - } - - fn event_enabled( - &self, - event: &tracing::Event<'_>, - _ctx: tracing_subscriber::layer::Context<'_, S>, - ) -> bool { - let etw_meta = EVENT_METADATA.get(&event.metadata().callsite()); - let keyword = if let Some(meta) = etw_meta { - meta.kw - } else { - self.default_keyword - }; - - self.provider - .enabled(event.metadata().level(), keyword) - } - - fn on_event(&self, event: &tracing::Event<'_>, ctx: tracing_subscriber::layer::Context<'_, S>) { - let timestamp = std::time::SystemTime::now(); - - let current_span = ctx - .event_span(event) - .map(|evt| evt.id()) - .map_or(0, |id| (id.into_u64())); - let parent_span = ctx - .event_span(event) - .map_or(0, |evt| evt.parent().map_or(0, |p| p.id().into_u64())); - - let etw_meta = EVENT_METADATA.get(&event.metadata().callsite()); - let (name, keyword, tag) = if let Some(meta) = etw_meta { - (event.metadata().name(), meta.kw, meta.event_tag) - } else { - (event.metadata().name(), self.default_keyword, 0) - }; - - self.provider.as_ref().write_record( - timestamp, - current_span, - parent_span, - name, - event.metadata().level(), - keyword, - tag, - event, - ); - } - - fn on_new_span( - &self, - attrs: &span::Attributes<'_>, - id: &span::Id, - ctx: tracing_subscriber::layer::Context<'_, S>, - ) { - let span = if let Some(span) = ctx.span(id) { - span - } else { - return; - }; - - if span.extensions().get::().is_some() { - return; - } - - let metadata = span.metadata(); - - let parent_span_id = if attrs.is_contextual() { - attrs.parent().map_or(0, |id| id.into_u64()) - } else { - 0 - }; - - let n = metadata.fields().len(); - - let mut data = { - let mut v: Vec = Vec::with_capacity(n); - v.resize_with(n, Default::default); - - let mut i = 0; - for field in metadata.fields().iter() { - v[i].field = field.name(); - v[i].value = ValueTypes::None; - v[i].sort_index = i as u8; - i += 1; - } - - let mut indexes: [u8; 32] = [ - 0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16, 17, 18, 19, 20, 21, 22, - 23, 24, 25, 26, 27, 28, 29, 30, 31, - ]; - - indexes[0..n].sort_by_key(|idx| v[v[*idx as usize].sort_index as usize].field); - - i = 0; - for f in &mut v { - f.sort_index = indexes[i]; - i += 1; - } - - SpanData { - fields: v.into_boxed_slice(), - activity_id: *GLOBAL_ACTIVITY_SEED, - related_activity_id: *GLOBAL_ACTIVITY_SEED, - start_time: SystemTime::UNIX_EPOCH, - } - }; - - let (_, half) = data.activity_id.split_at_mut(8); - half.copy_from_slice(&id.into_u64().to_le_bytes()); - - data.activity_id[0] = 1; - data.related_activity_id[0] = if parent_span_id != 0 { - let (_, half) = data.related_activity_id.split_at_mut(8); - half.copy_from_slice(&parent_span_id.to_le_bytes()); - 1 - } else { - 0 - }; - - attrs.values().record(&mut ValueVisitor { - fields: &mut data.fields, - }); - - // This will unfortunately box data. It would be ideal if we could avoid this second heap allocation - // by packing everything into a single alloc. - span.extensions_mut().replace(data); - } - - fn on_enter(&self, id: &span::Id, ctx: tracing_subscriber::layer::Context<'_, S>) { - // A span was started - let timestamp = std::time::SystemTime::now(); - - let span = if let Some(span) = ctx.span(id) { - span - } else { - return; - }; - - let metadata = span.metadata(); - - let mut extensions = span.extensions_mut(); - let data = if let Some(data) = extensions.get_mut::() { - data - } else { - // We got a span that was entered without being new'ed? - return; - }; - - let etw_meta = EVENT_METADATA.get(&metadata.callsite()); - let (keyword, tag) = if let Some(meta) = etw_meta { - (meta.kw, meta.event_tag) - } else { - (self.default_keyword, 0) - }; - - self.provider.as_ref().span_start( - &span, - timestamp, - &data.activity_id, - &data.related_activity_id, - &data.fields, - metadata.level(), - keyword, - tag, - ); - - data.start_time = timestamp; - } - - fn on_exit(&self, id: &span::Id, ctx: tracing_subscriber::layer::Context<'_, S>) { - // A span was exited - let stop_timestamp = std::time::SystemTime::now(); - - let span = if let Some(span) = ctx.span(id) { - span - } else { - return; - }; - - let metadata = span.metadata(); - - let mut extensions = span.extensions_mut(); - let data = if let Some(data) = extensions.get_mut::() { - data - } else { - // We got a span that was entered without being new'ed? - return; - }; - - let etw_meta = EVENT_METADATA.get(&metadata.callsite()); - let (keyword, tag) = if let Some(meta) = etw_meta { - (meta.kw, meta.event_tag) - } else { - (self.default_keyword, 0) - }; - - self.provider.as_ref().span_stop( - &span, - (data.start_time, stop_timestamp), - &data.activity_id, - &data.related_activity_id, - &data.fields, - metadata.level(), - keyword, - tag, - ); - } - - fn on_close(&self, _id: span::Id, _ctx: tracing_subscriber::layer::Context<'_, S>) { - // A span was closed - // Good for knowing when to log a summary event? - } - - fn on_record( - &self, - id: &span::Id, - values: &span::Record<'_>, - ctx: tracing_subscriber::layer::Context<'_, S>, - ) { - // Values were added to the given span - - let span = if let Some(span) = ctx.span(id) { - span - } else { - return; - }; - - let mut extensions = span.extensions_mut(); - let data = if let Some(data) = extensions.get_mut::() { - data - } else { - // We got a span that was entered without being new'ed? - return; - }; - - values.record(&mut ValueVisitor { - fields: &mut data.fields, - }); - } -} diff --git a/src/layer/filter.rs b/src/layer/filter.rs new file mode 100644 index 0000000..5f817a7 --- /dev/null +++ b/src/layer/filter.rs @@ -0,0 +1,53 @@ +use tracing::Subscriber; +use tracing_subscriber::{layer::Filter, registry::LookupSpan}; + +use crate::{native::{EventWriter, ProviderTypes}, statics::EVENT_METADATA}; + +use super::*; + +impl Filter for EtwFilter +where + S: Subscriber + for<'a> LookupSpan<'a>, + Mode: ProviderTypes + 'static, + Mode::Provider: EventWriter + 'static, +{ + fn callsite_enabled( + &self, + metadata: &'static tracing::Metadata<'static>, + ) -> tracing::subscriber::Interest { + let etw_meta = EVENT_METADATA.get(&metadata.callsite()); + let keyword = if let Some(meta) = etw_meta { + meta.kw + } else { + self.layer.default_keyword + }; + + if Mode::supports_enable_callback() { + if self.layer.provider.enabled(metadata.level(), keyword) { + tracing::subscriber::Interest::always() + } else { + tracing::subscriber::Interest::never() + } + } else { + // Returning "sometimes" means the enabled function will be called every time an event or span is created from the callsite. + // This will let us perform a global "is enabled" check each time. + tracing::subscriber::Interest::sometimes() + } + } + + fn enabled( + &self, + metadata: &tracing::Metadata<'_>, + _cx: &tracing_subscriber::layer::Context<'_, S>, + ) -> bool { + self.layer.is_enabled(&metadata.callsite(), metadata.level()) + } + + fn event_enabled( + &self, + event: &tracing::Event<'_>, + _cx: &tracing_subscriber::layer::Context<'_, S>, + ) -> bool { + self.layer.is_enabled(&event.metadata().callsite(), event.metadata().level()) + } +} diff --git a/src/layer/layer.rs b/src/layer/layer.rs new file mode 100644 index 0000000..175da05 --- /dev/null +++ b/src/layer/layer.rs @@ -0,0 +1,297 @@ +use std::time::SystemTime; + +use tracing::Subscriber; +#[allow(unused_imports)] // Many imports are used exclusively by feature-gated code +use tracing_core::{callsite, span}; +use tracing_subscriber::{registry::LookupSpan, Layer}; + +use crate::{native::{EventWriter, ProviderTypes}, statics::*, values::*}; + +use super::*; + +struct SpanData { + fields: Box<[FieldValueIndex]>, + activity_id: [u8; 16], // // if set, byte 0 is 1 and 64-bit span ID in the lower 8 bytes + related_activity_id: [u8; 16], // if set, byte 0 is 1 and 64-bit span ID in the lower 8 bytes + start_time: SystemTime, +} + +impl Layer for EtwLayer +where + S: Subscriber + for<'a> LookupSpan<'a>, + Mode: ProviderTypes + 'static, + Mode::Provider: EventWriter + 'static, +{ + fn on_register_dispatch(&self, _collector: &tracing::Dispatch) { + // Late init when the layer is installed as a subscriber + } + + fn on_layer(&mut self, _subscriber: &mut S) { + // Late init when the layer is attached to a subscriber + } + + #[cfg(any(feature = "global_filter", docsrs))] + fn register_callsite( + &self, + metadata: &'static tracing::Metadata<'static>, + ) -> tracing::subscriber::Interest { + let etw_meta = EVENT_METADATA.get(&metadata.callsite()); + let keyword = if let Some(meta) = etw_meta { + meta.kw + } else { + self.layer.default_keyword + }; + + if Mode::supports_enable_callback() { + if self.layer.provider.enabled(metadata.level(), keyword) { + tracing::subscriber::Interest::always() + } else { + tracing::subscriber::Interest::never() + } + } else { + // Returning "sometimes" means the enabled function will be called every time an event or span is created from the callsite. + // This will let us perform a global "is enabled" check each time. + tracing::subscriber::Interest::sometimes() + } + } + + #[cfg(any(feature = "global_filter", docsrs))] + fn enabled( + &self, + metadata: &tracing::Metadata<'_>, + _ctx: tracing_subscriber::layer::Context<'_, S>, + ) -> bool { + self.layer.is_enabled(&metadata.callsite(), metadata.level()) + } + + #[cfg(any(feature = "global_filter", docsrs))] + fn event_enabled( + &self, + event: &tracing::Event<'_>, + _ctx: tracing_subscriber::layer::Context<'_, S>, + ) -> bool { + self.layer.is_enabled(&event.metadata().callsite(), event.metadata().level()) + } + + fn on_event(&self, event: &tracing::Event<'_>, ctx: tracing_subscriber::layer::Context<'_, S>) { + let timestamp = std::time::SystemTime::now(); + + let current_span = ctx + .event_span(event) + .map(|evt| evt.id()) + .map_or(0, |id| (id.into_u64())); + let parent_span = ctx + .event_span(event) + .map_or(0, |evt| evt.parent().map_or(0, |p| p.id().into_u64())); + + let etw_meta = EVENT_METADATA.get(&event.metadata().callsite()); + let (name, keyword, tag) = if let Some(meta) = etw_meta { + (event.metadata().name(), meta.kw, meta.event_tag) + } else { + (event.metadata().name(), self.layer.default_keyword, 0) + }; + + self.layer.provider.as_ref().write_record( + timestamp, + current_span, + parent_span, + name, + event.metadata().level(), + keyword, + tag, + event, + ); + } + + fn on_new_span( + &self, + attrs: &span::Attributes<'_>, + id: &span::Id, + ctx: tracing_subscriber::layer::Context<'_, S>, + ) { + let span = if let Some(span) = ctx.span(id) { + span + } else { + return; + }; + + if span.extensions().get::().is_some() { + return; + } + + let metadata = span.metadata(); + + let parent_span_id = if attrs.is_contextual() { + attrs.parent().map_or(0, |id| id.into_u64()) + } else { + 0 + }; + + let n = metadata.fields().len(); + + let mut data = { + let mut v: Vec = Vec::with_capacity(n); + v.resize_with(n, Default::default); + + let mut i = 0; + for field in metadata.fields().iter() { + v[i].field = field.name(); + v[i].value = ValueTypes::None; + v[i].sort_index = i as u8; + i += 1; + } + + let mut indexes: [u8; 32] = [ + 0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16, 17, 18, 19, 20, 21, 22, + 23, 24, 25, 26, 27, 28, 29, 30, 31, + ]; + + indexes[0..n].sort_by_key(|idx| v[v[*idx as usize].sort_index as usize].field); + + i = 0; + for f in &mut v { + f.sort_index = indexes[i]; + i += 1; + } + + SpanData { + fields: v.into_boxed_slice(), + activity_id: *GLOBAL_ACTIVITY_SEED, + related_activity_id: *GLOBAL_ACTIVITY_SEED, + start_time: SystemTime::UNIX_EPOCH, + } + }; + + let (_, half) = data.activity_id.split_at_mut(8); + half.copy_from_slice(&id.into_u64().to_le_bytes()); + + data.activity_id[0] = 1; + data.related_activity_id[0] = if parent_span_id != 0 { + let (_, half) = data.related_activity_id.split_at_mut(8); + half.copy_from_slice(&parent_span_id.to_le_bytes()); + 1 + } else { + 0 + }; + + attrs.values().record(&mut ValueVisitor { + fields: &mut data.fields, + }); + + // This will unfortunately box data. It would be ideal if we could avoid this second heap allocation + // by packing everything into a single alloc. + span.extensions_mut().replace(data); + } + + fn on_enter(&self, id: &span::Id, ctx: tracing_subscriber::layer::Context<'_, S>) { + // A span was started + let timestamp = std::time::SystemTime::now(); + + let span = if let Some(span) = ctx.span(id) { + span + } else { + return; + }; + + let metadata = span.metadata(); + + let mut extensions = span.extensions_mut(); + let data = if let Some(data) = extensions.get_mut::() { + data + } else { + // We got a span that was entered without being new'ed? + return; + }; + + let etw_meta = EVENT_METADATA.get(&metadata.callsite()); + let (keyword, tag) = if let Some(meta) = etw_meta { + (meta.kw, meta.event_tag) + } else { + (self.layer.default_keyword, 0) + }; + + self.layer.provider.as_ref().span_start( + &span, + timestamp, + &data.activity_id, + &data.related_activity_id, + &data.fields, + metadata.level(), + keyword, + tag, + ); + + data.start_time = timestamp; + } + + fn on_exit(&self, id: &span::Id, ctx: tracing_subscriber::layer::Context<'_, S>) { + // A span was exited + let stop_timestamp = std::time::SystemTime::now(); + + let span = if let Some(span) = ctx.span(id) { + span + } else { + return; + }; + + let metadata = span.metadata(); + + let mut extensions = span.extensions_mut(); + let data = if let Some(data) = extensions.get_mut::() { + data + } else { + // We got a span that was entered without being new'ed? + return; + }; + + let etw_meta = EVENT_METADATA.get(&metadata.callsite()); + let (keyword, tag) = if let Some(meta) = etw_meta { + (meta.kw, meta.event_tag) + } else { + (self.layer.default_keyword, 0) + }; + + self.layer.provider.as_ref().span_stop( + &span, + (data.start_time, stop_timestamp), + &data.activity_id, + &data.related_activity_id, + &data.fields, + metadata.level(), + keyword, + tag, + ); + } + + fn on_close(&self, _id: span::Id, _ctx: tracing_subscriber::layer::Context<'_, S>) { + // A span was closed + // Good for knowing when to log a summary event? + } + + fn on_record( + &self, + id: &span::Id, + values: &span::Record<'_>, + ctx: tracing_subscriber::layer::Context<'_, S>, + ) { + // Values were added to the given span + + let span = if let Some(span) = ctx.span(id) { + span + } else { + return; + }; + + let mut extensions = span.extensions_mut(); + let data = if let Some(data) = extensions.get_mut::() { + data + } else { + // We got a span that was entered without being new'ed? + return; + }; + + values.record(&mut ValueVisitor { + fields: &mut data.fields, + }); + } +} diff --git a/src/layer/mod.rs b/src/layer/mod.rs new file mode 100644 index 0000000..a70a974 --- /dev/null +++ b/src/layer/mod.rs @@ -0,0 +1,71 @@ +mod layer; + +#[cfg(any(not(feature = "global_filter"), docsrs))] +mod filter; + +use std::{marker::PhantomData, pin::Pin, sync::Arc}; + +use tracing::Subscriber; +use tracing_core::callsite; +use tracing_subscriber::registry::LookupSpan; + +use crate::{native::{EventWriter, ProviderTypes}, statics::EVENT_METADATA}; + +pub(crate) struct _EtwLayer +where + Mode::Provider: crate::native::EventWriter + 'static +{ + pub(crate) provider: Pin>, + pub(crate) default_keyword: u64, + pub(crate) _p: PhantomData, +} + +impl Clone for _EtwLayer +where + Mode::Provider: crate::native::EventWriter + 'static +{ + fn clone(&self) -> Self { + _EtwLayer { + provider: self.provider.clone(), + default_keyword: self.default_keyword, + _p: PhantomData + } + } +} + +// This struct needs to be public as it implements the tracing_subscriber::Layer and tracing_subscriber::Layer::Filter traits. +#[doc(hidden)] +pub struct EtwLayer +where + Mode::Provider: EventWriter + 'static +{ + pub(crate) layer: _EtwLayer +} + +// This struct needs to be public as it implements the tracing_subscriber::Layer::Filter trait. +#[doc(hidden)] +#[cfg(any(not(feature = "global_filter"), docsrs))] +pub struct EtwFilter +where + Mode::Provider: EventWriter + 'static +{ + pub(crate) layer: _EtwLayer +} + +impl _EtwLayer +where + S: Subscriber + for<'a> LookupSpan<'a>, + Mode: ProviderTypes + 'static, + Mode::Provider: EventWriter + 'static, +{ + fn is_enabled(&self, callsite: &callsite::Identifier, level: &tracing_core::Level) -> bool { + let etw_meta = EVENT_METADATA.get(&callsite); + let keyword = if let Some(meta) = etw_meta { + meta.kw + } else { + self.default_keyword + }; + + self.provider.enabled(level, keyword) + } +} diff --git a/src/layer_builder.rs b/src/layer_builder.rs new file mode 100644 index 0000000..9912e8f --- /dev/null +++ b/src/layer_builder.rs @@ -0,0 +1,259 @@ +use std::marker::PhantomData; +#[allow(unused_imports)] +use std::{pin::Pin, sync::Arc}; + +#[allow(unused_imports)] // Many imports are used exclusively by feature-gated code +use tracing::metadata::LevelFilter; +use tracing::Subscriber; +#[allow(unused_imports)] +use tracing_subscriber::filter::{combinator::And, FilterExt, Filtered, Targets}; +#[allow(unused_imports)] +use tracing_subscriber::{Layer, layer::Filter}; +use tracing_subscriber::registry::LookupSpan; + + +#[cfg(any(not(feature = "global_filter"), docsrs))] +use crate::layer::EtwFilter; +use crate::layer::{EtwLayer, _EtwLayer}; +use crate::native::{EventWriter, GuidWrapper, ProviderTypes}; +use crate::{error::EtwError, native}; + +/// Builds a [tracing_subscriber::Layer] that will logs events from a single +/// ETW or user_events provider. Use [LayerBuilder::new] to construct a new +/// builder for the given provider name. Use the `with_*` methods to set +/// additional properties for the provider, such as the keyword to use +/// for events (default: 1) or a specific provider GUID (default: a hash of +/// the provider name). +/// +/// Use [LayerBuilder::new_common_schema_events] to create a layer that +/// will log events in the Common Schema 4.0 mapping. Only use this if +/// you know that you need events in this format. +/// +/// Multiple `tracing_etw` layers can be created at the same time, +/// with different provider names/IDs, keywords, or output formats. +/// (Target filters)[tracing_subscriber::filter] can then be used to direct +/// specific events to specific layers. +pub struct LayerBuilder +where + Mode: ProviderTypes +{ + provider_name: String, + provider_id: GuidWrapper, + provider_group: Option, + default_keyword: u64, + _m: PhantomData, +} + +impl LayerBuilder { + #[allow(clippy::new_ret_no_self)] + pub fn new(name: &str) -> LayerBuilder { + LayerBuilder:: { + provider_name: name.to_owned(), + provider_id: GuidWrapper::from_name(name), + provider_group: None, + default_keyword: 1, + _m: PhantomData, + } + } +} + +impl LayerBuilder { + /// For advanced scenarios. + /// Emit events that follow the Common Schema 4.0 mapping. + /// Recommended only for compatibility with specialized event consumers. + /// Most ETW consumers will not benefit from events in this schema, and + /// may perform worse. Common Schema events are much slower to generate + /// and should not be enabled unless absolutely necessary. + #[cfg(any(feature = "common_schema", docsrs))] + pub fn new_common_schema_events( + name: &str, + ) -> LayerBuilder { + LayerBuilder:: { + provider_name: name.to_owned(), + provider_id: GuidWrapper::from_name(name), + provider_group: None, + default_keyword: 1, + _m: PhantomData, + } + } +} + +impl LayerBuilder +where + Mode: ProviderTypes + 'static, +{ + /// For advanced scenarios. + /// Assign a provider ID to the ETW provider rather than use + /// one generated from the provider name. + pub fn with_provider_id(mut self, guid: &G) -> Self + where + for<'a> &'a G: Into + { + self.provider_id = guid.into(); + self + } + + /// Get the current provider ID that will be used for the ETW provider. + /// This is a convenience function to help with tools that do not implement + /// the standard provider name to ID algorithm. + pub fn get_provider_id(&self) -> GuidWrapper { + self.provider_id.clone() + } + + + /// Set the keyword used for events that do not explicitly set a keyword. + /// + /// Events logged with the [crate::etw_event!] macro specify a keyword for the event. + /// Events and spans logged with the [tracing::event!], [tracing::span!], + /// or other similar `tracing` macros will use the default keyword. + /// + /// If this method is not called, the default keyword will be `1`. + /// + /// Keyword value `0` is special in ETW (but not user_events), and should + /// not be used. + pub fn with_default_keyword(mut self, kw: u64) -> Self { + self.default_keyword = kw; + self + } + + /// For advanced scenarios. + /// Set the provider group to join this provider to. + pub fn with_provider_group(mut self, group_id: &G) -> Self + where + for <'a> &'a G: Into, + { + self.provider_group = Some(group_id.into()); + self + } + + fn validate_config(&self) -> Result<(), EtwError> { + #[cfg(target_os = "linux")] + { + if self + .provider_name + .contains(|f: char| !f.is_ascii_alphanumeric() && f != '_') + { + // The perf command is very particular about the provider names it accepts. + // The Linux kernel itself cares less, and other event consumers should also presumably not need this check. + return Err(EtwError::InvalidProviderNameCharacters(self.provider_name.clone())); + } + + let group_name_len = match &self.provider_group { + None => 0, + Some(ref name) => Mode::get_provider_group(&name).as_ref().len() + }; + + if self.provider_name.len() + group_name_len >= 234 { + return Err(EtwError::TooManyCharacters(self.provider_name.len() + group_name_len)); + } + } + + match &self.provider_group { + None => Ok(()), + Some(value) => Mode::is_valid(value) + } + } + + #[cfg(any(not(feature = "global_filter"), docsrs))] + fn build_target_filter(&self, target: &'static str) -> Targets { + let mut targets = Targets::new().with_target(&self.provider_name, LevelFilter::TRACE); + + #[cfg(target_os = "linux")] + match self.provider_group { + None => {} + Some(ref name) => { + targets = targets.with_target(Mode::get_provider_group(name).as_ref(), LevelFilter::TRACE); + } + } + + if !target.is_empty() { + targets = targets.with_target(target, LevelFilter::TRACE) + } + + targets + } + + fn build_layer(&self) -> EtwLayer + where + S: Subscriber + for<'a> LookupSpan<'a>, + Mode::Provider: EventWriter + 'static, + { + EtwLayer:: { + layer: _EtwLayer { + provider: Mode::Provider::new( + &self.provider_name, + &self.provider_id, + &self.provider_group, + self.default_keyword, + ), + default_keyword: self.default_keyword, + _p: PhantomData, + } + } + } + + #[cfg(any(not(feature = "global_filter"), docsrs))] + fn build_filter(&self, layer: _EtwLayer) -> EtwFilter + where + S: Subscriber + for<'a> LookupSpan<'a>, + Mode::Provider: EventWriter + 'static, + { + EtwFilter:: { + layer + } + } + + #[cfg_attr(docsrs, doc(cfg(feature = "global_filter")))] + #[cfg(any(feature = "global_filter", docsrs))] + pub fn build_global_filter(self) -> Result, EtwError> + where + S: Subscriber + for<'a> LookupSpan<'a>, + Mode::Provider: EventWriter + 'static, + { + self.validate_config()?; + + Ok(self.build_layer()) + } + + #[allow(clippy::type_complexity)] + #[cfg_attr(docsrs, doc(cfg(not(feature = "global_filter"))))] + #[cfg(any(not(feature = "global_filter"), docsrs))] + pub fn build(self) -> Result, EtwFilter, S>, EtwError> + where + S: Subscriber + for<'a> LookupSpan<'a>, + Mode::Provider: EventWriter + 'static, + { + self.validate_config()?; + + let layer = self.build_layer(); + + let filter = self.build_filter(layer.layer.clone()); + + Ok(layer.with_filter(filter)) + } + + /// Constructs the configured layer with a target [tracing_subscriber::filter] applied. + /// This can be used to target specific events to specific layers, and in effect allow + /// specific events to be logged only from specific ETW/user_event providers. + #[allow(clippy::type_complexity)] + #[cfg_attr(docsrs, doc(cfg(not(feature = "global_filter"))))] + #[cfg(any(not(feature = "global_filter"), docsrs))] + pub fn build_with_target( + self, + target: &'static str, + ) -> Result, And, Targets, S>, S>, EtwError> + where + S: Subscriber + for<'a> LookupSpan<'a>, + Mode::Provider: EventWriter + 'static, + { + self.validate_config()?; + + let layer = self.build_layer(); + + let filter = self.build_filter(layer.layer.clone()); + + let targets = self.build_target_filter(target); + + Ok(layer.with_filter(filter.and(targets))) + } +} diff --git a/src/lib.rs b/src/lib.rs index c385acb..e01e219 100644 --- a/src/lib.rs +++ b/src/lib.rs @@ -75,7 +75,7 @@ // the `docsrs` configuration attribute is defined #![cfg_attr(docsrs, feature(doc_cfg))] -mod layer; +mod layer_builder; // Module that abstracts the native ETW and Linux user_events APIs, depending on the target platform. // Consumers of the crate should not need to use this module directly. #[doc(hidden)] @@ -87,7 +87,9 @@ mod statics; pub mod _details; pub mod error; -pub use layer::LayerBuilder; +pub use layer_builder::LayerBuilder; + +mod layer; #[macro_export] macro_rules! etw_event { From 1a15226faa598844cf2329ee51c3cf4c2ac3883a Mon Sep 17 00:00:00 2001 From: Kyle Sabo Date: Fri, 23 Aug 2024 22:24:42 -0700 Subject: [PATCH 4/4] Fix up example --- src/bin/main.rs | 20 +++++++++++++++----- 1 file changed, 15 insertions(+), 5 deletions(-) diff --git a/src/bin/main.rs b/src/bin/main.rs index 1c7a76e..8f780b2 100644 --- a/src/bin/main.rs +++ b/src/bin/main.rs @@ -1,3 +1,5 @@ +#![allow(unused_imports)] + use tracing::{event, span, Level}; use tracing_etw::{etw_event, LayerBuilder}; use tracing_subscriber::{self, fmt::format::FmtSpan, prelude::*}; @@ -8,11 +10,19 @@ use tracing_subscriber::{self, fmt::format::FmtSpan, prelude::*}; // } fn main() { - tracing_subscriber::registry() - .with(LayerBuilder::new("test").build().unwrap()) // Collects everything - .with(LayerBuilder::new_common_schema_events("test2").build_with_target("geneva").unwrap()) - .with(tracing_subscriber::fmt::layer().with_span_events(FmtSpan::ACTIVE)) - .init(); + let registry = tracing_subscriber::registry(); + + #[cfg(not(feature = "global_filter"))] + let registry = registry.with(LayerBuilder::new("test").build().unwrap()); + #[cfg(all(not(feature = "global_filter"), feature = "common_schema"))] + let registry = registry.with(LayerBuilder::new_common_schema_events("test2").build_with_target("geneva").unwrap()); + #[cfg(not(feature = "global_filter"))] + let registry = registry.with(tracing_subscriber::fmt::layer().with_span_events(FmtSpan::ACTIVE)); + + #[cfg(feature = "global_filter")] + let registry = registry.with(LayerBuilder::new("test").build_global_filter().unwrap()); + + registry.init(); #[allow(non_snake_case)] let fieldB = "asdf";