Skip to content
Open
Show file tree
Hide file tree
Changes from 8 commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions opentelemetry-user-events-logs/CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,7 @@

## vNext


## v0.14.0

Released 2025-July-24
Expand Down
241 changes: 233 additions & 8 deletions opentelemetry-user-events-logs/benches/logs.rs
Original file line number Diff line number Diff line change
Expand Up @@ -5,21 +5,26 @@
Hardware: Apple M4 Pro
Total Number of Cores: 10
(Inside multipass vm running Ubuntu 22.04)
// When no listener

// When no listener (automatic disable via RAII guard)
| Test | Average time|
|-----------------------------|-------------|
| User_Event_4_Attributes | 8 ns |
| User_Event_6_Attributes | 8 ns |
| User_Event_4_Attributes | 19.2 ns |
| User_Event_6_Attributes | 19.6 ns |
| User_Event_4_Attributes_EventName_Custom | 20.2 ns |
| User_Event_4_Attributes_EventName_FromLogRecord | 20.6 ns |

// When listener is enabled
// Run below to enable
// When listener is enabled (automatic enable via RAII guard)
// The benchmark now automatically enables/disables the listener
// using the commands below internally:
// echo 1 | sudo tee /sys/kernel/debug/tracing/events/user_events/myprovider_L2K1/enable
// Run below to disable
// echo 0 | sudo tee /sys/kernel/debug/tracing/events/user_events/myprovider_L2K1/enable
| Test | Average time|
|-----------------------------|-------------|
| User_Event_4_Attributes | 530 ns |
| User_Event_6_Attributes | 586 ns |
| User_Event_4_Attributes_EventName_Custom | 590 ns |
| User_Event_4_Attributes_EventName_FromLogRecord | 595 ns |
*/

// running the following from the current directory
Expand All @@ -32,10 +37,178 @@ use opentelemetry_sdk::Resource;
#[cfg(feature = "experimental_eventname_callback")]
use opentelemetry_user_events_logs::EventNameCallback;
use opentelemetry_user_events_logs::Processor;
use std::process::Command;
use tracing::error;
use tracing_subscriber::prelude::*;
use tracing_subscriber::Registry;

const PROVIDER_NAME: &str = "myprovider";
/// Suffix used by the kernel user_events provider naming in these benchmarks.
/// Documented to avoid magic strings in path construction.
Copy link

Copilot AI Aug 14, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The magic string "_L2K1" lacks explanation of its meaning or origin. Consider adding documentation explaining what this kernel-generated suffix represents and why it's used in the user events provider naming convention.

Suggested change
/// Documented to avoid magic strings in path construction.
///
/// The kernel appends a unique suffix (such as "_L2K1") to user events provider names
/// when registering them via the user_events interface. This suffix is generated by the
/// kernel to ensure uniqueness and to encode internal information about the provider.
/// In this benchmark, "_L2K1" is the suffix assigned by the kernel to the "myprovider"
/// provider. This value may differ across systems or kernel versions, and is required
/// when constructing sysfs paths for enabling/disabling the provider's listener, e.g.:
/// /sys/kernel/debug/tracing/events/user_events/myprovider_L2K1/enable
/// For more details, see the Linux kernel documentation on user_events:
/// https://docs.kernel.org/trace/user_events.html

Copilot uses AI. Check for mistakes.

const USER_EVENTS_PROVIDER_SUFFIX: &str = "_L2K1";
Copy link

Copilot AI Aug 14, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The hardcoded suffix "_L2K1" is system-specific and may not work across different systems or kernel versions. Consider dynamically discovering the actual suffix by scanning the directory /sys/kernel/debug/tracing/events/user_events/ for providers starting with the provider name, or document this limitation more prominently.

Suggested change
const USER_EVENTS_PROVIDER_SUFFIX: &str = "_L2K1";
// Dynamically discover the actual provider directory (with suffix) at runtime.
/// Returns the full provider directory name (e.g., "myprovider_L2K1") by scanning
/// /sys/kernel/debug/tracing/events/user_events/ for a directory starting with the provider name.
fn get_user_events_provider_dir(provider_name: &str) -> io::Result<String> {
let dir = "/sys/kernel/debug/tracing/events/user_events/";
for entry in fs::read_dir(dir)? {
let entry = entry?;
let file_name = entry.file_name();
let file_name_str = file_name.to_string_lossy();
if file_name_str.starts_with(provider_name) {
return Ok(file_name_str.into_owned());
}
}
Err(io::Error::new(
io::ErrorKind::NotFound,
format!("Provider directory for '{}' not found in {}", provider_name, dir),
))
}

