diff --git a/CHANGELOG.md b/CHANGELOG.md index b42887c1..623ee2f1 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -8,6 +8,9 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ## [Unreleased] - ReleaseDate + +- [PR#169](https://github.com/EmbarkStudios/puffin/pull/169) Stream scope information only once. Breaking change! See PR for migration guide. + ## [0.18.1] - 2023-12-11 - [PR#175](https://github.com/EmbarkStudios/puffin/pull/175) Remove accidental `::{{closure}}` suffix from all `profile_function` scopes. diff --git a/puffin/Cargo.toml b/puffin/Cargo.toml index 148a6650..acc4b6cf 100644 --- a/puffin/Cargo.toml +++ b/puffin/Cargo.toml @@ -18,7 +18,7 @@ all-features = true [features] default = [] -packing = ["dep:bincode", "dep:parking_lot", "lz4", "serde"] +packing = ["dep:bincode", "lz4", "serde"] # Support lz4 compression. Fast, and lightweight dependency. # If both `lz4` and `zstd` are enabled, lz4 will be used for compression. @@ -38,12 +38,12 @@ web = ["dep:js-sys", "dep:web-time"] byteorder = { version = "1.0" } cfg-if = "1.0" once_cell = "1.0" +parking_lot = { version = "0.12"} # Optional: anyhow = { version = "1.0" } bincode = { version = "1.3", optional = true } lz4_flex = { version = "0.11", optional = true, default-features = false } -parking_lot = { version = "0.12", optional = true } serde = { version = "1.0", features = ["derive", "rc"], optional = true } [target.'cfg(not(target_arch = "wasm32"))'.dependencies] diff --git a/puffin/src/data.rs b/puffin/src/data.rs index 9de6ba11..6e6d3bf6 100644 --- a/puffin/src/data.rs +++ b/puffin/src/data.rs @@ -6,9 +6,8 @@ //! //! ```ignore //! '(' byte Sentinel +//! scope id u32 Unique monolithic identifier for a scope //! time_ns i64 Time stamp of when scope started -//! id str Scope name. Human readable, e.g. a function name. Never the empty string. -//! location str File name or similar. Could be the empty string. //! data str Resource that is being processed, e.g. name of image being loaded. Could be the empty string. //! scope_size u64 Number of bytes of child scope //! ``` @@ -26,6 +25,7 @@ //! At the moment strings may be at most 127 bytes long. use super::*; +use anyhow::Context; use byteorder::{LittleEndian as LE, ReadBytesExt, WriteBytesExt}; use std::mem::size_of; @@ -60,19 +60,11 @@ pub type Result = std::result::Result; impl Stream { /// Returns position where to write scope size once the scope is closed #[inline] - pub fn begin_scope( - &mut self, - start_ns: NanoSecond, - id: &str, - location: &str, - data: &str, - ) -> usize { + pub fn begin_scope(&mut self, start_ns: NanoSecond, scope_id: ScopeId, data: &str) -> usize { self.0.push(SCOPE_BEGIN); + self.write_scope_id(scope_id); self.0.write_i64::(start_ns).expect("can't fail"); - self.write_str(id); - self.write_str(location); self.write_str(data); - // Put place-holder value for total scope size. let offset = self.0.len(); self.write_scope_size(ScopeSize::unfinished()); @@ -105,6 +97,14 @@ impl Stream { self.0.write_u64::(nanos.0).expect("can't fail"); } + #[inline] + fn write_scope_id(&mut self, scope_id: ScopeId) { + // Could potentially use varint encoding. + self.0 + .write_u32::(scope_id.0.get()) + .expect("can't fail"); + } + #[inline] fn write_str(&mut self, s: &str) { // Future-proof: we may want to use VLQs later. @@ -143,14 +143,11 @@ impl<'s> Reader<'s> { self.parse_u8() .expect("swallowing already peeked SCOPE_BEGIN"); } - Some(_) | None => { - return Ok(None); - } + Some(_) | None => return Ok(None), } + let scope_id = self.parse_scope_id()?; let start_ns = self.parse_nanos()?; - let id = self.parse_string()?; - let location = self.parse_string()?; let data = self.parse_string()?; let scope_size = self.parse_scope_size()?; if scope_size == ScopeSize::unfinished() { @@ -169,11 +166,10 @@ impl<'s> Reader<'s> { } Ok(Some(Scope { - record: Record { + id: scope_id, + record: ScopeRecord { start_ns, duration_ns: stop_ns - start_ns, - id, - location, data, }, child_begin_position, @@ -203,6 +199,15 @@ impl<'s> Reader<'s> { self.0.read_u8().map_err(|_err| Error::PrematureEnd) } + fn parse_scope_id(&mut self) -> Result { + self.0 + .read_u32::() + .context("Can not parse scope id") + .and_then(|x| NonZeroU32::new(x).context("Not a `NonZeroU32` scope id")) + .map(ScopeId) + .map_err(|_err| Error::PrematureEnd) + } + fn parse_nanos(&mut self) -> Result { self.0.read_i64::().map_err(|_err| Error::PrematureEnd) } @@ -281,14 +286,33 @@ impl<'s> Iterator for Reader<'s> { // ---------------------------------------------------------------------------- +#[test] +fn write_scope() { + let mut stream: Stream = Stream::default(); + let start = stream.begin_scope(100, ScopeId::new(1), "data"); + stream.end_scope(start, 300); + + let scopes = Reader::from_start(&stream).read_top_scopes().unwrap(); + assert_eq!(scopes.len(), 1); + assert_eq!( + scopes[0].record, + ScopeRecord { + start_ns: 100, + duration_ns: 200, + data: "data" + } + ); +} + #[test] fn test_profile_data() { let stream = { let mut stream = Stream::default(); - let t0 = stream.begin_scope(100, "top", "top.rs", "data_top"); - let m1 = stream.begin_scope(200, "middle_0", "middle.rs", "data_middle_0"); + + let t0 = stream.begin_scope(100, ScopeId::new(1), "data_top"); + let m1 = stream.begin_scope(200, ScopeId::new(2), "data_middle_0"); stream.end_scope(m1, 300); - let m1 = stream.begin_scope(300, "middle_1", "middle.rs:42", "data_middle_1"); + let m1 = stream.begin_scope(300, ScopeId::new(3), "data_middle_1"); stream.end_scope(m1, 400); stream.end_scope(t0, 400); stream @@ -296,46 +320,36 @@ fn test_profile_data() { let top_scopes = Reader::from_start(&stream).read_top_scopes().unwrap(); assert_eq!(top_scopes.len(), 1); - let middle_scopes = Reader::with_offset(&stream, top_scopes[0].child_begin_position) - .unwrap() - .read_top_scopes() - .unwrap(); - assert_eq!( top_scopes[0].record, - Record { + ScopeRecord { start_ns: 100, duration_ns: 300, - id: "top", - location: "top.rs", - data: "data_top", + data: "data_top" } ); - assert_eq!( - top_scopes[0].next_sibling_position, - stream.len() as u64, - "Top scope has no siblings" - ); + + let middle_scopes = Reader::with_offset(&stream, top_scopes[0].child_begin_position) + .unwrap() + .read_top_scopes() + .unwrap(); assert_eq!(middle_scopes.len(), 2); + assert_eq!( middle_scopes[0].record, - Record { + ScopeRecord { start_ns: 200, duration_ns: 100, - id: "middle_0", - location: "middle.rs", - data: "data_middle_0", + data: "data_middle_0" } ); assert_eq!( middle_scopes[1].record, - Record { + ScopeRecord { start_ns: 300, duration_ns: 100, - id: "middle_1", - location: "middle.rs:42", - data: "data_middle_1", + data: "data_middle_1" } ); } diff --git a/puffin/src/frame_data.rs b/puffin/src/frame_data.rs index df7af418..58be9e2e 100644 --- a/puffin/src/frame_data.rs +++ b/puffin/src/frame_data.rs @@ -1,5 +1,5 @@ +use crate::ScopeDetails; use crate::{Error, FrameIndex, NanoSecond, Result, StreamInfo, ThreadInfo}; - #[cfg(feature = "packing")] use parking_lot::RwLock; @@ -95,6 +95,11 @@ impl UnpackedFrameData { #[cfg(not(feature = "packing"))] pub struct FrameData { unpacked_frame: Arc, + /// Scopes that were registered during this frame. + pub scope_delta: Vec>, + /// Does [`Self::scope_delta`] contain all the scopes up to this point? + /// If `false`, it just contains the new scopes since last frame data. + pub full_delta: bool, } #[cfg(not(feature = "packing"))] @@ -105,15 +110,26 @@ impl FrameData { pub fn new( frame_index: FrameIndex, thread_streams: BTreeMap, + scope_delta: Vec>, + full_delta: bool, ) -> Result { - Ok(Self::from_unpacked(Arc::new(UnpackedFrameData::new( - frame_index, - thread_streams, - )?))) - } - - fn from_unpacked(unpacked_frame: Arc) -> Self { - Self { unpacked_frame } + Ok(Self::from_unpacked( + Arc::new(UnpackedFrameData::new(frame_index, thread_streams)?), + scope_delta, + full_delta, + )) + } + + fn from_unpacked( + unpacked_frame: Arc, + scope_delta: Vec>, + full_delta: bool, + ) -> Self { + Self { + unpacked_frame, + scope_delta, + full_delta, + } } #[inline] @@ -290,6 +306,13 @@ pub struct FrameData { /// [`UnpackedFrameData::thread_streams`], compressed. /// [`None`] if not yet compressed. packed_streams: RwLock>, + + /// Scopes that were registered during this frame. + pub scope_delta: Vec>, + + /// Does [`Self::scope_delta`] contain all the scopes up to this point? + /// If `false`, it just contains the new scopes since last frame data. + pub full_delta: bool, } #[cfg(feature = "packing")] @@ -297,18 +320,27 @@ impl FrameData { pub fn new( frame_index: FrameIndex, thread_streams: BTreeMap, + scope_delta: Vec>, + full_delta: bool, ) -> Result { - Ok(Self::from_unpacked(Arc::new(UnpackedFrameData::new( - frame_index, - thread_streams, - )?))) - } - - fn from_unpacked(unpacked_frame: Arc) -> Self { + Ok(Self::from_unpacked( + Arc::new(UnpackedFrameData::new(frame_index, thread_streams)?), + scope_delta, + full_delta, + )) + } + + fn from_unpacked( + unpacked_frame: Arc, + scope_delta: Vec>, + full_delta: bool, + ) -> Self { Self { meta: unpacked_frame.meta.clone(), unpacked_frame: RwLock::new(Some(Ok(unpacked_frame))), packed_streams: RwLock::new(None), + scope_delta, + full_delta, } } @@ -411,12 +443,18 @@ impl FrameData { /// Writes one [`FrameData`] into a stream, prefixed by its length ([`u32`] le). #[cfg(not(target_arch = "wasm32"))] // compression not supported on wasm #[cfg(feature = "serialization")] - pub fn write_into(&self, write: &mut impl std::io::Write) -> anyhow::Result<()> { + pub fn write_into( + &self, + scope_collection: &crate::ScopeCollection, + send_all_scopes: bool, + write: &mut impl std::io::Write, + ) -> anyhow::Result<()> { use bincode::Options as _; - use byteorder::WriteBytesExt as _; + use byteorder::{WriteBytesExt as _, LE}; + let meta_serialized = bincode::options().serialize(&self.meta)?; - write.write_all(b"PFD3")?; + write.write_all(b"PFD4")?; write.write_all(&(meta_serialized.len() as u32).to_le_bytes())?; write.write_all(&meta_serialized)?; @@ -428,6 +466,15 @@ impl FrameData { write.write_u8(packed_streams.compression_kind as u8)?; write.write_all(&packed_streams.bytes)?; + let to_serialize_scopes: Vec<_> = if send_all_scopes { + scope_collection.scopes_by_id().values().cloned().collect() + } else { + self.scope_delta.clone() + }; + + let serialized_scopes = bincode::options().serialize(&to_serialize_scopes)?; + write.write_u32::(serialized_scopes.len() as u32)?; + write.write_all(&serialized_scopes)?; Ok(()) } @@ -439,7 +486,7 @@ impl FrameData { pub fn read_next(read: &mut impl std::io::Read) -> anyhow::Result> { use anyhow::Context as _; use bincode::Options as _; - use byteorder::ReadBytesExt; + use byteorder::{ReadBytesExt, LE}; let mut header = [0_u8; 4]; if let Err(err) = read.read_exact(&mut header) { @@ -480,7 +527,11 @@ impl FrameData { } fn into_frame_data(self) -> FrameData { - FrameData::from_unpacked(Arc::new(self.into_unpacked_frame_data())) + FrameData::from_unpacked( + Arc::new(self.into_unpacked_frame_data()), + Default::default(), + false, + ) } } @@ -540,6 +591,8 @@ impl FrameData { meta, unpacked_frame: RwLock::new(None), packed_streams: RwLock::new(Some(packed_streams)), + scope_delta: Default::default(), + full_delta: false, })) } else if &header == b"PFD3" { // Added 2023-05-13: CompressionKind field @@ -570,6 +623,48 @@ impl FrameData { meta, unpacked_frame: RwLock::new(None), packed_streams: RwLock::new(Some(packed_streams)), + scope_delta: Default::default(), + full_delta: false, + })) + } else if &header == b"PFD4" { + // Added 2024-01-08: Split up stream scope details from the record stream. + let meta_length = read.read_u32::()? as usize; + let meta = { + let mut meta = vec![0_u8; meta_length]; + read.read_exact(&mut meta)?; + bincode::options() + .deserialize(&meta) + .context("bincode deserialize")? + }; + + let streams_compressed_length = read.read_u32::()? as usize; + let compression_kind = CompressionKind::from_u8(read.read_u8()?)?; + let streams_compressed = { + let mut streams_compressed = vec![0_u8; streams_compressed_length]; + read.read_exact(&mut streams_compressed)?; + PackedStreams::new(compression_kind, streams_compressed) + }; + + let serialized_scope_len = read.read_u32::()?; + let deserialized_scopes: Vec = { + let mut serialized_scopes = vec![0; serialized_scope_len as usize]; + read.read_exact(&mut serialized_scopes)?; + bincode::options() + .deserialize_from(serialized_scopes.as_slice()) + .context("Can not deserialize scope details")? + }; + + let new_scopes: Vec<_> = deserialized_scopes + .into_iter() + .map(|x| Arc::new(x.clone())) + .collect(); + + Ok(Some(Self { + meta, + unpacked_frame: RwLock::new(None), + packed_streams: RwLock::new(Some(streams_compressed)), + scope_delta: new_scopes, + full_delta: false, })) } else { anyhow::bail!("Failed to decode: this data is newer than this reader. Please update your puffin version!"); diff --git a/puffin/src/lib.rs b/puffin/src/lib.rs index 5e016a2a..fba67d35 100644 --- a/puffin/src/lib.rs +++ b/puffin/src/lib.rs @@ -105,13 +105,17 @@ mod data; mod frame_data; mod merge; mod profile_view; +mod scope_details; pub use data::*; pub use frame_data::{FrameData, FrameMeta, UnpackedFrameData}; pub use merge::*; +use once_cell::sync::Lazy; pub use profile_view::{select_slowest, FrameView, GlobalFrameView}; - +pub use scope_details::{ScopeCollection, ScopeDetails, ScopeType}; +use std::borrow::Cow; use std::collections::BTreeMap; +use std::num::NonZeroU32; use std::sync::{ atomic::{AtomicBool, Ordering}, Arc, @@ -174,25 +178,15 @@ impl From> for Stream { /// Used when parsing a Stream. #[derive(Clone, Copy, Debug, PartialEq, Eq)] -pub struct Record<'s> { +pub struct ScopeRecord<'s> { pub start_ns: NanoSecond, pub duration_ns: NanoSecond, - - /// e.g. function name. Mandatory. Used to identify records. - /// Does not need to be globally unique, just unique in the parent scope. - /// Example: "load_image" - pub id: &'s str, - - /// e.g. file name. Optional. Used for finding the location of the profiler scope. - /// Example: "my_library/image_loader.rs:52" - pub location: &'s str, - /// e.g. function argument, like a mesh name. Optional. /// Example: "image.png". pub data: &'s str, } -impl<'s> Record<'s> { +impl<'s> ScopeRecord<'s> { #[inline] pub fn stop_ns(&self) -> NanoSecond { self.start_ns + self.duration_ns @@ -202,7 +196,11 @@ impl<'s> Record<'s> { /// Used when parsing a Stream. #[derive(Clone, Copy, Debug, PartialEq, Eq)] pub struct Scope<'s> { - pub record: Record<'s>, + // Unique identifier for the profile scope. + // More detailed scope information can be requested via [`FrameView::scope_collection()`]. + pub id: ScopeId, + // Some dynamic data that is passed into the profiler scope. + pub record: ScopeRecord<'s>, /// Stream offset for first child. pub child_begin_position: u64, /// Stream offset after last child. @@ -336,16 +334,25 @@ pub struct StreamInfoRef<'a> { // ---------------------------------------------------------------------------- type NsSource = fn() -> NanoSecond; -type ThreadReporter = fn(ThreadInfo, &StreamInfoRef<'_>); + +// Function interface for reporting thread local scope details. +// The scope details array will contain information about a scope the first time it is seen. +// The stream will always contain the scope timing details. +type ThreadReporter = fn(ThreadInfo, &[ScopeDetails], &StreamInfoRef<'_>); /// Report a stream of profile data from a thread to the [`GlobalProfiler`] singleton. -pub fn global_reporter(info: ThreadInfo, stream_info: &StreamInfoRef<'_>) { - GlobalProfiler::lock().report(info, stream_info); +/// This is used for internal purposes only +pub(crate) fn internal_profile_reporter( + info: ThreadInfo, + scope_details: &[ScopeDetails], + stream_scope_times: &StreamInfoRef<'_>, +) { + GlobalProfiler::lock().report(info, scope_details, stream_scope_times); } - /// Collects profiling data for one thread pub struct ThreadProfiler { stream_info: StreamInfo, + scope_details: Vec, /// Current depth. depth: usize, now_ns: NsSource, @@ -357,9 +364,10 @@ impl Default for ThreadProfiler { fn default() -> Self { Self { stream_info: Default::default(), + scope_details: Default::default(), depth: 0, now_ns: crate::now_ns, - reporter: global_reporter, + reporter: internal_profile_reporter, start_time_ns: None, } } @@ -369,10 +377,10 @@ impl ThreadProfiler { /// Explicit initialize with custom callbacks. /// /// If not called, each thread will use the default nanosecond source ([`now_ns()`]) - /// and report scopes to the global profiler ([`global_reporter()`]). + /// and report scopes to the global profiler ([`internal_profile_reporter()`]). /// /// For instance, when compiling for WASM the default timing function ([`now_ns()`]) won't work, - /// so you'll want to call `puffin::ThreadProfiler::initialize(my_timing_function, puffin::global_reporter);`. + /// so you'll want to call `puffin::ThreadProfiler::initialize(my_timing_function, internal_profile_reporter);`. pub fn initialize(now_ns: NsSource, reporter: ThreadReporter) { ThreadProfiler::call(|tp| { tp.now_ns = now_ns; @@ -380,18 +388,52 @@ impl ThreadProfiler { }); } + #[must_use] + pub fn register_function_scope( + &mut self, + function_name: impl Into>, + file_path: impl Into>, + line_nr: u32, + ) -> ScopeId { + let new_id = fetch_add_scope_id(); + self.scope_details.push( + ScopeDetails::from_scope_id(new_id) + .with_function_name(function_name) + .with_file(file_path) + .with_line_nr(line_nr), + ); + new_id + } + + #[must_use] + pub fn register_scope( + &mut self, + scope_name: impl Into>, + function_name: impl Into>, + file_path: impl Into>, + line_nr: u32, + ) -> ScopeId { + let new_id = fetch_add_scope_id(); + self.scope_details.push( + ScopeDetails::from_scope_id(new_id) + .with_scope_name(scope_name) + .with_function_name(function_name) + .with_file(file_path) + .with_line_nr(line_nr), + ); + new_id + } + /// Returns position where to write scope size once the scope is closed. #[must_use] - pub fn begin_scope(&mut self, id: &str, location: &str, data: &str) -> usize { + pub fn begin_scope(&mut self, scope_id: ScopeId, data: &str) -> usize { let now_ns = (self.now_ns)(); self.start_time_ns = Some(self.start_time_ns.unwrap_or(now_ns)); self.depth += 1; self.stream_info.range_ns.0 = self.stream_info.range_ns.0.min(now_ns); - self.stream_info - .stream - .begin_scope(now_ns, id, location, data) + self.stream_info.stream.begin_scope(now_ns, scope_id, data) } pub fn end_scope(&mut self, start_offset: usize) { @@ -415,7 +457,13 @@ impl ThreadProfiler { start_time_ns: self.start_time_ns, name: std::thread::current().name().unwrap_or_default().to_owned(), }; - (self.reporter)(info, &self.stream_info.as_stream_into_ref()); + (self.reporter)( + info, + &self.scope_details, + &self.stream_info.as_stream_into_ref(), + ); + + self.scope_details.clear(); self.stream_info.clear(); } } @@ -430,6 +478,17 @@ impl ThreadProfiler { } } +/// Incremental monolithic counter to identify scopes. +static SCOPE_ID_TRACKER: std::sync::atomic::AtomicU32 = std::sync::atomic::AtomicU32::new(1); + +fn fetch_add_scope_id() -> ScopeId { + let new_id = SCOPE_ID_TRACKER.fetch_add(1, std::sync::atomic::Ordering::Relaxed); + ScopeId( + NonZeroU32::new(new_id) + .expect("safe because integer is retrieved from fetch-add atomic operation"), + ) +} + // ---------------------------------------------------------------------------- /// Add these to [`GlobalProfiler`] with [`GlobalProfiler::add_sink()`]. @@ -447,6 +506,13 @@ pub struct GlobalProfiler { next_sink_id: FrameSinkId, sinks: std::collections::HashMap, + // When true will propagate a full snapshot from `scope_collection` to every sink. + propagate_all_scope_details: bool, + // The new scopes' details, or also the first time macro or external library detected a scope. + new_scopes: Vec>, + // Store an absolute collection of scope details such that sinks can request a total state by setting `propagate_all_scope_details`. + // This should not be mutable accessible to external applications as frame views store there own copy. + scope_collection: ScopeCollection, } impl Default for GlobalProfiler { @@ -456,6 +522,9 @@ impl Default for GlobalProfiler { current_frame: Default::default(), next_sink_id: FrameSinkId(1), sinks: Default::default(), + propagate_all_scope_details: Default::default(), + new_scopes: Default::default(), + scope_collection: Default::default(), } } } @@ -473,7 +542,6 @@ impl GlobalProfiler { /// Access to the global profiler singleton. #[cfg(not(feature = "parking_lot"))] pub fn lock() -> std::sync::MutexGuard<'static, Self> { - use once_cell::sync::Lazy; static GLOBAL_PROFILER: Lazy> = Lazy::new(Default::default); GLOBAL_PROFILER.lock().expect("poisoned mutex") @@ -489,34 +557,102 @@ impl GlobalProfiler { let current_frame_index = self.current_frame_index; self.current_frame_index += 1; - let new_frame = - match FrameData::new(current_frame_index, std::mem::take(&mut self.current_frame)) { - Ok(new_frame) => Arc::new(new_frame), - Err(Error::Empty) => { - return; // don't warn about empty frames, just ignore them - } - Err(err) => { - eprintln!("puffin ERROR: Bad frame: {err:?}"); - return; - } - }; + let mut scope_deltas = Vec::with_capacity(self.new_scopes.len()); + + // Firstly add the new registered scopes. + for scope_detail in self.new_scopes.drain(..) { + scope_deltas.push(scope_detail); + } + + let current_frame_scope = std::mem::take(&mut self.current_frame); + + // Secondly add a full snapshot of all scopes if requested. + // Could potentially do this per sink. + let propagate_full_delta = std::mem::take(&mut self.propagate_all_scope_details); + + if propagate_full_delta { + scope_deltas.extend(self.scope_collection.scopes_by_id().values().cloned()); + } + + let new_frame = match FrameData::new( + current_frame_index, + current_frame_scope, + scope_deltas, + propagate_full_delta, + ) { + Ok(new_frame) => Arc::new(new_frame), + Err(Error::Empty) => { + return; // don't warn about empty frames, just ignore them + } + Err(err) => { + eprintln!("puffin ERROR: Bad frame: {err:?}"); + return; + } + }; self.add_frame(new_frame); } /// Manually add frame data. pub fn add_frame(&mut self, new_frame: Arc) { + for delta in &new_frame.scope_delta { + self.scope_collection.insert(delta.clone()); + } + for sink in self.sinks.values() { sink(new_frame.clone()); } } - /// Report some profiling data. Called from [`ThreadProfiler`]. - pub fn report(&mut self, info: ThreadInfo, stream_info: &StreamInfoRef<'_>) { + /// Inserts user scopes into puffin. + /// Returns the scope id for every inserted scope in the same order as input slice. + /// + /// Scopes details should only be registered once for each scope and need be inserted before being reported to puffin. + /// This function is relevant when you're registering measurement not performed using the puffin profiler macros. + /// Scope id is always supposed to be `None` as it will be set by puffin. + pub fn register_user_scopes(&mut self, scopes: &[ScopeDetails]) -> Vec { + let mut new_scopes = Vec::with_capacity(scopes.len()); + for scope_detail in scopes { + let new_scope_id = fetch_add_scope_id(); + let scope = self.scope_collection.insert(Arc::new( + (*scope_detail).clone().with_scope_id(new_scope_id), + )); + new_scopes.push(scope); + } + let new_scope_ids = new_scopes.iter().filter_map(|x| x.scope_id).collect(); + self.new_scopes.extend(new_scopes); + new_scope_ids + } + + /// Reports some profiling data. Called from [`ThreadProfiler`]. + pub(crate) fn report( + &mut self, + info: ThreadInfo, + scope_details: &[ScopeDetails], + stream_scope_times: &StreamInfoRef<'_>, + ) { + if !scope_details.is_empty() { + // Here we can run slightly heavy logic as its only ran once for each scope. + self.new_scopes.extend( + scope_details + .iter() + .map(|x| Arc::new(x.clone().into_readable().clone())), + ); + } + self.current_frame .entry(info) .or_default() - .extend(stream_info); + .extend(stream_scope_times); + } + + /// Reports user scopes to puffin profiler. + /// Every scope reported should first be registered by [`Self::register_user_scopes`]. + pub fn report_user_scopes(&mut self, info: ThreadInfo, stream_scope_times: &StreamInfoRef<'_>) { + self.current_frame + .entry(info) + .or_default() + .extend(stream_scope_times); } /// Tells [`GlobalProfiler`] to call this function with each new finished frame. @@ -532,6 +668,12 @@ impl GlobalProfiler { pub fn remove_sink(&mut self, id: FrameSinkId) -> Option { self.sinks.remove(&id) } + + /// Sends a snapshot of all scopes to all sinks via the frame data. + /// This is useful for if a sink is initialized after scopes are registered. + pub fn emit_scope_snapshot(&mut self) { + self.propagate_all_scope_details = true; + } } // ---------------------------------------------------------------------------- @@ -561,8 +703,6 @@ pub fn now_ns() -> NanoSecond { #[cfg(target_arch = "wasm32")] use web_time::Instant; - use once_cell::sync::Lazy; - static START_TIME: Lazy<(NanoSecond, Instant)> = Lazy::new(|| (nanos_since_epoch(), Instant::now())); START_TIME.0 + START_TIME.1.elapsed().as_nanos() as NanoSecond @@ -591,15 +731,12 @@ pub struct ProfilerScope { } impl ProfilerScope { - /// The `id` doesn't need to be static, but it should be unchanging, - /// and this is a good way to enforce it. + /// The scope id identifies which scopes' time is being reported. /// `data` can be changing, i.e. a name of a mesh or a texture. #[inline] - pub fn new(id: &'static str, location: &str, data: impl AsRef) -> Self { + pub fn new(scope_id: ScopeId, data: impl AsRef) -> Self { Self { - start_stream_offset: ThreadProfiler::call(|tp| { - tp.begin_scope(id, location, data.as_ref()) - }), + start_stream_offset: ThreadProfiler::call(|tp| tp.begin_scope(scope_id, data.as_ref())), _dont_send_me: Default::default(), } } @@ -612,6 +749,21 @@ impl Drop for ProfilerScope { } } +/// A unique id for each scope and [`ScopeDetails`]. +#[derive(Copy, Clone, Debug, PartialEq, Eq, Hash, PartialOrd, Ord)] +#[cfg_attr( + feature = "serialization", + derive(serde::Serialize, serde::Deserialize) +)] +pub struct ScopeId(pub NonZeroU32); + +impl ScopeId { + #[cfg(test)] + pub(crate) fn new(id: u32) -> Self { + ScopeId(NonZeroU32::new(id).expect("Scope id was not non-zero u32")) + } +} + #[doc(hidden)] #[inline(always)] pub fn type_name_of(_: T) -> &'static str { @@ -619,21 +771,22 @@ pub fn type_name_of(_: T) -> &'static str { } /// Returns the name of the calling function without a long module path prefix. -#[doc(hidden)] #[macro_export] macro_rules! current_function_name { () => {{ fn f() {} - let name = $crate::type_name_of(f); - // Remove "::f" from the name: - let name = &name.get(..name.len() - 3).unwrap(); - $crate::clean_function_name(name) + $crate::type_name_of(f) }}; } #[doc(hidden)] #[inline(never)] -pub fn clean_function_name(name: &'static str) -> String { +pub fn clean_function_name(name: &str) -> String { + let Some(name) = name.strip_suffix(USELESS_SCOPE_NAME_SUFFIX) else { + // Probably the user registered a user scope name. + return name.to_owned(); + }; + // "foo::bar::baz" -> "baz" fn last_part(name: &str) -> &str { if let Some(colon) = name.rfind("::") { @@ -680,33 +833,44 @@ pub fn clean_function_name(name: &'static str) -> String { #[test] fn test_clean_function_name() { assert_eq!(clean_function_name(""), ""); - assert_eq!(clean_function_name("foo"), "foo"); - assert_eq!(clean_function_name("foo::bar"), "foo::bar"); - assert_eq!(clean_function_name("foo::bar::baz"), "bar::baz"); assert_eq!( - clean_function_name("some::GenericThing<_, _>::function_name"), + clean_function_name(&format!("foo{}", USELESS_SCOPE_NAME_SUFFIX)), + "foo" + ); + assert_eq!( + clean_function_name(&format!("foo::bar{}", USELESS_SCOPE_NAME_SUFFIX)), + "foo::bar" + ); + assert_eq!( + clean_function_name(&format!("foo::bar::baz{}", USELESS_SCOPE_NAME_SUFFIX)), + "bar::baz" + ); + assert_eq!( + clean_function_name(&format!( + "some::GenericThing<_, _>::function_name{}", + USELESS_SCOPE_NAME_SUFFIX + )), "GenericThing<_, _>::function_name" ); assert_eq!( - clean_function_name("::function_name"), + clean_function_name(&format!( + "::function_name{}", + USELESS_SCOPE_NAME_SUFFIX + )), "::function_name" ); } -/// Returns a shortened path to the current file. -#[macro_export] -macro_rules! current_file_name { - () => { - $crate::short_file_name(file!()) - }; -} - /// Shortens a long `file!()` path to the essentials. /// /// We want to keep it short for two reasons: readability, and bandwidth #[doc(hidden)] #[inline(never)] -pub fn short_file_name(path: &'static str) -> String { +pub fn short_file_name(path: &str) -> String { + if path.is_empty() { + return "".to_string(); + } + let path = path.replace('\\', "/"); // Handle Windows let components: Vec<&str> = path.split('/').collect(); if components.len() <= 2 { @@ -782,6 +946,75 @@ fn test_short_file_name() { } } +#[test] +fn profile_macros_test() { + set_scopes_on(true); + + let frame_view = GlobalFrameView::default(); + + GlobalProfiler::lock().add_sink(Box::new(|data| { + if data.frame_index() == 0 { + assert_eq!(data.frame_index(), 0); + assert_eq!(data.meta().num_scopes, 2); + assert_eq!(data.meta().num_bytes, 62); + } else if data.frame_index() == 1 { + assert_eq!(data.frame_index(), 1); + assert_eq!(data.meta().num_scopes, 2); + assert_eq!(data.meta().num_bytes, 62); + } else { + panic!("Only two frames in this test"); + } + })); + + let line_nr_fn = line!() + 3; + let line_nr_scope = line!() + 4; + fn a() { + profile_function!(); + { + profile_scope!("my-scope"); + } + } + + a(); + + // First frame + GlobalProfiler::lock().new_frame(); + + let lock = frame_view.lock(); + let scope_details = lock + .scope_collection() + .fetch_by_id(&ScopeId::new(1)) + .unwrap(); + assert_eq!(scope_details.file_path, "puffin/src/lib.rs"); + assert_eq!(scope_details.function_name, "profile_macros_test::a"); + assert_eq!(scope_details.line_nr, line_nr_fn); + + let scope_details = lock + .scope_collection() + .fetch_by_id(&ScopeId::new(2)) + .unwrap(); + + assert_eq!(scope_details.file_path, "puffin/src/lib.rs"); + assert_eq!(scope_details.function_name, "profile_macros_test::a"); + assert_eq!(scope_details.scope_name, Some(Cow::Borrowed("my-scope"))); + assert_eq!(scope_details.line_nr, line_nr_scope); + + let scope_details = lock.scope_collection().fetch_by_name("my-scope").unwrap(); + assert_eq!(scope_details, &ScopeId::new(2)); + + drop(lock); + + // Second frame + a(); + + GlobalProfiler::lock().new_frame(); +} + +// The macro defines 'f()' at the place where macro is called. +// This code is located at the place of call and two closures deep. +// Strip away this useless suffix. +const USELESS_SCOPE_NAME_SUFFIX: &str = "::{{closure}}::{{closure}}::f"; + #[allow(clippy::doc_markdown)] // clippy wants to put "MacBook" in ticks 🙄 /// Automatically name the profiling scope based on function name. /// @@ -810,7 +1043,7 @@ fn test_short_file_name() { /// } /// ``` /// -/// Overhead: around 210 ns on 2020 Intel MacBook Pro. +/// Overhead: around 54 ns on Macbook Pro with Apple M1 Max. #[macro_export] macro_rules! profile_function { () => { @@ -818,31 +1051,19 @@ macro_rules! profile_function { }; ($data:expr) => { let _profiler_scope = if $crate::are_scopes_on() { - static mut _FUNCTION_NAME: &'static str = ""; - static mut _LOCATION: &'static str = ""; - static _INITITIALIZED: ::std::sync::Once = ::std::sync::Once::new(); - - #[allow(unsafe_code)] - // SAFETY: accessing the statics is safe because it is done in cojunction with `std::sync::Once`` - let (function_name, location) = unsafe { - _INITITIALIZED.call_once(|| { - let function_name = $crate::current_function_name!(); - - // We call `current_function_name` from a closure, so we need to strip that from the output. - // We only strip it once though, because if the user calls `profile_function!` from within a closure, they probably want to know it. - let function_name = function_name.strip_suffix("::{{closure}}").unwrap_or(function_name.as_ref()); - - _FUNCTION_NAME = function_name.to_owned().leak(); - _LOCATION = format!("{}:{}", $crate::current_file_name!(), line!()).leak(); - }); - (_FUNCTION_NAME, _LOCATION) - }; - - Some($crate::ProfilerScope::new( - function_name, - location, - $data, - )) + static SCOPE_ID: std::sync::OnceLock<$crate::ScopeId> = std::sync::OnceLock::new(); + let scope_id = SCOPE_ID.get_or_init(|| { + $crate::ThreadProfiler::call(|tp| { + let id = tp.register_function_scope( + $crate::current_function_name!(), + file!(), + line!(), + ); + id + }) + }); + + Some($crate::ProfilerScope::new(*scope_id, $data)) } else { None }; @@ -859,31 +1080,27 @@ macro_rules! profile_function { /// An optional second argument can be a string (e.g. a mesh name) to help diagnose what was slow. /// Example: `profile_scope!("load_mesh", mesh_name);` /// -/// Overhead: around 140 ns on 2020 Intel MacBook Pro. +/// Overhead: around 54 ns on Macbook Pro with Apple M1 Max. #[macro_export] macro_rules! profile_scope { - ($id:expr) => { - $crate::profile_scope!($id, ""); + ($name:expr) => { + $crate::profile_scope!($name, ""); }; - ($id:expr, $data:expr) => { + ($name:expr, $data:expr) => { let _profiler_scope = if $crate::are_scopes_on() { - static mut _LOCATION: &'static str = ""; - static _INITITIALIZED: ::std::sync::Once = ::std::sync::Once::new(); - - #[allow(unsafe_code)] - // SAFETY: accessing the statics is safe because it is done in cojunction with `std::sync::Once`` - let location = unsafe { - _INITITIALIZED.call_once(|| { - _LOCATION = format!("{}:{}", $crate::current_file_name!(), line!()).leak(); - }); - _LOCATION - }; - - Some($crate::ProfilerScope::new( - $id, - location, - $data, - )) + static SCOPE_ID: std::sync::OnceLock<$crate::ScopeId> = std::sync::OnceLock::new(); + let scope_id = SCOPE_ID.get_or_init(|| { + $crate::ThreadProfiler::call(|tp| { + let id = tp.register_scope( + $name, + $crate::current_function_name!(), + file!(), + line!(), + ); + id + }) + }); + Some($crate::ProfilerScope::new(*scope_id, $data)) } else { None }; diff --git a/puffin/src/merge.rs b/puffin/src/merge.rs index 91d848a3..8139edd3 100644 --- a/puffin/src/merge.rs +++ b/puffin/src/merge.rs @@ -1,10 +1,13 @@ -use crate::{NanoSecond, Reader, Result, Scope, Stream, ThreadInfo, UnpackedFrameData}; -use std::collections::BTreeMap; +use crate::{ + NanoSecond, Reader, Result, Scope, ScopeCollection, ScopeId, Stream, ThreadInfo, + UnpackedFrameData, +}; +use std::{collections::BTreeMap, hash::Hash}; /// Temporary structure while building a [`MergeScope`]. #[derive(Clone, Debug, PartialEq, PartialOrd, Eq, Ord, Hash)] struct MergeId<'s> { - id: &'s str, + id: ScopeId, data: &'s str, } @@ -18,7 +21,6 @@ struct MergeNode<'s> { /// indexed by their id+data children: BTreeMap, MergeNode<'s>>, } - #[derive(Clone, Copy, Debug, PartialEq)] struct MergePiece<'s> { /// The start of the scope relative to its *parent* [`Scope`]. @@ -41,9 +43,7 @@ pub struct MergeScope<'s> { /// Number of pieces that got merged together to us. pub num_pieces: usize, /// The common identifier that we merged using. - pub id: std::borrow::Cow<'s, str>, - /// only set if all children had the same - pub location: std::borrow::Cow<'s, str>, + pub id: ScopeId, /// only set if all children had the same pub data: std::borrow::Cow<'s, str>, @@ -58,8 +58,7 @@ impl<'s> MergeScope<'s> { duration_per_frame_ns: self.duration_per_frame_ns, max_duration_ns: self.max_duration_ns, num_pieces: self.num_pieces, - id: std::borrow::Cow::Owned(self.id.into_owned()), - location: std::borrow::Cow::Owned(self.location.into_owned()), + id: self.id, data: std::borrow::Cow::Owned(self.data.into_owned()), children: self.children.into_iter().map(Self::into_owned).collect(), } @@ -72,9 +71,10 @@ impl<'s> MergeNode<'s> { for child in Reader::with_offset(stream, piece.scope.child_begin_position)? { let child = child?; + self.children .entry(MergeId { - id: child.record.id, + id: child.id, data: child.record.data, }) .or_default() @@ -90,14 +90,13 @@ impl<'s> MergeNode<'s> { Ok(()) } - fn build(self, num_frames: i64) -> MergeScope<'s> { + fn build(self, scope_collection: &ScopeCollection, num_frames: i64) -> MergeScope<'s> { assert!(!self.pieces.is_empty()); let mut relative_start_ns = self.pieces[0].relative_start_ns; let mut total_duration_ns = 0; let mut slowest_ns = 0; let num_pieces = self.pieces.len(); - let id = self.pieces[0].scope.record.id; - let mut location = self.pieces[0].scope.record.location; + let id = self.pieces[0].scope.id; let mut data = self.pieces[0].scope.record.data; for piece in &self.pieces { @@ -106,13 +105,10 @@ impl<'s> MergeNode<'s> { total_duration_ns += piece.scope.record.duration_ns; slowest_ns = slowest_ns.max(piece.scope.record.duration_ns); - assert_eq!(id, piece.scope.record.id); + assert_eq!(id, piece.scope.id); if data != piece.scope.record.data { data = ""; // different in different pieces } - if location != piece.scope.record.location { - location = ""; // different in different pieces - } } MergeScope { @@ -121,18 +117,21 @@ impl<'s> MergeNode<'s> { duration_per_frame_ns: total_duration_ns / num_frames, max_duration_ns: slowest_ns, num_pieces, - id: id.into(), - location: location.into(), + id, data: data.into(), - children: build(self.children, num_frames), + children: build(scope_collection, self.children, num_frames), } } } -fn build<'s>(nodes: BTreeMap, MergeNode<'s>>, num_frames: i64) -> Vec> { +fn build<'s>( + scope_collection: &ScopeCollection, + nodes: BTreeMap, MergeNode<'s>>, + num_frames: i64, +) -> Vec> { let mut scopes: Vec<_> = nodes .into_values() - .map(|node| node.build(num_frames)) + .map(|node| node.build(scope_collection, num_frames)) .collect(); // Earliest first: @@ -150,6 +149,7 @@ fn build<'s>(nodes: BTreeMap, MergeNode<'s>>, num_frames: i64) -> Ve /// For the given thread, merge all scopes with the same id+data path. pub fn merge_scopes_for_thread<'s>( + scope_collection: &ScopeCollection, frames: &'s [std::sync::Arc], thread_info: &ThreadInfo, ) -> Result>> { @@ -163,7 +163,7 @@ pub fn merge_scopes_for_thread<'s>( for scope in top_scopes { top_nodes .entry(MergeId { - id: scope.record.id, + id: scope.id, data: scope.record.data, }) .or_default() @@ -178,7 +178,7 @@ pub fn merge_scopes_for_thread<'s>( } } - Ok(build(top_nodes, frames.len() as _)) + Ok(build(scope_collection, top_nodes, frames.len() as _)) } // ---------------------------------------------------------------------------- @@ -187,21 +187,41 @@ pub fn merge_scopes_for_thread<'s>( fn test_merge() { use crate::*; + let mut scope_collection = ScopeCollection::default(); + // top scopes + scope_collection.insert(Arc::new( + ScopeDetails::from_scope_id(ScopeId::new(1)).with_function_name("a"), + )); + scope_collection.insert(Arc::new( + ScopeDetails::from_scope_id(ScopeId::new(2)).with_function_name("b"), + )); + + // middle scopes + scope_collection.insert(Arc::new( + ScopeDetails::from_scope_id(ScopeId::new(3)).with_function_name("ba"), + )); + scope_collection.insert(Arc::new( + ScopeDetails::from_scope_id(ScopeId::new(4)).with_function_name("bb"), + )); + scope_collection.insert(Arc::new( + ScopeDetails::from_scope_id(ScopeId::new(5)).with_function_name("bba"), + )); + let stream = { let mut stream = Stream::default(); for i in 0..2 { let ns = 1000 * i; - let a = stream.begin_scope(ns + 100, "a", "", ""); + let a = stream.begin_scope(ns + 100, ScopeId::new(1), ""); stream.end_scope(a, ns + 200); - let b = stream.begin_scope(ns + 200, "b", "", ""); + let b = stream.begin_scope(ns + 200, ScopeId::new(2), ""); - let ba = stream.begin_scope(ns + 400, "ba", "", ""); + let ba = stream.begin_scope(ns + 400, ScopeId::new(3), ""); stream.end_scope(ba, ns + 600); - let bb = stream.begin_scope(ns + 600, "bb", "", ""); - let bba = stream.begin_scope(ns + 600, "bba", "", ""); + let bb = stream.begin_scope(ns + 600, ScopeId::new(4), ""); + let bba = stream.begin_scope(ns + 600, ScopeId::new(5), ""); stream.end_scope(bba, ns + 700); stream.end_scope(bb, ns + 800); stream.end_scope(b, ns + 900); @@ -219,7 +239,7 @@ fn test_merge() { thread_streams.insert(thread_info.clone(), stream_info); let frame = UnpackedFrameData::new(0, thread_streams).unwrap(); let frames = [Arc::new(frame)]; - let merged = merge_scopes_for_thread(&frames, &thread_info).unwrap(); + let merged = merge_scopes_for_thread(&scope_collection, &frames, &thread_info).unwrap(); let expected = vec![ MergeScope { @@ -228,8 +248,7 @@ fn test_merge() { duration_per_frame_ns: 2 * 100, max_duration_ns: 100, num_pieces: 2, - id: "a".into(), - location: "".into(), + id: ScopeId::new(1), data: "".into(), children: vec![], }, @@ -239,8 +258,7 @@ fn test_merge() { duration_per_frame_ns: 2 * 700, max_duration_ns: 700, num_pieces: 2, - id: "b".into(), - location: "".into(), + id: ScopeId::new(2), data: "".into(), children: vec![ MergeScope { @@ -249,8 +267,7 @@ fn test_merge() { duration_per_frame_ns: 2 * 200, max_duration_ns: 200, num_pieces: 2, - id: "ba".into(), - location: "".into(), + id: ScopeId::new(3), data: "".into(), children: vec![], }, @@ -260,8 +277,7 @@ fn test_merge() { duration_per_frame_ns: 2 * 200, max_duration_ns: 200, num_pieces: 2, - id: "bb".into(), - location: "".into(), + id: ScopeId::new(4), data: "".into(), children: vec![MergeScope { relative_start_ns: 0, @@ -269,8 +285,7 @@ fn test_merge() { duration_per_frame_ns: 2 * 100, max_duration_ns: 100, num_pieces: 2, - id: "bba".into(), - location: "".into(), + id: ScopeId::new(5), data: "".into(), children: vec![], }], diff --git a/puffin/src/profile_view.rs b/puffin/src/profile_view.rs index a5e0adc3..ba912e1f 100644 --- a/puffin/src/profile_view.rs +++ b/puffin/src/profile_view.rs @@ -1,6 +1,6 @@ use std::sync::{Arc, Mutex}; -use crate::{FrameData, FrameSinkId}; +use crate::{FrameData, FrameSinkId, ScopeCollection}; /// A view of recent and slowest frames, used by GUIs. #[derive(Clone)] @@ -16,6 +16,7 @@ pub struct FrameView { /// /// Only recommended if you set a large max_recent size. pack_frames: bool, + scope_collection: ScopeCollection, } impl Default for FrameView { @@ -29,6 +30,7 @@ impl Default for FrameView { slowest: std::collections::BinaryHeap::with_capacity(max_slow), max_slow, pack_frames: true, + scope_collection: Default::default(), } } } @@ -38,7 +40,16 @@ impl FrameView { self.recent.is_empty() && self.slowest.is_empty() } + pub fn scope_collection(&self) -> &ScopeCollection { + &self.scope_collection + } + pub fn add_frame(&mut self, new_frame: Arc) { + // Register all scopes from the new frame into the scope collection. + for new_scope in &new_frame.scope_delta { + self.scope_collection.insert(new_scope.clone()); + } + if let Some(last) = self.recent.back() { if new_frame.frame_index() <= last.frame_index() { // A frame from the past!? @@ -159,7 +170,7 @@ impl FrameView { frames.dedup_by_key(|frame| frame.frame_index()); for frame in frames { - frame.write_into(write)?; + frame.write_into(&self.scope_collection, false, write)?; } Ok(()) } @@ -251,6 +262,11 @@ impl Drop for GlobalFrameView { } impl GlobalFrameView { + /// Sink ID + pub fn sink_id(&self) -> FrameSinkId { + self.sink_id + } + /// View the latest profiling data. pub fn lock(&self) -> std::sync::MutexGuard<'_, FrameView> { self.view.lock().unwrap() diff --git a/puffin/src/scope_details.rs b/puffin/src/scope_details.rs new file mode 100644 index 00000000..42ebb13d --- /dev/null +++ b/puffin/src/scope_details.rs @@ -0,0 +1,216 @@ +use crate::{clean_function_name, short_file_name, ScopeId}; +use std::{borrow::Cow, collections::HashMap, sync::Arc}; + +#[derive(Default, Clone)] +struct Inner { + // Store a both-way map, memory wise this can be a bit redundant but allows for faster access of information by external libs. + pub(crate) scope_id_to_details: HashMap>, + pub(crate) type_to_scope_id: HashMap, ScopeId>, +} + +/// A collection of scope details containing more information about a recorded profile scope. +#[derive(Default, Clone)] +pub struct ScopeCollection(Inner); + +impl ScopeCollection { + /// Fetches scope details by scope id. + #[inline] + pub fn fetch_by_id(&self, scope_id: &ScopeId) -> Option<&Arc> { + self.0.scope_id_to_details.get(scope_id) + } + + /// Fetches scope details by scope name. + #[inline] + pub fn fetch_by_name(&self, scope_name: &str) -> Option<&ScopeId> { + self.0.type_to_scope_id.get(scope_name) + } + + /// Insert a scope into the collection. + /// This method asserts the scope id is set which only puffin should do. + /// Custom sinks might use this method to store new scope details received from puffin. + pub fn insert(&mut self, scope_details: Arc) -> Arc { + let scope_id = scope_details + .scope_id + .expect("`ScopeDetails` missing `ScopeId`"); + + self.0 + .type_to_scope_id + .insert(scope_details.name().clone(), scope_id); + self.0 + .scope_id_to_details + .entry(scope_id) + .or_insert(scope_details) + .clone() + } + + /// Fetches all registered scopes and their ids. + /// Useful for fetching scope id by it's scope name. + /// For profiler scopes and user scopes this is the manual provided name. + /// For function profiler scopes this is the function name. + #[inline] + pub fn scopes_by_name(&self) -> &HashMap, ScopeId> { + &self.0.type_to_scope_id + } + + /// Fetches all registered scopes. + /// Useful for fetching scope details by a scope id. + #[inline] + pub fn scopes_by_id(&self) -> &HashMap> { + &self.0.scope_id_to_details + } +} + +/// Scopes are identified by user-provided name while functions are identified by the function name. +#[derive(Debug, Clone, PartialEq, Hash, PartialOrd, Ord, Eq)] +#[cfg_attr( + feature = "serialization", + derive(serde::Serialize, serde::Deserialize) +)] +pub enum ScopeType { + /// The scope is a function profile scope generated by `puffin::profile_function!`. + Function, + /// The named scope is a profile scope inside a function generated by `puffin::profile_scope!` or registered manually. + /// It is identified by a unique name. + Named, +} + +impl ScopeType { + pub fn type_str(&self) -> &'static str { + match self { + ScopeType::Function => "function scope", + ScopeType::Named => "named", + } + } +} + +#[derive(Debug, Default, Clone, PartialEq, Hash, PartialOrd, Ord, Eq)] +#[cfg_attr( + feature = "serialization", + derive(serde::Serialize, serde::Deserialize) +)] +/// Detailed information about a scope. +pub struct ScopeDetails { + /// Unique scope identifier. + /// Always initialized once registered. + /// It is `None` when an external library has yet to register this scope. + pub(crate) scope_id: Option, + /// A name for a profile scope, a function profile scope does not have a custom provided name. + pub scope_name: Option>, + /// The function name of the function in which this scope is contained. + /// The name might be slightly modified to represent a short descriptive representation. + pub function_name: Cow<'static, str>, + /// The file path in which this scope is contained. + /// The path might be slightly modified to represent a short descriptive representation. + pub file_path: Cow<'static, str>, + /// The exact line number at which this scope is located. + pub line_nr: u32, +} + +impl ScopeDetails { + /// Creates a new user scope with a unique name. + pub fn from_scope_name(scope_name: T) -> Self + where + T: Into>, + { + Self { + scope_id: None, + scope_name: Some(scope_name.into()), + function_name: Default::default(), + file_path: Default::default(), + line_nr: Default::default(), + } + } + + /// Creates a new user scope with a unique id allocated by puffin. + /// This function should not be exposed as only puffin should allocate ids for scopes. + pub(crate) fn from_scope_id(scope_id: ScopeId) -> Self { + Self { + scope_id: Some(scope_id), + scope_name: None, + function_name: Default::default(), + file_path: Default::default(), + line_nr: Default::default(), + } + } + + #[inline] + pub fn with_function_name(mut self, name: T) -> Self + where + T: Into>, + { + self.function_name = name.into(); + self + } + + #[inline] + pub fn with_file(mut self, file: T) -> Self + where + T: Into>, + { + self.file_path = file.into(); + self + } + + #[inline] + pub fn with_line_nr(mut self, line_nr: u32) -> Self { + self.line_nr = line_nr; + self + } + + /// Returns the scope name if this is a profile scope or else the function name. + pub fn name(&self) -> &Cow<'static, str> { + self.scope_name.as_ref().map_or(&self.function_name, |x| x) + } + + /// Returns what type of scope this is. + pub fn scope_type(&self) -> ScopeType { + // scope name is only set for named scopes. + if self.scope_name.is_some() { + ScopeType::Named + } else { + ScopeType::Function + } + } + + /// Returns the exact location of the profile scope formatted as `file:line_nr` + #[inline] + pub fn location(&self) -> String { + if self.line_nr != 0 { + format!("{}:{}", self.file_path, self.line_nr) + } else { + format!("{}", self.file_path) + } + } + + /// Turns the scope details into a more readable version: + /// + /// * Consistent / shortened file path across platforms + /// * Consistent / shortened function name + #[inline] + pub(crate) fn into_readable(self) -> Self { + Self { + scope_id: self.scope_id, + scope_name: self.scope_name, + function_name: clean_function_name(&self.function_name).into(), + file_path: short_file_name(&self.file_path).into(), + line_nr: self.line_nr, + } + } + + // This function should not be exposed as only puffin should allocate ids. + #[inline] + pub(crate) fn with_scope_id(mut self, scope_id: ScopeId) -> Self { + self.scope_id = Some(scope_id); + self + } + + // This function should not be exposed as users are supposed to provide scope name in constructor. + #[inline] + pub(crate) fn with_scope_name(mut self, scope_name: T) -> Self + where + T: Into>, + { + self.scope_name = Some(scope_name.into()); + self + } +} diff --git a/puffin_egui/src/flamegraph.rs b/puffin_egui/src/flamegraph.rs index 4b27a91a..5c9ca339 100644 --- a/puffin_egui/src/flamegraph.rs +++ b/puffin_egui/src/flamegraph.rs @@ -162,7 +162,7 @@ impl Default for Options { } /// Context for painting a frame. -struct Info { +struct Info<'a> { ctx: egui::Context, /// Bounding box of canvas in points: canvas: Rect, @@ -178,6 +178,8 @@ struct Info { num_frames: usize, font_id: FontId, + + scope_collection: &'a ScopeCollection, } #[derive(Clone, Copy, Eq, PartialEq)] @@ -187,7 +189,7 @@ enum PaintResult { Normal, } -impl Info { +impl<'a> Info<'a> { fn point_from_ns(&self, options: &Options, ns: NanoSecond) -> f32 { self.canvas.min.x + options.sideways_pan_in_points @@ -196,7 +198,12 @@ impl Info { } /// Show the flamegraph. -pub fn ui(ui: &mut egui::Ui, options: &mut Options, frames: &SelectedFrames) { +pub fn ui( + ui: &mut egui::Ui, + options: &mut Options, + scope_collection: &ScopeCollection, + frames: &SelectedFrames, +) { puffin::profile_function!(); let mut reset_view = false; @@ -290,6 +297,7 @@ pub fn ui(ui: &mut egui::Ui, options: &mut Options, frames: &SelectedFrames) { stop_ns: max_ns, num_frames: frames.frames.len(), font_id: TextStyle::Body.resolve(ui.style()), + scope_collection, }; if reset_view { @@ -322,7 +330,7 @@ pub fn ui(ui: &mut egui::Ui, options: &mut Options, frames: &SelectedFrames) { fn ui_canvas( options: &mut Options, - info: &Info, + info: &Info<'_>, frames: &SelectedFrames, (min_ns, max_ns): (NanoSecond, NanoSecond), ) -> f32 { @@ -379,7 +387,7 @@ fn ui_canvas( let mut paint_streams = || -> Result<()> { if options.merge_scopes { for merge in &frames.threads[&thread_info].merged_scopes { - paint_merge_scope(info, options, 0, merge, 0, cursor_y)?; + paint_merge_scope(info, options, 0, merge, 0, cursor_y); } } else { for stream_info in &frames.threads[&thread_info].streams { @@ -413,7 +421,7 @@ fn ui_canvas( cursor_y } -fn interact_with_canvas(options: &mut Options, response: &Response, info: &Info) { +fn interact_with_canvas(options: &mut Options, response: &Response, info: &Info<'_>) { if response.drag_delta().x != 0.0 { options.sideways_pan_in_points += response.drag_delta().x; options.zoom_to_relative_ns_range = None; @@ -478,7 +486,7 @@ fn interact_with_canvas(options: &mut Options, response: &Response, info: &Info) } fn paint_timeline( - info: &Info, + info: &Info<'_>, canvas: Rect, options: &Options, start_ns: NanoSecond, @@ -590,16 +598,18 @@ fn grid_text(grid_ns: NanoSecond) -> String { } } +#[allow(clippy::too_many_arguments)] fn paint_record( - info: &Info, + info: &Info<'_>, options: &mut Options, prefix: &str, suffix: &str, - record: &Record<'_>, + scope_id: ScopeId, + scope_data: &ScopeRecord<'_>, top_y: f32, ) -> PaintResult { - let start_x = info.point_from_ns(options, record.start_ns); - let stop_x = info.point_from_ns(options, record.stop_ns()); + let start_x = info.point_from_ns(options, scope_data.start_ns); + let stop_x = info.point_from_ns(options, scope_data.stop_ns()); if info.canvas.max.x < start_x || stop_x < info.canvas.min.x || stop_x - start_x < options.cull_width @@ -617,18 +627,22 @@ fn paint_record( false }; + let Some(scope_details) = info.scope_collection.fetch_by_id(&scope_id) else { + return PaintResult::Culled; + }; + if info.response.double_clicked() { if let Some(mouse_pos) = info.response.interact_pointer_pos() { if rect.contains(mouse_pos) { - options.filter.set_filter(record.id.to_string()); + options.filter.set_filter(scope_details.name().to_string()); } } } else if is_hovered && info.response.clicked() { options.zoom_to_relative_ns_range = Some(( info.ctx.input(|i| i.time), ( - record.start_ns - info.start_ns, - record.stop_ns() - info.start_ns, + scope_data.start_ns - info.start_ns, + scope_data.stop_ns() - info.start_ns, ), )); } @@ -636,13 +650,13 @@ fn paint_record( let mut rect_color = if is_hovered { HOVER_COLOR } else { - color_from_duration(record.duration_ns) + color_from_duration(scope_data.duration_ns) }; let mut min_width = options.min_width; if !options.filter.is_empty() { - if options.filter.include(record.id) { + if options.filter.include(&scope_details.name()) { // keep full opacity min_width *= 2.0; // make it more visible even when thin } else { @@ -665,13 +679,25 @@ fn paint_record( if wide_enough_for_text { let painter = info.painter.with_clip_rect(rect.intersect(info.canvas)); - let duration_ms = to_ms(record.duration_ns); - let text = if record.data.is_empty() { - format!("{}{} {:6.3} ms {}", prefix, record.id, duration_ms, suffix) + let scope_name = scope_details.name(); + + let duration_ms = to_ms(scope_data.duration_ns); + let text = if scope_data.data.is_empty() { + format!( + "{}{} {:6.3} ms {}", + prefix, + scope_name.as_str(), + duration_ms, + suffix + ) } else { format!( "{}{} {:?} {:6.3} ms {}", - prefix, record.id, record.data, duration_ms, suffix + prefix, + scope_name.as_str(), + scope_data.data, + duration_ms, + suffix ) }; let pos = pos2( @@ -712,7 +738,7 @@ fn to_ms(ns: NanoSecond) -> f64 { } fn paint_scope( - info: &Info, + info: &Info<'_>, options: &mut Options, stream: &Stream, scope: &Scope<'_>, @@ -721,7 +747,7 @@ fn paint_scope( ) -> Result { let top_y = min_y + (depth as f32) * (options.rect_height + options.spacing); - let result = paint_record(info, options, "", "", &scope.record, top_y); + let result = paint_record(info, options, "", "", scope.id, &scope.record, top_y); if result != PaintResult::Culled { let mut num_children = 0; @@ -731,19 +757,17 @@ fn paint_scope( } if result == PaintResult::Hovered { + let Some(scope_details) = info.scope_collection.fetch_by_id(&scope.id) else { + return Ok(PaintResult::Culled); + }; egui::show_tooltip_at_pointer(&info.ctx, Id::new("puffin_profiler_tooltip"), |ui| { - ui.monospace(format!("id: {}", scope.record.id)); - if !scope.record.location.is_empty() { - ui.monospace(format!("location: {}", scope.record.location)); - } - if !scope.record.data.is_empty() { - ui.monospace(format!("data: {}", scope.record.data)); - } + paint_scope_details(ui, scope.id, scope.record.data, scope_details); + add_space(ui); ui.monospace(format!( "duration: {:7.3} ms", to_ms(scope.record.duration_ns) )); - ui.monospace(format!("children: {num_children}")); + ui.monospace(format!("children: {num_children:3}")); }); } } @@ -752,13 +776,13 @@ fn paint_scope( } fn paint_merge_scope( - info: &Info, + info: &Info<'_>, options: &mut Options, ns_offset: NanoSecond, merge: &MergeScope<'_>, depth: usize, min_y: f32, -) -> Result { +) -> PaintResult { let top_y = min_y + (depth as f32) * (options.rect_height + options.spacing); let prefix = if info.num_frames <= 1 { @@ -782,42 +806,80 @@ fn paint_merge_scope( "per frame" }; - let record = Record { + let record = ScopeRecord { start_ns: ns_offset + merge.relative_start_ns, duration_ns: merge.duration_per_frame_ns, - id: &merge.id, - location: &merge.location, data: &merge.data, }; - let result = paint_record(info, options, &prefix, suffix, &record, top_y); + let result = paint_record(info, options, &prefix, suffix, merge.id, &record, top_y); if result != PaintResult::Culled { for child in &merge.children { - paint_merge_scope(info, options, record.start_ns, child, depth + 1, min_y)?; + paint_merge_scope(info, options, record.start_ns, child, depth + 1, min_y); } if result == PaintResult::Hovered { egui::show_tooltip_at_pointer(&info.ctx, Id::new("puffin_profiler_tooltip"), |ui| { - merge_scope_tooltip(ui, merge, info.num_frames); + merge_scope_tooltip(ui, info.scope_collection, merge, info.num_frames); }); } } - Ok(result) + result } -fn merge_scope_tooltip(ui: &mut egui::Ui, merge: &MergeScope<'_>, num_frames: usize) { +fn paint_scope_details(ui: &mut Ui, scope_id: ScopeId, data: &str, scope_details: &ScopeDetails) { + egui::Grid::new("scope_details_tooltip") + .num_columns(2) + .show(ui, |ui| { + ui.monospace("id"); + ui.monospace(format!("{}", scope_id.0)); + ui.end_row(); + + ui.monospace("function name"); + ui.monospace(scope_details.function_name.as_str()); + ui.end_row(); + + if let Some(scope_name) = &scope_details.scope_name { + ui.monospace("scope name"); + ui.monospace(scope_name.as_str()); + ui.end_row(); + } + + if !scope_details.file_path.is_empty() { + ui.monospace("location"); + ui.monospace(scope_details.location()); + ui.end_row(); + } + + if !data.is_empty() { + ui.monospace("data"); + ui.monospace(data.as_str()); + ui.end_row(); + } + + ui.monospace("scope type"); + ui.monospace(scope_details.scope_type().type_str()); + ui.end_row(); + }); +} + +fn merge_scope_tooltip( + ui: &mut egui::Ui, + scope_collection: &ScopeCollection, + merge: &MergeScope<'_>, + num_frames: usize, +) { #![allow(clippy::collapsible_else_if)] - ui.monospace(format!("id: {}", merge.id)); - if !merge.location.is_empty() { - ui.monospace(format!("location: {}", merge.location)); - } - if !merge.data.is_empty() { - ui.monospace(format!("data: {}", merge.data)); - } - ui.add_space(8.0); + let Some(scope_details) = scope_collection.fetch_by_id(&merge.id) else { + return; + }; + + paint_scope_details(ui, merge.id, &merge.data, scope_details); + + add_space(ui); if num_frames <= 1 { if merge.num_pieces <= 1 { @@ -866,11 +928,10 @@ fn merge_scope_tooltip(ui: &mut egui::Ui, merge: &MergeScope<'_>, num_frames: us "{:7.3} ms for slowest call", to_ms(merge.max_duration_ns) )); - // } } } -fn paint_thread_info(info: &Info, thread: &ThreadInfo, pos: Pos2, collapsed: &mut bool) { +fn paint_thread_info(info: &Info<'_>, thread: &ThreadInfo, pos: Pos2, collapsed: &mut bool) { let collapsed_symbol = if *collapsed { "⏵" } else { "⏷" }; let galley = info.ctx.fonts(|f| { @@ -907,3 +968,8 @@ fn paint_thread_info(info: &Info, thread: &ThreadInfo, pos: Pos2, collapsed: &mu *collapsed = !(*collapsed); } } + +fn add_space(ui: &mut Ui) { + // a separator will make the parent tooltip unnecessarily wide (immediate mode problems) + ui.add_space(8.0); +} diff --git a/puffin_egui/src/lib.rs b/puffin_egui/src/lib.rs index 147b9a26..cd419524 100644 --- a/puffin_egui/src/lib.rs +++ b/puffin_egui/src/lib.rs @@ -249,7 +249,11 @@ pub struct Streams { } impl Streams { - fn new(frames: &[Arc], thread_info: &ThreadInfo) -> Self { + fn new( + scope_collection: &ScopeCollection, + frames: &[Arc], + thread_info: &ThreadInfo, + ) -> Self { crate::profile_function!(); let mut streams = vec![]; @@ -261,7 +265,7 @@ impl Streams { let merges = { puffin::profile_scope!("merge_scopes_for_thread"); - puffin::merge_scopes_for_thread(frames, thread_info).unwrap() + puffin::merge_scopes_for_thread(scope_collection, frames, thread_info).unwrap() }; let merges = merges.into_iter().map(|ms| ms.into_owned()).collect(); @@ -290,12 +294,18 @@ pub struct SelectedFrames { } impl SelectedFrames { - fn try_from_vec(frames: Vec>) -> Option { + fn try_from_vec( + scope_collection: &ScopeCollection, + frames: Vec>, + ) -> Option { let frames = vec1::Vec1::try_from_vec(frames).ok()?; - Some(Self::from_vec1(frames)) + Some(Self::from_vec1(scope_collection, frames)) } - fn from_vec1(mut frames: vec1::Vec1>) -> Self { + fn from_vec1( + scope_collection: &ScopeCollection, + mut frames: vec1::Vec1>, + ) -> Self { puffin::profile_function!(); frames.sort_by_key(|f| f.frame_index()); frames.dedup_by_key(|f| f.frame_index()); @@ -309,7 +319,7 @@ impl SelectedFrames { let threads: BTreeMap = threads .iter() - .map(|ti| (ti.clone(), Streams::new(&frames, ti))) + .map(|ti| (ti.clone(), Streams::new(scope_collection, &frames, ti))) .collect(); let mut merged_min_ns = NanoSecond::MAX; @@ -511,7 +521,9 @@ impl ProfilerUi { let frames = if let Some(frame) = hovered_frame { match frame.unpacked() { - Ok(frame) => SelectedFrames::try_from_vec(vec![frame]), + Ok(frame) => { + SelectedFrames::try_from_vec(&frame_view.scope_collection(), vec![frame]) + } Err(err) => { ui.colored_label(ERROR_COLOR, format!("Failed to load hovered frame: {err}")); return; @@ -522,13 +534,12 @@ impl ProfilerUi { } else { puffin::profile_scope!("select_latest_frames"); let latest = frame_view.latest_frames(self.max_num_latest); - SelectedFrames::try_from_vec( - latest - .into_iter() - .map(|frame| frame.unpacked()) - .filter_map(|unpacked| unpacked.ok()) - .collect(), - ) + let unpacked: Vec> = latest + .into_iter() + .map(|frame| frame.unpacked()) + .filter_map(|unpacked| unpacked.ok()) + .collect(); + SelectedFrames::try_from_vec(&frame_view.scope_collection(), unpacked) }; let frames = if let Some(frames) = frames { @@ -565,7 +576,10 @@ impl ProfilerUi { if let Ok(latest) = latest.unpacked() { self.pause_and_select( frame_view, - SelectedFrames::from_vec1(vec1::vec1![latest]), + SelectedFrames::from_vec1( + &frame_view.scope_collection(), + vec1::vec1![latest], + ), ); } } @@ -590,8 +604,18 @@ impl ProfilerUi { ui.separator(); match self.view { - View::Flamegraph => flamegraph::ui(ui, &mut self.flamegraph_options, &frames), - View::Stats => stats::ui(ui, &mut self.stats_options, &frames.frames), + View::Flamegraph => flamegraph::ui( + ui, + &mut self.flamegraph_options, + &frame_view.scope_collection(), + &frames, + ), + View::Stats => stats::ui( + ui, + &mut self.stats_options, + &frame_view.scope_collection(), + &frames.frames, + ), } } @@ -659,7 +683,7 @@ impl ProfilerUi { self.show_frame_list( ui, - frame_view, + &frame_view, &slowest_of_the_slow, true, &mut hovered_frame, @@ -810,7 +834,9 @@ impl ProfilerUi { } } - if let Some(new_selection) = SelectedFrames::try_from_vec(new_selection) { + if let Some(new_selection) = + SelectedFrames::try_from_vec(&frame_view.scope_collection(), new_selection) + { self.pause_and_select(frame_view, new_selection); } diff --git a/puffin_egui/src/stats.rs b/puffin_egui/src/stats.rs index 5cf77c48..8e0caa28 100644 --- a/puffin_egui/src/stats.rs +++ b/puffin_egui/src/stats.rs @@ -1,3 +1,4 @@ +use egui::TextBuffer; use puffin::*; use crate::filter::Filter; @@ -7,7 +8,12 @@ pub struct Options { filter: Filter, } -pub fn ui(ui: &mut egui::Ui, options: &mut Options, frames: &[std::sync::Arc]) { +pub fn ui( + ui: &mut egui::Ui, + options: &mut Options, + scope_infos: &ScopeCollection, + frames: &[std::sync::Arc], +) { let mut threads = std::collections::HashSet::<&ThreadInfo>::new(); let mut stats = Stats::default(); @@ -56,7 +62,8 @@ pub fn ui(ui: &mut egui::Ui, options: &mut Options, frames: &[std::sync::Arc5}", stats.count)); ui.monospace(format!("{:>6.1} kB", stats.bytes as f32 * 1e-3)); ui.monospace(format!("{:>8.1} µs", stats.total_self_ns as f32 * 1e-3)); @@ -87,14 +104,13 @@ pub fn ui(ui: &mut egui::Ui, options: &mut Options, frames: &[std::sync::Arc { - scopes: std::collections::HashMap, ScopeStats>, +struct Stats { + scopes: std::collections::HashMap, } #[derive(Clone, Hash, PartialEq, Eq, PartialOrd, Ord)] -struct Key<'s> { - id: &'s str, - location: &'s str, +struct Key { + id: ScopeId, thread_name: String, } @@ -110,10 +126,10 @@ struct ScopeStats { max_ns: NanoSecond, } -fn collect_stream<'s>( - stats: &mut Stats<'s>, +fn collect_stream( + stats: &mut Stats, thread_name: &str, - stream: &'s puffin::Stream, + stream: &puffin::Stream, ) -> puffin::Result<()> { for scope in puffin::Reader::from_start(stream) { collect_scope(stats, thread_name, stream, &scope?)?; @@ -122,7 +138,7 @@ fn collect_stream<'s>( } fn collect_scope<'s>( - stats: &mut Stats<'s>, + stats: &mut Stats, thread_name: &str, stream: &'s puffin::Stream, scope: &puffin::Scope<'s>, @@ -137,8 +153,7 @@ fn collect_scope<'s>( let self_time = scope.record.duration_ns.saturating_sub(ns_used_by_children); let key = Key { - id: scope.record.id, - location: scope.record.location, + id: scope.id, thread_name: thread_name.to_owned(), }; let scope_stats = stats.scopes.entry(key).or_default(); @@ -153,9 +168,8 @@ fn collect_scope<'s>( fn scope_byte_size(scope: &puffin::Scope<'_>) -> usize { 1 + // `(` sentinel 8 + // start time - 1 + scope.record.id.len() + // - 1 + scope.record.location.len() + // - 1 + scope.record.data.len() + // + 8 + // scope id + 1 + scope.record.data.len() + // dynamic data len 8 + // scope size 1 + // `)` sentinel 8 // stop time diff --git a/puffin_http/src/client.rs b/puffin_http/src/client.rs index ba5333e3..b0c39c7f 100644 --- a/puffin_http/src/client.rs +++ b/puffin_http/src/client.rs @@ -122,6 +122,7 @@ pub fn consume_message(stream: &mut impl std::io::Read) -> anyhow::Result, num_clients: Arc, + send_all_scopes: bool, + frame_view: FrameView, } impl PuffinServerImpl { @@ -137,6 +143,8 @@ impl PuffinServerImpl { .spawn(move || client_loop(packet_rx, client_addr, tcp_stream)) .context("Couldn't spawn thread")?; + // Send all scopes when new client connects. + self.send_all_scopes = true; self.clients.push(Client { client_addr, packet_tx: Some(packet_tx), @@ -162,12 +170,19 @@ impl PuffinServerImpl { puffin::profile_function!(); let mut packet = vec![]; + packet .write_all(&crate::PROTOCOL_VERSION.to_le_bytes()) .unwrap(); + frame - .write_into(&mut packet) + .write_into( + &self.frame_view.scope_collection(), + self.send_all_scopes, + &mut packet, + ) .context("Encode puffin frame")?; + self.send_all_scopes = false; let packet: Packet = packet.into();