diff --git a/CHANGELOG.md b/CHANGELOG.md index 4ac57c9a..bfa278f7 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,29 +1,29 @@ # Changelog + All notable changes to `puffin` will be documented in this file. The format is based on [Keep a Changelog](https://keepachangelog.com/en/1.0.0/), and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.html). + ## Unreleased +* New `serialization` feature flag enables exporting and importing `.puffin` files. This replaces the old `with_serde` feature flag. +* Add `GlobalProfiler::add_sink` for installing callbacks that are called each frame. * Speed up `GlobalProfiler::new_frame`. ## 0.6.0 - 2021-07-05 - * Handle Windows, which uses backslash (`\`) as path separator. ## 0.5.2 - * Add opt-in `serde` support. ## 0.5.1 - * Remove stderr warning about empty frames. ## 0.5.0 - * `GlobalProfiler` now store recent history and the slowest frames. diff --git a/Cargo.lock b/Cargo.lock index a1d2b0e2..f1373752 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -1294,6 +1294,15 @@ dependencies = [ "cfg-if 1.0.0", ] +[[package]] +name = "lz4_flex" +version = "0.8.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "5827b976d911b5d2e42b2ccfc7c0d2461a1414e8280436885218762fc529b3f8" +dependencies = [ + "twox-hash", +] + [[package]] name = "macroquad" version = "0.3.8" @@ -1912,8 +1921,11 @@ dependencies = [ name = "puffin" version = "0.6.0" dependencies = [ + "anyhow", + "bincode", "byteorder", "criterion", + "lz4_flex", "once_cell", "serde", ] @@ -1950,7 +1962,6 @@ name = "puffin_http" version = "0.3.0" dependencies = [ "anyhow", - "bincode", "log", "puffin", "retain_mut", @@ -2365,6 +2376,12 @@ dependencies = [ "wayland-client", ] +[[package]] +name = "static_assertions" +version = "1.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "a2eb9349b6444b326872e140eb1cf5e7c522154d69e7a0ffb0fb81c06b37543f" + [[package]] name = "strsim" version = "0.9.3" @@ -2458,6 +2475,16 @@ version = "0.12.3" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "7ae2f58a822f08abdaf668897e96a5656fe72f5a9ce66422423e8849384872e6" +[[package]] +name = "twox-hash" +version = "1.6.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "1f559b464de2e2bdabcac6a210d12e9b5a5973c251e102c44c585c71d51bd78e" +dependencies = [ + "cfg-if 1.0.0", + "static_assertions", +] + [[package]] name = "unicode-segmentation" version = "1.8.0" diff --git a/puffin-imgui/CHANGELOG.md b/puffin-imgui/CHANGELOG.md index b19e0bfe..c1dc39c2 100644 --- a/puffin-imgui/CHANGELOG.md +++ b/puffin-imgui/CHANGELOG.md @@ -4,11 +4,13 @@ All notable changes to `puffin-imgui` will be documented in this file. The format is based on [Keep a Changelog](https://keepachangelog.com/en/1.0.0/), and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.html). + ## Unreleased +* Fix "Toggle with spacebar." tooltip always showing. +* Show frame index. ## 0.9.0 - * Paint flamegraph top-down * Scrollable flamegraph * Option to sort threads by name @@ -19,7 +21,6 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ## 0.8.0 - * Select frames from recent history or from among the slowest ever. * Nicer colors. * Simpler interaction (drag to pan, scroll to zoom, click to focus, double-click to reset). diff --git a/puffin-imgui/src/ui.rs b/puffin-imgui/src/ui.rs index d8095f1b..8aadd932 100644 --- a/puffin-imgui/src/ui.rs +++ b/puffin-imgui/src/ui.rs @@ -370,7 +370,7 @@ impl ProfilerUi { } } } - if ui.is_any_item_hovered() { + if ui.is_item_hovered() { ui.tooltip_text("Toggle with spacebar."); } @@ -381,7 +381,8 @@ impl ProfilerUi { ); ui.text(im_str!( - "Current frame: {:.1} ms, {} threads, {} scopes, {:.1} kB", + "Showing frame #{}, {:.1} ms, {} threads, {} scopes, {:.1} kB", + frame.frame_index, (max_ns - min_ns) as f64 * 1e-6, frame.thread_streams.len(), frame.num_scopes, diff --git a/puffin/Cargo.toml b/puffin/Cargo.toml index c0bf77c4..2884a256 100644 --- a/puffin/Cargo.toml +++ b/puffin/Cargo.toml @@ -15,6 +15,9 @@ include = [ "**/*.rs", "Cargo.toml"] [dependencies] byteorder = { version = "1" } once_cell = "1" +anyhow = { version = "1", optional = true } +bincode = { version = "1.3", optional = true } +lz4_flex = { version = "0.8.2", optional = true } serde = { version = "1", features = ["derive", "rc"], optional = true } [dev-dependencies] @@ -22,7 +25,8 @@ criterion = "0.3" [features] default = [] -with_serde = ["serde"] +# Feature for enabling loading/saving data to a binary stream and/or file. +serialization = ["anyhow", "bincode", "lz4_flex", "serde"] [[bench]] name = "benchmark" diff --git a/puffin/src/lib.rs b/puffin/src/lib.rs index 0d03018b..b64b1083 100644 --- a/puffin/src/lib.rs +++ b/puffin/src/lib.rs @@ -121,7 +121,10 @@ pub type NanoSecond = i64; /// Stream of profiling events from one thread. #[derive(Clone, Default)] -#[cfg_attr(feature = "with_serde", derive(serde::Deserialize, serde::Serialize))] +#[cfg_attr( + feature = "serialization", + derive(serde::Deserialize, serde::Serialize) +)] pub struct Stream(Vec); impl Stream { @@ -188,7 +191,10 @@ pub struct Scope<'s> { /// Used to identify one source of profiling data. #[derive(Clone, Debug, Eq, PartialEq, Ord, PartialOrd)] -#[cfg_attr(feature = "with_serde", derive(serde::Deserialize, serde::Serialize))] +#[cfg_attr( + feature = "serialization", + derive(serde::Deserialize, serde::Serialize) +)] pub struct ThreadInfo { /// Useful for ordering threads. pub start_time_ns: Option, @@ -202,7 +208,10 @@ pub type FrameIndex = u64; /// A `Stream` plus some info about it. #[derive(Clone)] -#[cfg_attr(feature = "with_serde", derive(serde::Deserialize, serde::Serialize))] +#[cfg_attr( + feature = "serialization", + derive(serde::Deserialize, serde::Serialize) +)] pub struct StreamInfo { /// The raw profile data. pub stream: Stream, @@ -271,7 +280,10 @@ impl StreamInfo { /// One frame worth of profile data, collected from many sources. #[derive(Clone)] -#[cfg_attr(feature = "with_serde", derive(serde::Deserialize, serde::Serialize))] +#[cfg_attr( + feature = "serialization", + derive(serde::Deserialize, serde::Serialize) +)] pub struct FrameData { pub frame_index: FrameIndex, pub thread_streams: BTreeMap>, @@ -319,6 +331,66 @@ impl FrameData { let (min, max) = self.range_ns; max - min } + + /// Writes one Frame into a stream, prefixed by it's length (u32 le). + #[cfg(feature = "serialization")] + pub fn write_into(&self, write: &mut impl std::io::Write) -> anyhow::Result<()> { + use bincode::Options as _; + let serialized = bincode::options().serialize(self)?; + let compressed = lz4_flex::compress_prepend_size(&serialized); + write.write_all(b"PFD0")?; + write.write_all(&(compressed.len() as u32).to_le_bytes())?; + write.write_all(&compressed)?; + Ok(()) + } + + /// Read the next [`FrameData`] from a stream. + /// + /// `None` is returned if the end of the stream is reached (EOF), + /// or an end-of-stream sentinel of 0u32 is read. + #[cfg(feature = "serialization")] + pub fn read_next(read: &mut impl std::io::Read) -> anyhow::Result> { + use anyhow::Context as _; + + let mut header = [0_u8; 4]; + if let Err(err) = read.read_exact(&mut header) { + if err.kind() == std::io::ErrorKind::UnexpectedEof { + return Ok(None); + } else { + return Err(err.into()); + } + } + + if header == [0_u8; 4] { + Ok(None) // end-of-stream sentinel. + } else if &header == b"PFD0" { + let mut compressed_length = [0_u8; 4]; + read.read_exact(&mut compressed_length)?; + let mut compressed = vec![0_u8; u32::from_le_bytes(compressed_length) as usize]; + read.read_exact(&mut compressed)?; + + let serialized = + lz4_flex::decompress_size_prepended(&compressed).context("lz4 decompress")?; + + use bincode::Options as _; + Ok(Some( + bincode::options() + .deserialize(&serialized) + .context("bincode deserialize")?, + )) + } else { + // Old packet without magic header + let mut bytes = vec![0_u8; u32::from_le_bytes(header) as usize]; + read.read_exact(&mut bytes)?; + + use bincode::Options as _; + Ok(Some( + bincode::options() + .deserialize(&bytes) + .context("bincode deserialize")?, + )) + } + } } // ---------------------------------------------------------------------------- @@ -440,6 +512,12 @@ impl Ord for OrderedData { } } +/// Add these to [`GlobalProfiler`] with [`GlobalProfiler::add_sink`]. +pub type FrameSink = Box) + Send>; + +#[derive(Clone, Copy, Debug, Hash, PartialEq, Eq)] +pub struct FrameSinkId(u64); + /// Singleton. Collects profiling data from multiple threads. pub struct GlobalProfiler { current_frame_index: FrameIndex, @@ -451,6 +529,9 @@ pub struct GlobalProfiler { slowest_frames: std::collections::BinaryHeap, max_slow: usize, + + next_sink_id: FrameSinkId, + sinks: std::collections::HashMap, } impl Default for GlobalProfiler { @@ -465,6 +546,8 @@ impl Default for GlobalProfiler { max_recent, slowest_frames: std::collections::BinaryHeap::with_capacity(max_slow), max_slow, + next_sink_id: FrameSinkId(1), + sinks: Default::default(), } } } @@ -501,6 +584,10 @@ impl GlobalProfiler { /// Manually add frame data. pub fn add_frame(&mut self, new_frame: Arc) { + for sink in self.sinks.values() { + sink(new_frame.clone()); + } + let add_to_slowest = if self.slowest_frames.len() < self.max_slow { true } else if let Some(fastest_of_the_slow) = self.slowest_frames.peek() { @@ -516,6 +603,15 @@ impl GlobalProfiler { } } + if let Some(last) = self.recent_frames.back() { + if new_frame.frame_index != last.frame_index + 1 { + // Keep `recent_frames` consecutive. + // Important when loading .puffin files which has both + // the slowest frames and most recent frames in the same stream. + self.recent_frames.clear(); + } + } + self.recent_frames.push_back(new_frame); while self.recent_frames.len() > self.max_recent { self.recent_frames.pop_front(); @@ -572,6 +668,69 @@ impl GlobalProfiler { pub fn set_max_slow(&mut self, max_slow: usize) { self.max_slow = max_slow; } + + /// Export profile data as a `.puffin` file. + #[cfg(feature = "serialization")] + pub fn save_to_path(&self, path: &std::path::Path) -> anyhow::Result<()> { + let mut file = std::fs::File::create(path)?; + self.save_to_writer(&mut file) + } + + /// Export profile data as a `.puffin` file. + #[cfg(feature = "serialization")] + pub fn save_to_writer(&self, write: &mut impl std::io::Write) -> anyhow::Result<()> { + write.write_all(b"PUF0")?; + + let slowest_frames = self.slowest_frames.iter().map(|f| &f.0); + let mut frames: Vec<_> = slowest_frames.chain(self.recent_frames.iter()).collect(); + frames.sort_by_key(|frame| frame.frame_index); + frames.dedup_by_key(|frame| frame.frame_index); + + for frame in frames { + frame.write_into(write)?; + } + Ok(()) + } + + /// Import profile data from a `.puffin` file. + #[cfg(feature = "serialization")] + pub fn load_path(path: &std::path::Path) -> anyhow::Result { + let mut file = std::fs::File::open(path)?; + Self::load_reader(&mut file) + } + + /// Import profile data from a `.puffin` file. + #[cfg(feature = "serialization")] + pub fn load_reader(read: &mut impl std::io::Read) -> anyhow::Result { + let mut magic = [0_u8; 4]; + read.read_exact(&mut magic)?; + if &magic != b"PUF0" { + anyhow::bail!("Expected .puffin magic header of 'PUF0', found {:?}", magic); + } + + let mut slf = Self { + max_recent: usize::MAX, + ..Default::default() + }; + while let Some(frame) = FrameData::read_next(read)? { + slf.add_frame(frame.into()); + } + + Ok(slf) + } + + /// Call this function with each new finished frame. + /// The returned [`FrameSinkId`] can be used to remove the sink with [`Self::remove_sink`]. + pub fn add_sink(&mut self, sink: FrameSink) -> FrameSinkId { + let id = self.next_sink_id; + self.next_sink_id.0 += 1; + self.sinks.insert(id, sink); + id + } + + pub fn remove_sink(&mut self, id: FrameSinkId) -> Option { + self.sinks.remove(&id) + } } // ---------------------------------------------------------------------------- diff --git a/puffin_egui/CHANGELOG.md b/puffin_egui/CHANGELOG.md index 3e61fa1f..1f18b66c 100644 --- a/puffin_egui/CHANGELOG.md +++ b/puffin_egui/CHANGELOG.md @@ -5,6 +5,8 @@ All notable changes to the egui crate will be documented in this file. ## Unreleased +* Show frame index. + ## 0.4.0 - 2021-07-05 diff --git a/puffin_egui/src/lib.rs b/puffin_egui/src/lib.rs index 707967fc..ca73069c 100644 --- a/puffin_egui/src/lib.rs +++ b/puffin_egui/src/lib.rs @@ -443,7 +443,8 @@ impl ProfilerUi { ); ui.separator(); ui.label(format!( - "Current frame: {:.1} ms, {} threads, {} scopes, {:.1} kB", + "Showing frame #{}, {:.1} ms, {} threads, {} scopes, {:.1} kB", + frame.frame_index, (max_ns - min_ns) as f64 * 1e-6, frame.thread_streams.len(), frame.num_scopes, diff --git a/puffin_http/CHANGELOG.md b/puffin_http/CHANGELOG.md new file mode 100644 index 00000000..77240d99 --- /dev/null +++ b/puffin_http/CHANGELOG.md @@ -0,0 +1,13 @@ +# Changelog + +All notable changes to `puffin_http` will be documented in this file. + + +## Unreleased +* Remove `Server::update` (no longer needed). +* Compress the TCP stream (approximately 75% bandwidth reduction). + + +## 0.3.0 +* Initial release + diff --git a/puffin_http/Cargo.toml b/puffin_http/Cargo.toml index 887e9738..cd180409 100644 --- a/puffin_http/Cargo.toml +++ b/puffin_http/Cargo.toml @@ -14,9 +14,8 @@ include = [ "**/*.rs", "Cargo.toml"] [dependencies] anyhow = "1" -bincode = "1.3" log = "0.4" -puffin = { version = "0.6.0", path = "../puffin", features = ["with_serde"] } +puffin = { version = "0.6.0", path = "../puffin", features = ["serialization"] } retain_mut = "0.1.3" serde = { version = "1", features = ["derive"] } diff --git a/puffin_http/examples/server.rs b/puffin_http/examples/server.rs index 394e01b3..c2c31a24 100644 --- a/puffin_http/examples/server.rs +++ b/puffin_http/examples/server.rs @@ -7,16 +7,36 @@ fn main() { let server_addr = format!("0.0.0.0:{}", puffin_http::DEFAULT_PORT); eprintln!("Serving demo profile data on {}", server_addr); - let puffin_server = puffin_http::Server::new(&server_addr).unwrap(); + let _puffin_server = puffin_http::Server::new(&server_addr).unwrap(); puffin::set_scopes_on(true); + let mut frame_counter = 0; + loop { puffin::profile_scope!("main_loop"); puffin::GlobalProfiler::lock().new_frame(); - puffin_server.update(); - sleep_ms(16); + // Give us something to inspect: + + std::thread::Builder::new() + .name("Other thread".to_owned()) + .spawn(|| { + sleep_ms(5); + }) + .unwrap(); + + sleep_ms(14); + if frame_counter % 7 == 0 { + puffin::profile_scope!("Spike"); + std::thread::sleep(std::time::Duration::from_millis(10)) + } + + for _ in 0..1000 { + puffin::profile_scope!("very thin"); + } + + frame_counter += 1; } } diff --git a/puffin_http/src/client.rs b/puffin_http/src/client.rs index 0a1c5d98..3bf0065b 100644 --- a/puffin_http/src/client.rs +++ b/puffin_http/src/client.rs @@ -3,6 +3,8 @@ use std::sync::{ Arc, }; +use puffin::FrameData; + /// Connect to a [`crate::Server`], reading profile data /// and feeding it to [`puffin::GlobalProfiler`]. /// @@ -53,7 +55,10 @@ impl Client { .add_frame(std::sync::Arc::new(frame_data)); } Err(err) => { - log::warn!("Connection to puffin server closed: {}", err); + log::warn!( + "Connection to puffin server closed: {}", + error_display_chain(err.as_ref()) + ); connected.store(false, SeqCst); break; } @@ -83,7 +88,7 @@ impl Client { } /// Read a `puffin_http` message from a stream. -pub fn consume_message(stream: &mut dyn std::io::Read) -> anyhow::Result { +pub fn consume_message(stream: &mut impl std::io::Read) -> anyhow::Result { let mut server_version = [0_u8; 2]; stream.read_exact(&mut server_version)?; let server_version = u16::from_le_bytes(server_version); @@ -99,24 +104,25 @@ pub fn consume_message(stream: &mut dyn std::io::Read) -> anyhow::Result {} std::cmp::Ordering::Greater => { anyhow::bail!( - "puffin server is using a newer protocol version ({}) than the client ({}). Update puffin_viewer with 'cargo install puffin_viewer'.", - server_version, - crate::PROTOCOL_VERSION - ); + "puffin server is using a newer protocol version ({}) than the client ({}). Update puffin_viewer with 'cargo install puffin_viewer'.", + server_version, + crate::PROTOCOL_VERSION + ); } } - let mut message_len = [0_u8; 4]; - stream.read_exact(&mut message_len)?; - let message_len = u32::from_le_bytes(message_len); - - let mut bytes = vec![0_u8; message_len as usize]; - stream.read_exact(&mut bytes)?; - use anyhow::Context as _; - use bincode::Options as _; + FrameData::read_next(stream) + .context("Failed to parse FrameData")? + .ok_or_else(|| anyhow::format_err!("End of stream")) +} - bincode::options() - .deserialize(&bytes) - .context("Failed to decode bincode") +/// Show full cause chain in a single line +fn error_display_chain(error: &dyn std::error::Error) -> String { + let mut s = error.to_string(); + if let Some(source) = error.source() { + s.push_str(" -> "); + s.push_str(&error_display_chain(source)); + } + s } diff --git a/puffin_http/src/server.rs b/puffin_http/src/server.rs index 3bf6ce62..fa859edd 100644 --- a/puffin_http/src/server.rs +++ b/puffin_http/src/server.rs @@ -1,4 +1,5 @@ use anyhow::Context as _; +use puffin::GlobalProfiler; use std::{ io::Write, net::{SocketAddr, TcpListener, TcpStream}, @@ -7,8 +8,10 @@ use std::{ /// Listens for incoming connections /// and streams them puffin profiler data. +/// +/// Drop to stop transmitting and listening for new connections. pub struct Server { - tx: std::sync::mpsc::Sender>, + sink_id: puffin::FrameSinkId, } impl Server { @@ -19,9 +22,8 @@ impl Server { .set_nonblocking(true) .context("TCP set_nonblocking")?; - let (tx, rx) = std::sync::mpsc::channel(); - - let server = Server { tx }; + let (tx, rx): (std::sync::mpsc::Sender>, _) = + std::sync::mpsc::channel(); std::thread::Builder::new() .name("puffin-server".to_owned()) @@ -42,15 +44,17 @@ impl Server { }) .context("Couldn't spawn thread")?; - Ok(server) + let sink_id = GlobalProfiler::lock().add_sink(Box::new(move |frame| { + tx.send(frame).ok(); + })); + + Ok(Server { sink_id }) } +} - /// Call this once per frame, right after calling [`puffin::GlobalProfiler::new_frame`]. - pub fn update(&self) { - let latest_frame = puffin::GlobalProfiler::lock().latest_frame(); - if let Some(latest_frame) = latest_frame { - self.tx.send(latest_frame).ok(); - } +impl Drop for Server { + fn drop(&mut self) { + GlobalProfiler::lock().remove_sink(self.sink_id); } } @@ -85,19 +89,13 @@ impl PuffinServerImpl { } pub fn send(&mut self, frame: &puffin::FrameData) -> anyhow::Result<()> { - use bincode::Options as _; - let mut encoded = bincode::options() - .serialize(frame) - .context("Encode puffin frame")?; - let mut message = vec![]; message .write_all(&crate::PROTOCOL_VERSION.to_le_bytes()) .unwrap(); - message - .write_all(&(encoded.len() as u32).to_le_bytes()) - .unwrap(); - message.append(&mut encoded); + frame + .write_into(&mut message) + .context("Encode puffin frame")?; use retain_mut::RetainMut as _; self.clients diff --git a/puffin_viewer/Cargo.toml b/puffin_viewer/Cargo.toml index d0cd9caa..e20048e5 100644 --- a/puffin_viewer/Cargo.toml +++ b/puffin_viewer/Cargo.toml @@ -14,7 +14,7 @@ include = [ "**/*.rs", "Cargo.toml"] [dependencies] puffin_egui = { version = "0.4.1", path = "../puffin_egui" } -puffin = { version = "0.6.0", path = "../puffin", features = ["with_serde"] } +puffin = { version = "0.6.0", path = "../puffin", features = ["serialization"] } puffin_http = { version = "0.3.0", path = "../puffin_http" } argh = "0.1"