From 1efc17b0fdeb2d864ea71d7c2f578657eb28dbb4 Mon Sep 17 00:00:00 2001 From: Johan Andersson Date: Wed, 19 Oct 2022 16:11:00 +0200 Subject: [PATCH] Don't merge scopes that have different data (#102) Previously we would merge all scopes that have the same `id`, but if you have multiple scopes after each that have same `id` but different dynamic `data` field they would be merged together and we wouldn't display the `data` field. This is something we ran into in our codebase that made it harder to see why a certain heavy operation was happening as we were missing the context for it. Which we did specify but was merged together and not shown here as merging scopes is on by default (and is a general good idea). Adds a simple visual test for in the imgui and egui clients. Resolves: #73 ## Example This is how it looks like now: ![image](https://user-images.githubusercontent.com/1262692/196470164-64076531-647c-48dc-84d3-7bb1a3d502a6.png) from the following code: ```rust // test to verify these spikes timers are not merged together as they have different data for (name, ms) in [("First".to_string(), 20), ("Second".to_string(), 15)] { puffin::profile_scope!("Spike", name); std::thread::sleep(std::time::Duration::from_millis(ms)) } // these are however fine to merge together as data is the same for (_name, ms) in [("First".to_string(), 20), ("Second".to_string(), 15)] { puffin::profile_scope!("Spike"); std::thread::sleep(std::time::Duration::from_millis(ms)) } ``` Before this PR this would have been a single "4x Spike" --- CHANGELOG.md | 4 +++ puffin-imgui/examples/imgui.rs | 12 +++++++ puffin/src/merge.rs | 57 ++++++++++++++++++++++------------ puffin_egui/examples/eframe.rs | 12 +++++++ 4 files changed, 66 insertions(+), 19 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 1eaf92ba..235f2464 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -8,6 +8,10 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ## [Unreleased] - ReleaseDate + +### Fixed +* [PR#102](https://github.com/EmbarkStudios/puffin/pull/102) Add a runtime setting on frameview to pack or not + ## [0.13.3] - 2022-05-04 ### Changed * [PR#83](https://github.com/EmbarkStudios/puffin/pull/83) Add a runtime setting on frameview to pack or not diff --git a/puffin-imgui/examples/imgui.rs b/puffin-imgui/examples/imgui.rs index 58f4ffed..52c2adb0 100644 --- a/puffin-imgui/examples/imgui.rs +++ b/puffin-imgui/examples/imgui.rs @@ -152,6 +152,18 @@ fn main() { puffin::profile_scope!("Big spike"); std::thread::sleep(std::time::Duration::from_millis(50)) } + if frame_counter % 55 == 0 { + // test to verify these spikes timers are not merged together as they have different data + for (name, ms) in [("First".to_string(), 20), ("Second".to_string(), 15)] { + puffin::profile_scope!("Spike", name); + std::thread::sleep(std::time::Duration::from_millis(ms)) + } + // these are however fine to merge together as data is the same + for (_name, ms) in [("First".to_string(), 20), ("Second".to_string(), 15)] { + puffin::profile_scope!("Spike"); + std::thread::sleep(std::time::Duration::from_millis(ms)) + } + } for _ in 0..1000 { puffin::profile_scope!("very thin"); diff --git a/puffin/src/merge.rs b/puffin/src/merge.rs index 208dd338..c4d4beb9 100644 --- a/puffin/src/merge.rs +++ b/puffin/src/merge.rs @@ -1,6 +1,13 @@ use crate::{NanoSecond, Reader, Result, Scope, Stream, ThreadInfo, UnpackedFrameData}; use std::collections::BTreeMap; +/// Temporary structure while building a [`MergeScope`]. +#[derive(Clone, Debug, PartialEq, PartialOrd, Eq, Ord, Hash)] +struct MergeId<'s> { + id: &'s str, + data: &'s str, +} + /// Temporary structure while building a [`MergeScope`]. #[derive(Default)] struct MergeNode<'s> { @@ -8,8 +15,8 @@ struct MergeNode<'s> { /// All these scopes have the same `id`. pieces: Vec>, - /// indexed by their id - children: BTreeMap<&'s str, MergeNode<'s>>, + /// indexed by their id+data + children: BTreeMap, MergeNode<'s>>, } #[derive(Clone, Copy, Debug, PartialEq)] @@ -65,13 +72,19 @@ impl<'s> MergeNode<'s> { for child in Reader::with_offset(stream, piece.scope.child_begin_position)? { let child = child?; - self.children.entry(child.record.id).or_default().add( - stream, - MergePiece { - relative_start_ns: child.record.start_ns - piece.scope.record.start_ns, - scope: child, - }, - )?; + self.children + .entry(MergeId { + id: child.record.id, + data: child.record.data, + }) + .or_default() + .add( + stream, + MergePiece { + relative_start_ns: child.record.start_ns - piece.scope.record.start_ns, + scope: child, + }, + )?; } Ok(()) @@ -116,7 +129,7 @@ impl<'s> MergeNode<'s> { } } -fn build<'s>(nodes: BTreeMap<&'s str, MergeNode<'s>>, num_frames: i64) -> Vec> { +fn build<'s>(nodes: BTreeMap, MergeNode<'s>>, num_frames: i64) -> Vec> { let mut scopes: Vec<_> = nodes .into_values() .map(|node| node.build(num_frames)) @@ -135,12 +148,12 @@ fn build<'s>(nodes: BTreeMap<&'s str, MergeNode<'s>>, num_frames: i64) -> Vec( frames: &'s [std::sync::Arc], thread_info: &ThreadInfo, ) -> Result>> { - let mut top_nodes: BTreeMap<&'s str, MergeNode<'s>> = Default::default(); + let mut top_nodes: BTreeMap, MergeNode<'s>> = Default::default(); for frame in frames { if let Some(stream_info) = frame.thread_streams.get(thread_info) { @@ -148,13 +161,19 @@ pub fn merge_scopes_for_thread<'s>( let top_scopes = Reader::from_start(&stream_info.stream).read_top_scopes()?; for scope in top_scopes { - top_nodes.entry(scope.record.id).or_default().add( - &stream_info.stream, - MergePiece { - relative_start_ns: scope.record.start_ns - offset_ns, - scope, - }, - )?; + top_nodes + .entry(MergeId { + id: scope.record.id, + data: scope.record.data, + }) + .or_default() + .add( + &stream_info.stream, + MergePiece { + relative_start_ns: scope.record.start_ns - offset_ns, + scope, + }, + )?; } } } diff --git a/puffin_egui/examples/eframe.rs b/puffin_egui/examples/eframe.rs index 67947baa..ef1432a7 100644 --- a/puffin_egui/examples/eframe.rs +++ b/puffin_egui/examples/eframe.rs @@ -41,6 +41,18 @@ impl eframe::App for ExampleApp { puffin::profile_scope!("Big spike"); std::thread::sleep(std::time::Duration::from_millis(50)) } + if self.frame_counter % 55 == 0 { + // test to verify these spikes timers are not merged together as they have different data + for (name, ms) in [("First".to_string(), 20), ("Second".to_string(), 15)] { + puffin::profile_scope!("Spike", name); + std::thread::sleep(std::time::Duration::from_millis(ms)) + } + // these are however fine to merge together as data is the same + for (_name, ms) in [("First".to_string(), 20), ("Second".to_string(), 15)] { + puffin::profile_scope!("Spike"); + std::thread::sleep(std::time::Duration::from_millis(ms)) + } + } for _ in 0..1000 { puffin::profile_scope!("very thin");