From fa6da96f533010847fa99098e3214edd86078898 Mon Sep 17 00:00:00 2001 From: hal8174 Date: Sat, 15 Feb 2025 22:27:16 +0100 Subject: [PATCH] more is working --- src/lib.rs | 170 +++++++++++++++++++++++++++++++++++++++++------- src/main.rs | 8 ++- src/trace.proto | 21 ++++++ 3 files changed, 173 insertions(+), 26 deletions(-) diff --git a/src/lib.rs b/src/lib.rs index d486e9f..563fe8e 100644 --- a/src/lib.rs +++ b/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>, + inner: Mutex, +} + +struct SpanInfo { + debug_annotations: Vec, + level: Level, + name: String, +} + +struct InnerPerfettoSubscriber { + buffer: Vec, + spans: HashMap, +} + +impl InnerPerfettoSubscriber { + fn new(buffer: Vec) -> Self { + Self { + buffer, + spans: HashMap::new(), + } + } +} + +struct DebugAnnotationVisitor { + data: Vec, +} + +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( diff --git a/src/main.rs b/src/main.rs index 265ddb0..466e0eb 100644 --- a/src/main.rs +++ b/src/main.rs @@ -9,10 +9,12 @@ fn main() { let _outer_span = span!(Level::TRACE, "test").entered(); sleep(std::time::Duration::from_millis(10)); - { - let _inner_span = span!(Level::TRACE, "test1").entered(); + for i in 0..3 { + 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)); } diff --git a/src/trace.proto b/src/trace.proto index 2456b4d..bb661fc 100644 --- a/src/trace.proto +++ b/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; + } +}