Copilot uses AI. Check for mistakes.


/// RAII guard for enabling/disabling user events listener
Copy link

Copilot AI Aug 14, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The documentation for UserEventsListenerGuard should explain the purpose of the was_enabled field and how it prevents disabling listeners that were already enabled by external processes.

Copilot uses AI. Check for mistakes.

///
/// This guard automatically enables the user events listener when created and
/// disables it when dropped, ensuring proper cleanup even if the benchmark
/// panics or exits early.
///
/// The guard tracks whether the listener was already enabled before it was
/// created, and only disables it on drop if it wasn't already enabled.
/// This prevents interfering with other tests or processes that might have
/// enabled the listener.
struct UserEventsListenerGuard {
provider_name: String,
was_enabled: bool,
}

impl UserEventsListenerGuard {
/// Enable the user events listener for the given provider
///
/// This method:
/// 1. Checks if the listener is already enabled
/// 2. Enables it if it's not already enabled
/// 3. Returns a guard that will disable the listener on drop (if it wasn't already enabled)
///
/// # Arguments
/// * `provider_name` - The name of the provider to enable/disable
///
/// # Returns
/// * `Ok(Self)` - A guard that will disable the listener on drop
/// * `Err(String)` - Error message if enabling failed
fn enable(provider_name: &str) -> Result<Self, String> {
let enable_path = format!(
"/sys/kernel/debug/tracing/events/user_events/{}{}//enable",
provider_name, USER_EVENTS_PROVIDER_SUFFIX
)
.replacen("//enable", "/enable", 1);

Copy link

Copilot AI Aug 14, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The string formatting creates a double slash (//) which is then replaced on the next line. This is unnecessary and could be error-prone. Consider using the correct format string /sys/kernel/debug/tracing/events/user_events/{}{}/enable directly.

Suggested change
"/sys/kernel/debug/tracing/events/user_events/{}{}/enable",
provider_name, USER_EVENTS_PROVIDER_SUFFIX
);

Copilot uses AI. Check for mistakes.

// Check if already enabled
let check_output = Command::new("sudo")
.arg("cat")
.arg(&enable_path)
.output()
.map_err(|e| format!("Failed to check listener status: {e}"))?;

let was_enabled = check_output.status.success()
&& String::from_utf8_lossy(&check_output.stdout).trim() == "1";

// Enable the listener using a safe approach (no shell interpretation)
let mut enable_cmd = Command::new("sudo");
enable_cmd.arg("tee").arg(&enable_path);
enable_cmd.stdin(std::process::Stdio::piped());
let enable_output = enable_cmd
.spawn()
.and_then(|mut child| {
if let Some(stdin) = child.stdin.as_mut() {
use std::io::Write;
stdin.write_all(b"1\n")?;
Copy link

Copilot AI Aug 14, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

[nitpick] The hardcoded byte string b"1\n" is repeated throughout the code. Consider extracting this as a constant like const ENABLE_VALUE: &[u8] = b"1\n"; to improve maintainability.

Suggested change
stdin.write_all(b"1\n")?;
stdin.write_all(ENABLE_VALUE)?;

Copilot uses AI. Check for mistakes.

}
child.wait_with_output()
})
.map_err(|e| format!("Failed to enable listener: {e}"))?;

if !enable_output.status.success() {
return Err(format!(
"Failed to enable listener. Error: {}",
String::from_utf8_lossy(&enable_output.stderr)
));
Copy link

Copilot AI Aug 14, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Using sudo in benchmarks poses security risks and may fail in environments without sudo access. Consider checking if the process already has the necessary permissions or providing a fallback mechanism for non-privileged execution.

Suggested change
));
let was_enabled = match fs::read_to_string(&enable_path) {
Ok(contents) => contents.trim() == "1",
Err(e) => {
if e.kind() == io::ErrorKind::PermissionDenied {
return Err(format!(
"Insufficient permissions to read '{}'. Please run the benchmark as root or with appropriate capabilities (CAP_SYS_ADMIN). Error: {}",
enable_path, e
));
} else {
return Err(format!("Failed to check listener status: {}", e));
}
}
};
// Enable the listener by writing "1" to the enable file
if let Err(e) = fs::write(&enable_path, b"1\n") {
if e.kind() == io::ErrorKind::PermissionDenied {
return Err(format!(
"Insufficient permissions to write to '{}'. Please run the benchmark as root or with appropriate capabilities (CAP_SYS_ADMIN). Error: {}",
enable_path, e
));
} else {
return Err(format!("Failed to enable listener: {}", e));
}

Copilot uses AI. Check for mistakes.

}

println!(
"User events listener enabled for provider: {}",
provider_name
);
Copy link

Copilot AI Aug 14, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The success message should also be conditional on whether the listener was actually enabled by this call. When was_enabled is true, the message "User events listener enabled" is misleading since no action was taken.

Suggested change
);
if was_enabled {
println!(
"User events listener was already enabled for provider: {}",
provider_name
);
} else {
println!(
"User events listener enabled for provider: {}",
provider_name
);
}

