feat: User_Events exporter - add support for serializing traceid and spanid (#198)

Author: cijothomas

opentelemetry-user-events-logs/CHANGELOG.md

@@ -10,6 +10,7 @@
   The provider name must:
   - Be less than 234 characters.
   - Contain only ASCII letters, digits, and the underscore (`'_'`) character.
+- Added support for TraceId,SpanId
 
 ## v0.10.0
 

opentelemetry-user-events-logs/Cargo.toml

@@ -21,6 +21,7 @@ futures-executor = "0.3"
 
 [dev-dependencies]
 opentelemetry-appender-tracing = { workspace = true }
+opentelemetry_sdk = { workspace = true, features = ["logs", "trace"] }
 tracing = { version = "0.1", default-features = false, features = ["std"] }
 tracing-core = "0.1.31"
 tracing-subscriber = { version = "0.3.0", default-features = false, features = ["env-filter", "fmt", "registry", "std"] }

opentelemetry-user-events-logs/src/lib.rs

@@ -11,8 +11,13 @@ pub use logs::*;
 mod tests {
 
     use super::*;
+    use opentelemetry::trace::Tracer;
+    use opentelemetry::trace::{TraceContextExt, TracerProvider};
     use opentelemetry_appender_tracing::layer;
-    use opentelemetry_sdk::logs::LoggerProviderBuilder;
+    use opentelemetry_sdk::{
+        logs::LoggerProviderBuilder,
+        trace::{Sampler, SdkTracerProvider},
+    };
     use serde_json::{from_str, Value};
     use std::process::Command;
     use tracing::error;
@@ -25,7 +30,7 @@ mod tests {
     #[test]
     fn integration_test_basic() {
         // Run using the below command
-        // sudo -E ~/.cargo/bin/cargo test integration -- --nocapture --ignored
+        // sudo -E ~/.cargo/bin/cargo test integration_test_basic -- --nocapture --ignored
 
         // Basic check if user_events are available
         check_user_events_available().expect("Kernel does not support user_events. Verify your distribution/kernel supports user_events: https://docs.kernel.org/trace/user_events.html.");
@@ -133,6 +138,143 @@ mod tests {
         );
     }
 
+    #[ignore]
+    #[test]
+    fn integration_test_with_tracing() {
+        // Run using the below command
+        // sudo -E ~/.cargo/bin/cargo test integration_test_with_tracing -- --nocapture --ignored
+
+        // Basic check if user_events are available
+        check_user_events_available().expect("Kernel does not support user_events. Verify your distribution/kernel supports user_events: https://docs.kernel.org/trace/user_events.html.");
+
+        // setup tracing
+        let tracer_provider = SdkTracerProvider::builder()
+            .with_sampler(Sampler::AlwaysOn)
+            .build();
+        let tracer = tracer_provider.tracer("test-tracer");
+
+        let logger_provider = LoggerProviderBuilder::default()
+            .with_user_event_exporter("myprovider")
+            .build();
+
+        // Once provider with user_event exporter is created, it should create the TracePoints
+        // following providername_level_k1 format
+        // Validate that the TracePoints are created.
+        let user_event_status = check_user_events_available().expect("Kernel does not support user_events. Verify your distribution/kernel supports user_events: https://docs.kernel.org/trace/user_events.html.");
+        assert!(user_event_status.contains("myprovider_L1K1"));
+        assert!(user_event_status.contains("myprovider_L2K1"));
+        assert!(user_event_status.contains("myprovider_L3K1"));
+        assert!(user_event_status.contains("myprovider_L4K1"));
+        assert!(user_event_status.contains("myprovider_L5K1"));
+
+        let filter_otel =
+            EnvFilter::new("info").add_directive("opentelemetry=off".parse().unwrap());
+        let otel_layer = layer::OpenTelemetryTracingBridge::new(&logger_provider);
+        let otel_layer = otel_layer.with_filter(filter_otel);
+        let subscriber = tracing_subscriber::registry().with(otel_layer);
+        let _guard = tracing::subscriber::set_default(subscriber);
+
+        // Start perf recording in a separate thread and emit logs in parallel.
+        let perf_thread =
+            std::thread::spawn(|| run_perf_and_decode(5, "user_events:myprovider_L2K1"));
+
+        // Give a little time for perf to start recording
+        std::thread::sleep(std::time::Duration::from_millis(1000));
+
+        // ACT
+        let (trace_id_expected, span_id_expected) = tracer.in_span("test-span", |cx| {
+            let trace_id = cx.span().span_context().trace_id();
+            let span_id = cx.span().span_context().span_id();
+
+            // logging is done inside span context.
+            error!(
+                name: "my-event-name",
+                target: "my-target",
+                event_id = 20,
+                user_name = "otel user",
+                user_email = "otel.user@opentelemetry.com"
+            );
+            (trace_id, span_id)
+        });
+
+        // Wait for the perf thread to complete and get the results
+        let result = perf_thread.join().expect("Perf thread panicked");
+
+        assert!(result.is_ok());
+        let json_content = result.unwrap();
+        assert!(!json_content.is_empty());
+
+        let formatted_output = json_content.trim().to_string();
+        /*
+                // Sample output from perf-decode
+                {
+        "./perf.data": [
+          { "n": "myprovider:my-event-name", "__csver__": 1024, "PartA": { "time": "2025-03-07T16:31:28.279214367+00:00" }, "PartC": { "user_name": "otel user", "user_email": "otel.user@opentelemetry.com" }, "PartB": { "_typeName": "Log", "severityNumber": 2, "severityText": "ERROR", "eventId": 20, "name": "my-event-name" }, "meta": { "time": 81252.403220286, "cpu": 4, "pid": 21084, "tid": 21085, "level": 2, "keyword": "0x1" } } ]
+        }
+                 */
+
+        let json_value: Value = from_str(&formatted_output).expect("Failed to parse JSON");
+        let perf_data_key = json_value
+            .as_object()
+            .expect("JSON is not an object")
+            .keys()
+            .find(|k| k.contains("perf.data"))
+            .expect("No perf.data key found in JSON");
+
+        let events = json_value[perf_data_key]
+            .as_array()
+            .expect("Events for perf.data is not an array");
+
+        // Find the specific event. Its named providername:eventname format.
+        let event = events
+            .iter()
+            .find(|e| {
+                if let Some(name) = e.get("n") {
+                    name.as_str().unwrap_or("") == "myprovider:my-event-name"
+                } else {
+                    false
+                }
+            })
+            .expect("Event 'myprovider:my-event-name' not found");
+
+        // Validate event structure and fields
+        assert_eq!(event["n"].as_str().unwrap(), "myprovider:my-event-name");
+        assert_eq!(event["__csver__"].as_i64().unwrap(), 1024);
+
+        // Validate PartA
+        let part_a = &event["PartA"];
+        // Only check if the time field exists, not the actual value
+        assert!(part_a.get("time").is_some(), "PartA.time is missing");
+
+        let part_a_ext_dt = part_a.get("ext_dt").expect("PartA.ext_dt is missing");
+
+        // Validate trace_id and span_id
+        assert_eq!(
+            part_a_ext_dt["traceId"].as_str().unwrap(),
+            format!("{:x}", trace_id_expected)
+        );
+        assert_eq!(
+            part_a_ext_dt["spanId"].as_str().unwrap(),
+            format!("{:x}", span_id_expected)
+        );
+
+        // Validate PartB
+        let part_b = &event["PartB"];
+        assert_eq!(part_b["_typeName"].as_str().unwrap(), "Log");
+        assert_eq!(part_b["severityNumber"].as_i64().unwrap(), 2);
+        assert_eq!(part_b["severityText"].as_str().unwrap(), "ERROR");
+        assert_eq!(part_b["eventId"].as_i64().unwrap(), 20);
+        assert_eq!(part_b["name"].as_str().unwrap(), "my-event-name");
+
+        // Validate PartC
+        let part_c = &event["PartC"];
+        assert_eq!(part_c["user_name"].as_str().unwrap(), "otel user");
+        assert_eq!(
+            part_c["user_email"].as_str().unwrap(),
+            "otel.user@opentelemetry.com"
+        );
+    }
+
     fn check_user_events_available() -> Result<String, String> {
         let output = Command::new("sudo")
             .arg("cat")

opentelemetry-user-events-logs/src/logs/exporter.rs

@@ -193,14 +193,24 @@ impl UserEventsExporter {
                     .timestamp()
                     .or(log_record.observed_timestamp())
                     .unwrap_or_else(SystemTime::now);
+                let time: String = chrono::DateTime::to_rfc3339(
+                    &chrono::DateTime::<chrono::Utc>::from(event_time),
+                );
                 cs_a_count += 1; // for event_time
-                eb.add_struct("PartA", cs_a_count, 0);
-                {
-                    let time: String = chrono::DateTime::to_rfc3339(
-                        &chrono::DateTime::<chrono::Utc>::from(event_time),
-                    );
-                    eb.add_str("time", time, FieldFormat::Default, 0);
+
+                if let Some(trace_context) = log_record.trace_context() {
+                    cs_a_count += 1; // for ext_dt
+                    eb.add_struct("PartA", cs_a_count, 0);
+                    eb.add_struct("ext_dt", 2, 0);
+                    eb.add_str("traceId", trace_context.trace_id.to_string(), FieldFormat::Default, 0);
+                    eb.add_str("spanId", trace_context.span_id.to_string(), FieldFormat::Default, 0);
+                }
+                else {
+                    eb.add_struct("PartA", cs_a_count, 0);
                 }
+
+                eb.add_str("time", time, FieldFormat::Default, 0);
+
                 //populate CS PartC
                 let (mut is_event_id, mut event_id) = (false, 0);
                 let (mut is_part_c_present, mut cs_c_bookmark, mut cs_c_count) = (false, 0, 0);