more is working

src/lib.rs

@@ -1,4 +1,5 @@
 use std::{
+    collections::HashMap,
     sync::{atomic::AtomicU64, Mutex},
     time::Instant,
 };
@@ -7,13 +8,110 @@ mod perfetto {
     include!(concat!(env!("OUT_DIR"), "/perfetto.trace.rs"));
 }
 
+use perfetto::DebugAnnotation;
 use prost::Message;
-use tracing::{span, Subscriber};
+use tracing::{field::Visit, span, Dispatch, Level, Subscriber};
+
+pub fn install_perfetto_subscriber() {
+    let subscriber = PerfettoSubscriber::new();
+    let dispatcher = Dispatch::new(subscriber);
+    tracing::dispatcher::set_global_default(dispatcher).unwrap();
+}
 
 pub struct PerfettoSubscriber {
     id_counter: AtomicU64,
     start_time: Instant,
-    writer: Mutex<Vec<perfetto::TracePacket>>,
+    inner: Mutex<InnerPerfettoSubscriber>,
+}
+
+struct SpanInfo {
+    debug_annotations: Vec<DebugAnnotation>,
+    level: Level,
+    name: String,
+}
+
+struct InnerPerfettoSubscriber {
+    buffer: Vec<perfetto::TracePacket>,
+    spans: HashMap<u64, SpanInfo>,
+}
+
+impl InnerPerfettoSubscriber {
+    fn new(buffer: Vec<perfetto::TracePacket>) -> Self {
+        Self {
+            buffer,
+            spans: HashMap::new(),
+        }
+    }
+}
+
+struct DebugAnnotationVisitor {
+    data: Vec<DebugAnnotation>,
+}
+
+impl DebugAnnotationVisitor {
+    fn new() -> Self {
+        Self { data: Vec::new() }
+    }
+}
+
+impl Visit for DebugAnnotationVisitor {
+    fn record_debug(&mut self, field: &tracing::field::Field, value: &dyn std::fmt::Debug) {
+        self.data.push(DebugAnnotation {
+            name_field: Some(perfetto::debug_annotation::NameField::Name(
+                field.name().to_owned(),
+            )),
+            value: Some(perfetto::debug_annotation::Value::StringValue(format!(
+                "{value:?}"
+            ))),
+        });
+    }
+
+    fn record_i64(&mut self, field: &tracing::field::Field, value: i64) {
+        self.data.push(DebugAnnotation {
+            name_field: Some(perfetto::debug_annotation::NameField::Name(
+                field.name().to_owned(),
+            )),
+            value: Some(perfetto::debug_annotation::Value::IntValue(value)),
+        });
+    }
+
+    fn record_u64(&mut self, field: &tracing::field::Field, value: u64) {
+        self.data.push(DebugAnnotation {
+            name_field: Some(perfetto::debug_annotation::NameField::Name(
+                field.name().to_owned(),
+            )),
+            value: Some(perfetto::debug_annotation::Value::UintValue(value)),
+        });
+    }
+
+    fn record_f64(&mut self, field: &tracing::field::Field, value: f64) {
+        self.data.push(DebugAnnotation {
+            name_field: Some(perfetto::debug_annotation::NameField::Name(
+                field.name().to_owned(),
+            )),
+            value: Some(perfetto::debug_annotation::Value::DoubleValue(value)),
+        });
+    }
+
+    fn record_bool(&mut self, field: &tracing::field::Field, value: bool) {
+        self.data.push(DebugAnnotation {
+            name_field: Some(perfetto::debug_annotation::NameField::Name(
+                field.name().to_owned(),
+            )),
+            value: Some(perfetto::debug_annotation::Value::BoolValue(value)),
+        });
+    }
+
+    fn record_str(&mut self, field: &tracing::field::Field, value: &str) {
+        self.data.push(DebugAnnotation {
+            name_field: Some(perfetto::debug_annotation::NameField::Name(
+                field.name().to_owned(),
+            )),
+            value: Some(perfetto::debug_annotation::Value::StringValue(
+                value.to_owned(),
+            )),
+        });
+    }
 }
 
 impl PerfettoSubscriber {
@@ -62,16 +160,16 @@ impl PerfettoSubscriber {
         });
         Self {
             id_counter: AtomicU64::new(1),
-            writer: Mutex::new(packets),
+            inner: Mutex::new(InnerPerfettoSubscriber::new(packets)),
             start_time: Instant::now(),
         }
     }
 
     fn flush(&self) {
-        let mut data = self.writer.lock().unwrap();
+        let mut data = self.inner.lock().unwrap();
 
         let trace = perfetto::Trace {
-            packet: data.to_vec(),
+            packet: data.buffer.clone(),
         };
         let buf = trace.encode_to_vec();
 
@@ -85,37 +183,53 @@ impl Subscriber for PerfettoSubscriber {
     }
 
     fn new_span(&self, span: &span::Attributes<'_>) -> span::Id {
-        println!("new_span {:?}", span);
+        // println!("new_span {:?}", span);
         let id = self
             .id_counter
             .fetch_add(1, std::sync::atomic::Ordering::Relaxed);
 
+        let mut debug_annotations = DebugAnnotationVisitor::new();
+        span.record(&mut debug_annotations);
+
+        let mut inner = self.inner.lock().unwrap();
+        inner.spans.insert(
+            id,
+            SpanInfo {
+                debug_annotations: debug_annotations.data,
+                level: *span.metadata().level(),
+                name: span.metadata().name().to_owned(),
+            },
+        );
         span::Id::from_u64(id)
     }
 
     fn record(&self, span: &span::Id, values: &span::Record<'_>) {
-        println!("record {:?} {:?}", span, values);
+        // println!("record {:?} {:?}", span, values);
     }
 
     fn record_follows_from(&self, span: &span::Id, follows: &span::Id) {
-        println!("record_follows_from {:?} {:?}", span, follows);
+        // println!("record_follows_from {:?} {:?}", span, follows);
     }
 
     fn event(&self, event: &tracing::Event<'_>) {
-        println!("event {:?}", event);
+        // println!("event {:?}", event);
         {
             let time = self.start_time.elapsed().as_nanos() as u64;
-            let mut vec = self.writer.lock().unwrap();
+            let mut inner = self.inner.lock().unwrap();
 
-            vec.push(perfetto::TracePacket {
+            let mut debug_annotations = DebugAnnotationVisitor::new();
+            event.record(&mut debug_annotations);
+
+            inner.buffer.push(perfetto::TracePacket {
             timestamp: Some(time),
             data: Some(perfetto::trace_packet::Data::TrackEvent(
                 perfetto::TrackEvent {
                     track_uuid: Some(49083589894),
-                    categories: vec![],
+                    categories: vec![event.metadata().level().as_str().to_owned()],
                     category_iids: vec![],
-                    name_field: Some(perfetto::track_event::NameField::Name(String::from("Test"))),
+                    name_field: Some(perfetto::track_event::NameField::Name(String::from(event.metadata().name()))),
                     r#type: Some(perfetto::track_event::Type::Instant as i32),
+            debug_annotations: debug_annotations.data,
                 },
             )),
             optional_trusted_packet_sequence_id: Some(
@@ -129,20 +243,25 @@ impl Subscriber for PerfettoSubscriber {
     }
 
     fn enter(&self, span: &span::Id) {
-        println!("enter {:?}", span);
+        // println!("enter {:?}", span);
         {
             let time = self.start_time.elapsed().as_nanos() as u64;
-            let mut vec = self.writer.lock().unwrap();
+            let mut inner = self.inner.lock().unwrap();
 
-            vec.push(perfetto::TracePacket {
+            let debug_annotations = inner.spans[&span.into_u64()].debug_annotations.clone();
+            let level = inner.spans[&span.into_u64()].level;
+            let name = inner.spans[&span.into_u64()].name.clone();
+
+            inner.buffer.push(perfetto::TracePacket {
             timestamp: Some(time),
             data: Some(perfetto::trace_packet::Data::TrackEvent(
                 perfetto::TrackEvent {
                     track_uuid: Some(49083589894),
-                    categories: vec![],
+                    categories: vec![level.as_str().to_owned()],
                     category_iids: vec![],
-                    name_field: Some(perfetto::track_event::NameField::Name(String::from("Test"))),
+                    name_field: Some(perfetto::track_event::NameField::Name(name)),
                     r#type: Some(perfetto::track_event::Type::SliceBegin as i32),
+                    debug_annotations,
                 },
             )),
             optional_trusted_packet_sequence_id: Some(
@@ -156,20 +275,25 @@ impl Subscriber for PerfettoSubscriber {
     }
 
     fn exit(&self, span: &span::Id) {
-        println!("exit {:?}", span);
+        // println!("exit {:?}", span);
         {
             let time = self.start_time.elapsed().as_nanos() as u64;
-            let mut vec = self.writer.lock().unwrap();
+            let mut inner = self.inner.lock().unwrap();
 
-            vec.push(perfetto::TracePacket {
+            let debug_annotations = inner.spans[&span.into_u64()].debug_annotations.clone();
+            let level = inner.spans[&span.into_u64()].level;
+            let name = inner.spans[&span.into_u64()].name.clone();
+
+            inner.buffer.push(perfetto::TracePacket {
             timestamp: Some(time),
             data: Some(perfetto::trace_packet::Data::TrackEvent(
                 perfetto::TrackEvent {
                     track_uuid: Some(49083589894),
-                    categories: vec![],
+                    categories: vec![level.as_str().to_owned()],
                     category_iids: vec![],
-                    name_field: Some(perfetto::track_event::NameField::Name(String::from("Test"))),
+                    name_field: Some(perfetto::track_event::NameField::Name(name)),
                     r#type: Some(perfetto::track_event::Type::SliceEnd as i32),
+                    debug_annotations,
                 },
             )),
             optional_trusted_packet_sequence_id: Some(

src/main.rs

@@ -9,10 +9,12 @@ fn main() {
 
     let _outer_span = span!(Level::TRACE, "test").entered();
     sleep(std::time::Duration::from_millis(10));
-    {
+    for i in 0..3 {
-        let _inner_span = span!(Level::TRACE, "test1").entered();
+        let span = span!(Level::TRACE, "test1");
+        let _inner_span = span.enter();
+        let _inner_span2 = span.enter();
         sleep(std::time::Duration::from_millis(10));
-        trace!("event");
+        trace!(iteration = i);
 
         sleep(std::time::Duration::from_millis(10));
     }

src/trace.proto

@@ -42,6 +42,7 @@ message TrackEvent {
 
   optional uint64 track_uuid = 11;
 
+  repeated DebugAnnotation debug_annotations = 4;
 }
 
 // https://cs.android.com/android/platform/superproject/main/+/main:external/perfetto/protos/perfetto/trace/track_event/track_descriptor.proto
@@ -73,3 +74,23 @@ message ThreadDescriptor {
 
   optional string thread_name = 5;
 }
+
+
+// https://cs.android.com/android/platform/superproject/main/+/main:external/perfetto/protos/perfetto/trace/track_event/debug_annotation.proto
+message DebugAnnotation {
+  oneof name_field {
+    uint64 name_iid = 1;
+    string name = 10;
+  }
+
+  oneof value {
+    bool bool_value = 2;
+    uint64 uint_value = 3;
+    int64 int_value = 4;
+    double double_value = 5;
+    uint64 pointer_value = 7;
+
+    string string_value = 6;
+    uint64 string_value_iid = 17;
+  }
+}