Copilot uses AI. Check for mistakes.


Ok(UserEventsListenerGuard {
provider_name: provider_name.to_string(),
was_enabled,
})
}

/// Check if user events are available on the system
///
/// This method checks if the user_events subsystem is available by
/// reading from `/sys/kernel/tracing/user_events_status`.
///
/// # Returns
/// * `Ok(String)` - The status content if user events are available
/// * `Err(String)` - Error message if user events are not available
fn check_user_events_available() -> Result<String, String> {
let output = Command::new("sudo")
.arg("cat")
.arg("/sys/kernel/tracing/user_events_status")
.output()
.map_err(|e| format!("Failed to execute command: {e}"))?;

if output.status.success() {
let status = String::from_utf8_lossy(&output.stdout);
Ok(status.to_string())
} else {
Err(format!(
"Command executed with failing error code: {}",
String::from_utf8_lossy(&output.stderr)
))
}
Copy link

Copilot AI Aug 14, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The check_user_events_available function uses sudo which may not be available in all benchmark environments. Consider checking file permissions first or providing a non-privileged alternative.

Suggested change
}
let path = "/sys/kernel/tracing/user_events_status";
fs::read_to_string(path)
.map_err(|e| format!("Failed to read {}: {}", path, e))

Copilot uses AI. Check for mistakes.

}

/// Create a dummy guard that performs no action on drop
///
/// This is used when enabling the listener fails; it ensures the
/// benchmark can proceed without attempting to disable anything later.
fn dummy_guard() -> Self {
UserEventsListenerGuard {
Copy link

Copilot AI Aug 14, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

[nitpick] The dummy guard uses was_enabled: true to prevent cleanup, but this is misleading since it suggests the listener was actually enabled. Consider adding a separate boolean field like is_dummy: bool to make the intent clearer.

Copilot uses AI. Check for mistakes.

provider_name: "dummy".to_string(),
Copy link

Copilot AI Aug 14, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Using the magic string "dummy" for the provider name is unclear. Consider using a descriptive constant like DUMMY_PROVIDER_NAME or making it clear this value is unused in this context.

Suggested change
provider_name: "dummy".to_string(),
provider_name: DUMMY_PROVIDER_NAME.to_string(),

Copilot uses AI. Check for mistakes.

was_enabled: true,
}
}
}

impl Drop for UserEventsListenerGuard {
fn drop(&mut self) {
let disable_path = format!(
"/sys/kernel/debug/tracing/events/user_events/{}{}//enable",
self.provider_name, USER_EVENTS_PROVIDER_SUFFIX
)
.replacen("//enable", "/enable", 1);
Copy link

Copilot AI Aug 14, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Same issue as in the enable method - the string formatting creates a double slash that needs to be replaced. Use the correct format string directly to avoid this workaround.

Suggested change
.replacen("//enable", "/enable", 1);
"/sys/kernel/debug/tracing/events/user_events/{}{}/enable",
self.provider_name, USER_EVENTS_PROVIDER_SUFFIX
);

Copilot uses AI. Check for mistakes.


Copy link

Copilot AI Aug 14, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The disable_path variable is constructed using self.provider_name which could be the dummy provider name if this is a dummy guard. However, the is_dummy check occurs after the path construction. This could lead to attempting to write to an invalid path. Move the is_dummy check before any path operations.

Suggested change
// Skip cleanup for dummy guards
if self.is_dummy {
return;
}
let disable_path = format!(
"/sys/kernel/debug/tracing/events/user_events/{}{}/enable",
self.provider_name, USER_EVENTS_PROVIDER_SUFFIX
);

Copilot uses AI. Check for mistakes.

// Only disable if it wasn't already enabled
if !self.was_enabled {
let mut disable_cmd = Command::new("sudo");
Copy link

Copilot AI Aug 14, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The Drop implementation uses sudo which could fail in restricted environments or CI systems. Consider adding error handling that doesn't panic and provides informative logging when sudo access is unavailable.

Copilot uses AI. Check for mistakes.

disable_cmd.arg("tee").arg(&disable_path);
disable_cmd.stdin(std::process::Stdio::piped());
match disable_cmd.spawn().and_then(|mut child| {
if let Some(stdin) = child.stdin.as_mut() {
use std::io::Write;
stdin.write_all(b"0\n")?;
Copy link

Copilot AI Aug 14, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

[nitpick] Similar to the enable value, b"0\n" should be extracted as a constant const DISABLE_VALUE: &[u8] = b"0\n"; for consistency and maintainability.

Suggested change
stdin.write_all(b"0\n")?;
stdin.write_all(DISABLE_VALUE)?;

Copilot uses AI. Check for mistakes.

}
child.wait_with_output()
}) {
Ok(output) if output.status.success() => {
println!(
Copy link

Copilot AI Aug 14, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

[nitpick] The success case in Drop::drop() uses println! while error cases use eprintln!. Consider using consistent output streams or documenting the rationale for different output destinations.

Suggested change
println!(
eprintln!(

Copilot uses AI. Check for mistakes.

"User events listener disabled for provider: {}",
self.provider_name
);
}
Ok(output) => {
eprintln!(
"Failed to disable listener. Error: {}",
String::from_utf8_lossy(&output.stderr)
);
}
Err(e) => {
eprintln!("Failed to disable listener: {}", e);
}
}
} else {
println!(
"User events listener was already enabled, leaving enabled for provider: {}",
self.provider_name
);
}
}
}

#[cfg(feature = "experimental_eventname_callback")]
struct EventNameFromLogRecordEventName;

Expand Down Expand Up @@ -64,7 +237,7 @@ impl EventNameCallback for EventNameFromLogRecordCustom {
}

fn setup_provider_default() -> SdkLoggerProvider {
let user_event_processor = Processor::builder("myprovider").build().unwrap();
let user_event_processor = Processor::builder(PROVIDER_NAME).build().unwrap();

SdkLoggerProvider::builder()
.with_resource(
Expand All @@ -81,7 +254,7 @@ fn setup_provider_with_callback<C>(event_name_callback: C) -> SdkLoggerProvider
where
C: EventNameCallback + 'static,
{
let user_event_processor = Processor::builder("myprovider")
let user_event_processor = Processor::builder(PROVIDER_NAME)
.with_event_name_callback(event_name_callback)
.build()
.unwrap();
Expand All @@ -97,7 +270,20 @@ where
}

fn benchmark_4_attributes(c: &mut Criterion) {
// Check if user events are available
if let Err(e) = UserEventsListenerGuard::check_user_events_available() {
eprintln!("Warning: User events not available: {}", e);
eprintln!("Benchmarks will run without listener enabled");
}

let provider = setup_provider_default();
// Enable listener with RAII guard (after provider is built so tracepoints exist)
let _guard = UserEventsListenerGuard::enable(PROVIDER_NAME).unwrap_or_else(|e| {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

this means the listener is always enabled when the benchmarks is run. What we really want is for the benchmark to run this with and without enabling the listener. A criterion bench group - like group.bench_function(enabled) and group.bench_function(disabled).

Copy link
Member

@lalitb lalitb Aug 13, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Oh yes, good find - seems I missed while reviewing.

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thank you for the excellent suggestion! You're absolutely right - the current approach always enables the listener, which doesn't provide meaningful performance comparison data.
I've restructured all benchmark functions to use criterion bench groups that run both with and without the listener enabled:
Each benchmark now creates a benchmark_group with "disabled" and "enabled" variants
The "disabled" case runs without any listener management (baseline performance)
The "enabled" case uses the RAII guard to enable/disable the listener
This provides proper comparison data showing the actual overhead of enabling user events
The changes maintain all the safety benefits (RAII guards, proper cleanup) while giving us the performance comparison we need. Users can now see the baseline performance vs. the overhead of having the listener active.
This addresses the core issue you identified - we now have proper benchmark data for both states rather than always running with the listener enabled.

eprintln!("Warning: Failed to enable listener: {}", e);
eprintln!("Benchmarks will run without listener enabled");
// Return a dummy guard that does nothing on drop
UserEventsListenerGuard::dummy_guard()
});
let ot_layer = tracing_layer::OpenTelemetryTracingBridge::new(&provider);
let subscriber = Registry::default().with(ot_layer);

Expand All @@ -119,7 +305,20 @@ fn benchmark_4_attributes(c: &mut Criterion) {

#[cfg(feature = "experimental_eventname_callback")]
fn benchmark_4_attributes_event_name_custom(c: &mut Criterion) {
// Check if user events are available
if let Err(e) = UserEventsListenerGuard::check_user_events_available() {
eprintln!("Warning: User events not available: {}", e);
eprintln!("Benchmarks will run without listener enabled");
}

let provider = setup_provider_with_callback(EventNameFromLogRecordCustom);
// Enable listener with RAII guard (after provider is built so tracepoints exist)
let _guard = UserEventsListenerGuard::enable(PROVIDER_NAME).unwrap_or_else(|e| {
eprintln!("Warning: Failed to enable listener: {}", e);
eprintln!("Benchmarks will run without listener enabled");
// Return a dummy guard that does nothing on drop
UserEventsListenerGuard::dummy_guard()
});
let ot_layer = tracing_layer::OpenTelemetryTracingBridge::new(&provider);
let subscriber = Registry::default().with(ot_layer);

Expand All @@ -141,7 +340,20 @@ fn benchmark_4_attributes_event_name_custom(c: &mut Criterion) {

#[cfg(feature = "experimental_eventname_callback")]
fn benchmark_4_attributes_event_name_from_log_record(c: &mut Criterion) {
// Check if user events are available
if let Err(e) = UserEventsListenerGuard::check_user_events_available() {
eprintln!("Warning: User events not available: {}", e);
eprintln!("Benchmarks will run without listener enabled");
}

let provider = setup_provider_with_callback(EventNameFromLogRecordEventName);
// Enable listener with RAII guard (after provider is built so tracepoints exist)
let _guard = UserEventsListenerGuard::enable(PROVIDER_NAME).unwrap_or_else(|e| {
eprintln!("Warning: Failed to enable listener: {}", e);
eprintln!("Benchmarks will run without listener enabled");
// Return a dummy guard that does nothing on drop
UserEventsListenerGuard::dummy_guard()
});
let ot_layer = tracing_layer::OpenTelemetryTracingBridge::new(&provider);
let subscriber = Registry::default().with(ot_layer);

Expand All @@ -162,7 +374,20 @@ fn benchmark_4_attributes_event_name_from_log_record(c: &mut Criterion) {
}

fn benchmark_6_attributes(c: &mut Criterion) {
// Check if user events are available
if let Err(e) = UserEventsListenerGuard::check_user_events_available() {
eprintln!("Warning: User events not available: {}", e);
eprintln!("Benchmarks will run without listener enabled");
}

let provider = setup_provider_default();
// Enable listener with RAII guard (after provider is built so tracepoints exist)
let _guard = UserEventsListenerGuard::enable(PROVIDER_NAME).unwrap_or_else(|e| {
eprintln!("Warning: Failed to enable listener: {}", e);
eprintln!("Benchmarks will run without listener enabled");
// Return a dummy guard that does nothing on drop
UserEventsListenerGuard::dummy_guard()
});
let ot_layer = tracing_layer::OpenTelemetryTracingBridge::new(&provider);
let subscriber = Registry::default().with(ot_layer);

Expand Down
Loading