diff --git a/CHANGELOG.md b/CHANGELOG.md index bc11f8f..4de7ad7 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,5 +1,15 @@ # Changelog +## [10.0.0] - 2021-09-xx + +### Changed +- `analyzeme`: Version-specific parts split out into `decodeme` crate. ([GH-181]) +- `analyzeme`: The crate now supports load both v7 and v8 of the file format. ([GH-181]) + +## [9.2.0] - 2021-09-13 +### Changed +- `analyzeme`: Makes a couple of methods in ProfilingData public. ([GH-180]) + ## [9.1.2] - 2021-05-21 ### Added - `measureme`: Allow recording interval events without using the drop guard ([GH-159]) @@ -92,6 +102,7 @@ ## [0.2.0] - 2019-04-10 +[9.2.0]: https://github.com/rust-lang/measureme/releases/tag/9.2.0 [9.1.2]: https://github.com/rust-lang/measureme/releases/tag/9.1.2 [9.1.1]: https://github.com/rust-lang/measureme/releases/tag/9.1.1 [9.1.0]: https://github.com/rust-lang/measureme/releases/tag/9.1.0 @@ -143,3 +154,5 @@ [GH-155]: https://github.com/rust-lang/measureme/pull/155 [GH-156]: https://github.com/rust-lang/measureme/pull/156 [GH-159]: https://github.com/rust-lang/measureme/pull/159 +[GH-180]: https://github.com/rust-lang/measureme/pull/180 +[GH-181]: https://github.com/rust-lang/measureme/pull/181 \ No newline at end of file diff --git a/Cargo.toml b/Cargo.toml index 4990890..d18ed24 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -3,6 +3,7 @@ members = [ "analyzeme", "crox", + "decodeme", "flamegraph", "measureme", "mmview", diff --git a/analyzeme/Cargo.toml b/analyzeme/Cargo.toml index 0a50faa..d474a5e 100644 --- a/analyzeme/Cargo.toml +++ b/analyzeme/Cargo.toml @@ -1,14 +1,19 @@ [package] name = "analyzeme" -version = "9.1.2" +version = "10.0.0-alpha" authors = ["Wesley Wiser ", "Michael Woerister "] edition = "2018" license = "MIT OR Apache-2.0" [dependencies] byteorder = "1.2.7" +decodeme = { path = "../decodeme" } memchr = "2" measureme = { path = "../measureme" } rustc-hash = "1.0.1" serde = { version = "1.0", features = [ "derive" ] } serde_json = "1.0" + +# Depending on older versions of this crate allows us to keep supporting older +# file formats. +analyzeme_9_2_0 = { package = "analyzeme", git = "https://github.com/rust-lang/measureme", tag = "9.2.0" } diff --git a/analyzeme/src/file_formats/mod.rs b/analyzeme/src/file_formats/mod.rs new file mode 100644 index 0000000..2864f47 --- /dev/null +++ b/analyzeme/src/file_formats/mod.rs @@ -0,0 +1,15 @@ +use decodeme::{event::Event, lightweight_event::LightweightEvent, Metadata}; +use std::fmt::Debug; + +pub mod v7; +pub mod v8; + +pub use v8 as current; + +/// The [EventDecoder] knows how to decode events for a specific file format. +pub trait EventDecoder: Debug + Send + Sync { + fn num_events(&self) -> usize; + fn metadata(&self) -> &Metadata; + fn decode_full_event<'a>(&'a self, event_index: usize) -> Event<'a>; + fn decode_lightweight_event<'a>(&'a self, event_index: usize) -> LightweightEvent; +} diff --git a/analyzeme/src/file_formats/v7.rs b/analyzeme/src/file_formats/v7.rs new file mode 100644 index 0000000..995853d --- /dev/null +++ b/analyzeme/src/file_formats/v7.rs @@ -0,0 +1,78 @@ +//! This module implements file loading for the v7 file format used until +//! crate version 9.2.0 + +use std::error::Error; + +use analyzeme_9_2_0::ProfilingData; +use decodeme::{ + event::Event, + event_payload::{EventPayload, Timestamp}, + lightweight_event::LightweightEvent, + Metadata, +}; + +pub const FILE_FORMAT: u32 = analyzeme_9_2_0::CURRENT_FILE_FORMAT_VERSION; + +#[derive(Debug)] +pub struct EventDecoder { + legacy_profiling_data: ProfilingData, + metadata: Metadata, +} + +impl EventDecoder { + pub fn new(entire_file_data: Vec) -> Result> { + let legacy_profiling_data = ProfilingData::from_paged_buffer(entire_file_data)?; + + let metadata = Metadata { + start_time: legacy_profiling_data.metadata.start_time, + cmd: legacy_profiling_data.metadata.cmd.clone(), + process_id: legacy_profiling_data.metadata.process_id, + }; + + Ok(EventDecoder { + legacy_profiling_data, + metadata, + }) + } +} + +impl super::EventDecoder for EventDecoder { + fn num_events(&self) -> usize { + self.legacy_profiling_data.num_events() + } + + fn metadata(&self) -> &Metadata { + &self.metadata + } + + fn decode_full_event(&self, event_index: usize) -> Event<'_> { + let legacy_event = self.legacy_profiling_data.decode_full_event(event_index); + let timestamp = convert_timestamp(legacy_event.timestamp); + + Event { + event_kind: legacy_event.event_kind, + label: legacy_event.label, + additional_data: legacy_event.additional_data, + thread_id: legacy_event.thread_id, + payload: EventPayload::Timestamp(timestamp), + } + } + + fn decode_lightweight_event(&self, event_index: usize) -> LightweightEvent { + let legacy_event = self + .legacy_profiling_data + .decode_lightweight_event(event_index); + LightweightEvent { + event_index, + thread_id: legacy_event.thread_id, + payload: EventPayload::Timestamp(convert_timestamp(legacy_event.timestamp)), + } + } +} + +fn convert_timestamp(legacy_timestamp: analyzeme_9_2_0::Timestamp) -> Timestamp { + match legacy_timestamp { + analyzeme_9_2_0::Timestamp::Interval { start, end } => Timestamp::Interval { start, end }, + analyzeme_9_2_0::Timestamp::Instant(t) => Timestamp::Instant(t), + } +} diff --git a/analyzeme/src/file_formats/v8.rs b/analyzeme/src/file_formats/v8.rs new file mode 100644 index 0000000..4ea4c9c --- /dev/null +++ b/analyzeme/src/file_formats/v8.rs @@ -0,0 +1,26 @@ +//! This module implements file loading for the v8 file format used until +//! crate version 10.0.0 + +use crate::{Event, LightweightEvent}; +pub use decodeme::EventDecoder; +use decodeme::Metadata; + +pub const FILE_FORMAT: u32 = decodeme::CURRENT_FILE_FORMAT_VERSION; + +impl super::EventDecoder for EventDecoder { + fn num_events(&self) -> usize { + self.num_events() + } + + fn metadata(&self) -> &Metadata { + self.metadata() + } + + fn decode_full_event(&self, event_index: usize) -> Event<'_> { + self.decode_full_event(event_index) + } + + fn decode_lightweight_event(&self, event_index: usize) -> LightweightEvent { + self.decode_lightweight_event(event_index) + } +} diff --git a/analyzeme/src/lib.rs b/analyzeme/src/lib.rs index 9f26b4c..acf36f4 100644 --- a/analyzeme/src/lib.rs +++ b/analyzeme/src/lib.rs @@ -10,17 +10,13 @@ //! To retrieve an `Iterator` of all of the events in the file, //! call the [`ProfilingData::iter()`] method. -mod event; -mod event_payload; -mod lightweight_event; +mod file_formats; mod profiling_data; mod stack_collapse; -mod stringtable; pub mod testing_common; -pub use crate::event::Event; -pub use crate::event_payload::{EventPayload, Timestamp}; -pub use crate::lightweight_event::LightweightEvent; pub use crate::profiling_data::{ProfilingData, ProfilingDataBuilder}; pub use crate::stack_collapse::collapse_stacks; -pub use crate::stringtable::{StringRef, StringTable}; +pub use decodeme::event::Event; +pub use decodeme::event_payload::{EventPayload, Timestamp}; +pub use decodeme::lightweight_event::LightweightEvent; diff --git a/analyzeme/src/lightweight_event.rs b/analyzeme/src/lightweight_event.rs deleted file mode 100644 index 0c89507..0000000 --- a/analyzeme/src/lightweight_event.rs +++ /dev/null @@ -1,84 +0,0 @@ -use crate::event::Event; -use crate::event_payload::{EventPayload, Timestamp}; -use crate::profiling_data::ProfilingData; -use std::hash::{Hash, Hasher}; -use std::time::{Duration, SystemTime}; - -#[derive(Clone, Debug)] -pub struct LightweightEvent<'a> { - pub data: &'a ProfilingData, - pub event_index: usize, - pub thread_id: u32, - pub payload: EventPayload, -} - -impl<'a> LightweightEvent<'a> { - pub fn to_event(&self) -> Event<'a> { - self.data.decode_full_event(self.event_index) - } - - /// Returns true if the time interval of `self` completely contains the - /// time interval of `other`. - pub fn contains(&self, other: &LightweightEvent) -> bool { - self.payload.contains(&other.payload) - } - - pub fn duration(&self) -> Option { - self.payload.duration() - } - - // Returns start time if event is a timestamp - pub fn start(&self) -> Option { - self.payload.timestamp().map(|t| t.start()) - } - - // Returns end time if event is a timestamp - pub fn end(&self) -> Option { - self.payload.timestamp().map(|t| t.end()) - } - - pub fn timestamp(&self) -> Option { - self.payload.timestamp() - } -} - -impl<'a> PartialEq for LightweightEvent<'a> { - fn eq(&self, other: &LightweightEvent<'a>) -> bool { - let LightweightEvent { - data, - event_index, - thread_id, - payload, - } = *self; - - let LightweightEvent { - data: other_data, - event_index: other_event_index, - thread_id: other_thread_id, - payload: other_payload, - } = *other; - - std::ptr::eq(data, other_data) - && event_index == other_event_index - && thread_id == other_thread_id - && payload == other_payload - } -} - -impl<'a> Eq for LightweightEvent<'a> {} - -impl<'a> Hash for LightweightEvent<'a> { - fn hash(&self, state: &mut H) { - let LightweightEvent { - data, - event_index, - thread_id, - payload, - } = *self; - - std::ptr::hash(data, state); - event_index.hash(state); - thread_id.hash(state); - payload.hash(state); - } -} diff --git a/analyzeme/src/profiling_data.rs b/analyzeme/src/profiling_data.rs index 17fbbd7..95e18b5 100644 --- a/analyzeme/src/profiling_data.rs +++ b/analyzeme/src/profiling_data.rs @@ -1,47 +1,20 @@ -use crate::event::Event; -use crate::event_payload::EventPayload; -use crate::lightweight_event::LightweightEvent; -use crate::StringTable; +use crate::file_formats::EventDecoder; +use crate::{file_formats, Event, LightweightEvent}; +use decodeme::{read_file_header, Metadata}; use measureme::file_header::{ - verify_file_header, write_file_header, FILE_EXTENSION, FILE_HEADER_SIZE, - FILE_MAGIC_EVENT_STREAM, FILE_MAGIC_TOP_LEVEL, + write_file_header, FILE_EXTENSION, FILE_MAGIC_EVENT_STREAM, FILE_MAGIC_TOP_LEVEL, }; use measureme::{ EventId, PageTag, RawEvent, SerializationSink, SerializationSinkBuilder, StringTableBuilder, }; -use serde::{Deserialize, Deserializer}; use std::fs; -use std::mem; use std::path::Path; use std::sync::Arc; -use std::time::{Duration, SystemTime, UNIX_EPOCH}; use std::{error::Error, path::PathBuf}; -const RAW_EVENT_SIZE: usize = mem::size_of::(); - -fn system_time_from_nanos<'de, D>(deserializer: D) -> Result -where - D: Deserializer<'de>, -{ - let duration_from_epoch = Duration::from_nanos(u64::deserialize(deserializer)?); - Ok(UNIX_EPOCH - .checked_add(duration_from_epoch) - .expect("a time that can be represented as SystemTime")) -} - -#[derive(Debug, Deserialize)] -pub struct Metadata { - #[serde(deserialize_with = "system_time_from_nanos")] - pub start_time: SystemTime, - pub process_id: u32, - pub cmd: String, -} - #[derive(Debug)] pub struct ProfilingData { - event_data: Vec, - string_table: StringTable, - pub metadata: Metadata, + event_decoder: Box, } impl ProfilingData { @@ -50,16 +23,7 @@ impl ProfilingData { if paged_path.exists() { let data = fs::read(&paged_path)?; - - verify_file_header(&data, FILE_MAGIC_TOP_LEVEL, Some(&paged_path), "top-level")?; - - let mut split_data = measureme::split_streams(&data[FILE_HEADER_SIZE..]); - - let string_data = split_data.remove(&PageTag::StringData).unwrap(); - let index_data = split_data.remove(&PageTag::StringIndex).unwrap(); - let event_data = split_data.remove(&PageTag::Events).unwrap(); - - ProfilingData::from_buffers(string_data, index_data, event_data, Some(&paged_path)) + ProfilingData::from_paged_buffer(data, Some(&paged_path)) } else { let mut msg = format!( "Could not find profiling data file `{}`.", @@ -82,97 +46,74 @@ impl ProfilingData { } } - pub fn from_paged_buffer(data: Vec) -> Result> { - verify_file_header(&data, FILE_MAGIC_TOP_LEVEL, None, "top-level")?; - - let mut split_data = measureme::split_streams(&data[FILE_HEADER_SIZE..]); - - let string_data = split_data.remove(&PageTag::StringData).unwrap(); - let index_data = split_data.remove(&PageTag::StringIndex).unwrap(); - let event_data = split_data.remove(&PageTag::Events).unwrap(); - - ProfilingData::from_buffers(string_data, index_data, event_data, None) - } - - pub fn from_buffers( - string_data: Vec, - string_index: Vec, - events: Vec, + pub fn from_paged_buffer( + data: Vec, diagnostic_file_path: Option<&Path>, ) -> Result> { - let index_data = string_index; - let event_data = events; + // let event_decoder = EventDecoder::new(data, diagnostic_file_path)?; + // Ok(ProfilingData { event_decoder }) - verify_file_header( - &event_data, - FILE_MAGIC_EVENT_STREAM, + let file_format_version = read_file_header( + &data, + FILE_MAGIC_TOP_LEVEL, diagnostic_file_path, - "event", + "top-level", )?; - let string_table = StringTable::new(string_data, index_data, diagnostic_file_path)?; + let event_decoder: Box = match file_format_version { + file_formats::v7::FILE_FORMAT => Box::new(file_formats::v7::EventDecoder::new(data)?), + file_formats::v8::FILE_FORMAT => Box::new(file_formats::v8::EventDecoder::new( + data, + diagnostic_file_path, + )?), + unsupported_version => { + let msg = if unsupported_version > file_formats::current::FILE_FORMAT { + format!( + "File version {} is too new for this version of measureme. Try upgrading your tools to the latest version.", + unsupported_version + ) + } else { + format!( + "File version {} is too new for this version of the measureme tool suite. Try upgrading the tool suite to the latest version.", + unsupported_version + ) + }; + + return Err(From::from(msg)); + } + }; - let metadata = string_table.get_metadata().to_string(); - let metadata: Metadata = serde_json::from_str(&metadata)?; + Ok(ProfilingData { event_decoder }) + } - Ok(ProfilingData { - string_table, - event_data, - metadata, - }) + pub fn metadata(&self) -> &Metadata { + self.event_decoder.metadata() } pub fn iter<'a>(&'a self) -> ProfilerEventIterator<'a> { ProfilerEventIterator::new(&self) } - pub fn num_events(&self) -> usize { - let event_byte_count = self.event_data.len() - FILE_HEADER_SIZE; - assert!(event_byte_count % RAW_EVENT_SIZE == 0); - event_byte_count / RAW_EVENT_SIZE + pub fn iter_full<'a>( + &'a self, + ) -> impl Iterator> + DoubleEndedIterator + ExactSizeIterator + 'a { + self.iter().map(move |e| self.to_full_event(&e)) } - pub(crate) fn decode_full_event<'a>(&'a self, event_index: usize) -> Event<'a> { - let event_start_addr = event_index_to_addr(event_index); - let event_end_addr = event_start_addr.checked_add(RAW_EVENT_SIZE).unwrap(); - - let raw_event_bytes = &self.event_data[event_start_addr..event_end_addr]; - let raw_event = RawEvent::deserialize(raw_event_bytes); - - let string_table = &self.string_table; - - let payload = EventPayload::from_raw_event(&raw_event, self.metadata.start_time); - - let event_id = string_table - .get(raw_event.event_id.to_string_id()) - .to_string(); - // Parse out the label and arguments from the `event_id`. - let (label, additional_data) = Event::parse_event_id(event_id); - - Event { - event_kind: string_table.get(raw_event.event_kind).to_string(), - label, - additional_data, - payload, - thread_id: raw_event.thread_id, - } + pub fn num_events(&self) -> usize { + self.event_decoder.num_events() } - fn decode_lightweight_event<'a>(&'a self, event_index: usize) -> LightweightEvent<'a> { - let event_start_addr = event_index_to_addr(event_index); - let event_end_addr = event_start_addr.checked_add(RAW_EVENT_SIZE).unwrap(); - - let raw_event_bytes = &self.event_data[event_start_addr..event_end_addr]; - let raw_event = RawEvent::deserialize(raw_event_bytes); + pub fn to_full_event<'a>(&'a self, light_weight_event: &LightweightEvent) -> Event<'a> { + self.decode_full_event(light_weight_event.event_index) + } - let payload = EventPayload::from_raw_event(&raw_event, self.metadata.start_time); + pub(crate) fn decode_full_event<'a>(&'a self, event_index: usize) -> Event<'a> { + self.event_decoder.decode_full_event(event_index) + } - LightweightEvent { - data: self, - event_index, - payload, - thread_id: raw_event.thread_id, - } + fn decode_lightweight_event(&self, event_index: usize) -> LightweightEvent { + self.event_decoder.decode_lightweight_event(event_index) } } @@ -193,9 +134,9 @@ impl<'a> ProfilerEventIterator<'a> { } impl<'a> Iterator for ProfilerEventIterator<'a> { - type Item = LightweightEvent<'a>; + type Item = LightweightEvent; - fn next(&mut self) -> Option> { + fn next(&mut self) -> Option { if self.forward_event_idx == self.backward_event_idx { return None; } @@ -261,6 +202,11 @@ impl ProfilingDataBuilder { ) .unwrap(); + string_table.alloc_metadata(&*format!( + r#"{{ "start_time": {}, "process_id": {}, "cmd": "{}" }}"#, + 0, 0, "test cmd", + )); + ProfilingDataBuilder { event_sink, string_table_data_sink, @@ -338,26 +284,23 @@ impl ProfilingDataBuilder { drop(self.string_table); let event_data = self.event_sink.into_bytes(); - let data_bytes = Arc::try_unwrap(self.string_table_data_sink) + let string_data = Arc::try_unwrap(self.string_table_data_sink) .unwrap() .into_bytes(); - let index_bytes = Arc::try_unwrap(self.string_table_index_sink) + let index_data = Arc::try_unwrap(self.string_table_index_sink) .unwrap() .into_bytes(); - verify_file_header(&event_data, FILE_MAGIC_EVENT_STREAM, None, "event").unwrap(); - - let string_table = StringTable::new(data_bytes, index_bytes, None).unwrap(); - let metadata = Metadata { - start_time: UNIX_EPOCH, - process_id: 0, - cmd: "test cmd".to_string(), - }; - ProfilingData { - event_data, - string_table, - metadata, + event_decoder: Box::new( + file_formats::current::EventDecoder::from_separate_buffers( + string_data, + index_data, + event_data, + None, + ) + .unwrap(), + ), } } @@ -371,10 +314,6 @@ impl ProfilingDataBuilder { impl<'a> ExactSizeIterator for ProfilerEventIterator<'a> {} -fn event_index_to_addr(event_index: usize) -> usize { - FILE_HEADER_SIZE + event_index * mem::size_of::() -} - // This struct reflects what filenames were in old versions of measureme. It is // used only for giving helpful error messages now if a user tries to load old // data. @@ -398,8 +337,8 @@ impl ProfilerFiles { #[cfg(test)] mod tests { use super::*; - use std::borrow::Cow; - use crate::event_payload::Timestamp; + use std::{borrow::Cow, time::SystemTime}; + use crate::{EventPayload, Timestamp}; use std::time::Duration; fn full_interval( @@ -437,7 +376,7 @@ mod tests { thread_id, } } - + fn full_integer( event_kind: &'static str, label: &'static str, @@ -454,14 +393,12 @@ mod tests { } fn lightweight_interval<'a>( - data: &'a ProfilingData, event_index: usize, thread_id: u32, start_nanos: u64, end_nanos: u64, - ) -> LightweightEvent<'a> { + ) -> LightweightEvent { LightweightEvent { - data, event_index, thread_id, payload: EventPayload::Timestamp(Timestamp::Interval { @@ -472,13 +409,11 @@ mod tests { } fn lightweight_instant<'a>( - data: &'a ProfilingData, event_index: usize, thread_id: u32, timestamp_nanos: u64, - ) -> LightweightEvent<'a> { + ) -> LightweightEvent { LightweightEvent { - data, event_index, thread_id, payload: EventPayload::Timestamp(Timestamp::Instant( @@ -488,13 +423,11 @@ mod tests { } fn lightweight_integer<'a>( - data: &'a ProfilingData, event_index: usize, thread_id: u32, value: u64, - ) -> LightweightEvent<'a> { + ) -> LightweightEvent { LightweightEvent { - data, event_index, thread_id, payload: EventPayload::Integer(value), @@ -512,15 +445,15 @@ mod tests { let profiling_data = builder.into_profiling_data(); - let events: Vec> = profiling_data.iter().collect(); + let events: Vec = profiling_data.iter().collect(); - assert_eq!(events[0], lightweight_interval(&profiling_data, 0, 0, 10, 100)); - assert_eq!(events[1], lightweight_interval(&profiling_data, 1, 1, 100, 110)); - assert_eq!(events[2], lightweight_interval(&profiling_data, 2, 0, 120, 140)); + assert_eq!(events[0], lightweight_interval(0, 0, 10, 100)); + assert_eq!(events[1], lightweight_interval(1, 1, 100, 110)); + assert_eq!(events[2], lightweight_interval(2, 0, 120, 140)); - assert_eq!(events[0].to_event(), full_interval("k1", "id1", 0, 10, 100)); - assert_eq!(events[1].to_event(), full_interval("k2", "id2", 1, 100, 110)); - assert_eq!(events[2].to_event(), full_interval("k3", "id3", 0, 120, 140)); + assert_eq!(profiling_data.to_full_event(&events[0]), full_interval("k1", "id1", 0, 10, 100)); + assert_eq!(profiling_data.to_full_event(&events[1]), full_interval("k2", "id2", 1, 100, 110)); + assert_eq!(profiling_data.to_full_event(&events[2]), full_interval("k3", "id3", 0, 120, 140)); } #[test] @@ -535,15 +468,15 @@ mod tests { let profiling_data = b.into_profiling_data(); - let events: Vec> = profiling_data.iter().collect(); + let events: Vec = profiling_data.iter().collect(); - assert_eq!(events[0], lightweight_interval(&profiling_data, 0, 0, 30, 90)); - assert_eq!(events[1], lightweight_interval(&profiling_data, 1, 0, 20, 100)); - assert_eq!(events[2], lightweight_interval(&profiling_data, 2, 0, 10, 100)); + assert_eq!(events[0], lightweight_interval(0, 0, 30, 90)); + assert_eq!(events[1], lightweight_interval(1, 0, 20, 100)); + assert_eq!(events[2], lightweight_interval(2, 0, 10, 100)); - assert_eq!(events[0].to_event(), full_interval("k3", "id3", 0, 30, 90)); - assert_eq!(events[1].to_event(), full_interval("k2", "id2", 0, 20, 100)); - assert_eq!(events[2].to_event(), full_interval("k1", "id1", 0, 10, 100)); + assert_eq!(profiling_data.to_full_event(&events[0]), full_interval("k3", "id3", 0, 30, 90)); + assert_eq!(profiling_data.to_full_event(&events[1]), full_interval("k2", "id2", 0, 20, 100)); + assert_eq!(profiling_data.to_full_event(&events[2]), full_interval("k1", "id1", 0, 10, 100)); } #[test] @@ -563,22 +496,22 @@ mod tests { let profiling_data = b.into_profiling_data(); - let events: Vec> = profiling_data.iter().collect(); - - assert_eq!(events[0], lightweight_instant(&profiling_data, 0, 0, 70)); - assert_eq!(events[1], lightweight_integer(&profiling_data, 1, 0, 42)); - assert_eq!(events[2], lightweight_instant(&profiling_data, 2, 0, 75)); - assert_eq!(events[3], lightweight_interval(&profiling_data, 3, 0, 30, 90)); - assert_eq!(events[4], lightweight_interval(&profiling_data, 4, 0, 20, 92)); - assert_eq!(events[5], lightweight_instant(&profiling_data, 5, 0, 95)); - assert_eq!(events[6], lightweight_interval(&profiling_data, 6, 0, 10, 100)); - - assert_eq!(events[0].to_event(), full_instant("k4", "id4", 0, 70)); - assert_eq!(events[1].to_event(), full_integer("k5", "id5", 0, 42)); - assert_eq!(events[2].to_event(), full_instant("k6", "id6", 0, 75)); - assert_eq!(events[3].to_event(), full_interval("k3", "id3", 0, 30, 90)); - assert_eq!(events[4].to_event(), full_interval("k2", "id2", 0, 20, 92)); - assert_eq!(events[5].to_event(), full_instant("k7", "id7", 0, 95)); - assert_eq!(events[6].to_event(), full_interval("k1", "id1", 0, 10, 100)); + let events: Vec = profiling_data.iter().collect(); + + assert_eq!(events[0], lightweight_instant(0, 0, 70)); + assert_eq!(events[1], lightweight_integer(1, 0, 42)); + assert_eq!(events[2], lightweight_instant(2, 0, 75)); + assert_eq!(events[3], lightweight_interval(3, 0, 30, 90)); + assert_eq!(events[4], lightweight_interval(4, 0, 20, 92)); + assert_eq!(events[5], lightweight_instant(5, 0, 95)); + assert_eq!(events[6], lightweight_interval(6, 0, 10, 100)); + + assert_eq!(profiling_data.to_full_event(&events[0]), full_instant("k4", "id4", 0, 70)); + assert_eq!(profiling_data.to_full_event(&events[1]), full_integer("k5", "id5", 0, 42)); + assert_eq!(profiling_data.to_full_event(&events[2]), full_instant("k6", "id6", 0, 75)); + assert_eq!(profiling_data.to_full_event(&events[3]), full_interval("k3", "id3", 0, 30, 90)); + assert_eq!(profiling_data.to_full_event(&events[4]), full_interval("k2", "id2", 0, 20, 92)); + assert_eq!(profiling_data.to_full_event(&events[5]), full_instant("k7", "id7", 0, 95)); + assert_eq!(profiling_data.to_full_event(&events[6]), full_interval("k1", "id1", 0, 10, 100)); } } diff --git a/analyzeme/src/stack_collapse.rs b/analyzeme/src/stack_collapse.rs index f31335a..531dbd6 100644 --- a/analyzeme/src/stack_collapse.rs +++ b/analyzeme/src/stack_collapse.rs @@ -5,8 +5,8 @@ use std::time::SystemTime; use crate::{LightweightEvent, ProfilingData}; // This state is kept up-to-date while iteration over events. -struct PerThreadState<'a> { - stack: Vec>, +struct PerThreadState { + stack: Vec, stack_id: String, start: SystemTime, end: SystemTime, @@ -19,7 +19,7 @@ struct PerThreadState<'a> { // https://github.com/michaelwoerister/measureme/pull/1 pub fn collapse_stacks<'a>(profiling_data: &ProfilingData) -> FxHashMap { let mut counters = FxHashMap::default(); - let mut threads = FxHashMap::<_, PerThreadState<'_>>::default(); + let mut threads = FxHashMap::<_, PerThreadState>::default(); for current_event in profiling_data .iter() @@ -48,7 +48,8 @@ pub fn collapse_stacks<'a>(profiling_data: &ProfilingData) -> FxHashMap(profiling_data: &ProfilingData) -> FxHashMap]) { // Check iterating forward over the events check_profiling_data( - &mut profiling_data.iter().map(|e| e.to_event()), + &mut profiling_data.iter_full(), &mut expected_events.iter().cloned(), expected_events.len(), ); // Check iterating backwards over the events check_profiling_data( - &mut profiling_data.iter().rev().map(|e| e.to_event()), + &mut profiling_data.iter_full().rev(), &mut expected_events.iter().rev().cloned(), expected_events.len(), ); diff --git a/crox/Cargo.toml b/crox/Cargo.toml index 020d855..faa459a 100644 --- a/crox/Cargo.toml +++ b/crox/Cargo.toml @@ -1,6 +1,6 @@ [package] name = "crox" -version = "9.1.2" +version = "10.0.0-alpha" authors = ["Wesley Wiser "] edition = "2018" diff --git a/crox/src/main.rs b/crox/src/main.rs index 9287a6d..f693505 100644 --- a/crox/src/main.rs +++ b/crox/src/main.rs @@ -159,14 +159,14 @@ fn main() -> Result<(), Box> { continue; } } - let full_event = event.to_event(); + let full_event = data.to_full_event(&event); let crox_event = Event { name: full_event.label.clone().into_owned(), category: full_event.event_kind.clone().into_owned(), event_type: EventType::Complete, timestamp: event.start().unwrap().duration_since(UNIX_EPOCH).unwrap(), duration, - process_id: data.metadata.process_id, + process_id: data.metadata().process_id, thread_id: *thread_to_collapsed_thread .get(&event.thread_id) .unwrap_or(&event.thread_id), @@ -176,12 +176,12 @@ fn main() -> Result<(), Box> { } // add crate name for the process_id let index_of_crate_name = data - .metadata + .metadata() .cmd .find(" --crate-name ") .map(|index| index + 14); if let Some(index) = index_of_crate_name { - let (_, last) = data.metadata.cmd.split_at(index); + let (_, last) = data.metadata().cmd.split_at(index); let (crate_name, _) = last.split_at(last.find(" ").unwrap_or(last.len())); let process_name = json!({ @@ -190,7 +190,7 @@ fn main() -> Result<(), Box> { "ts" : 0, "tid" : 0, "cat" : "", - "pid" : data.metadata.process_id, + "pid" : data.metadata().process_id, "args": { "name" : crate_name } @@ -204,9 +204,9 @@ fn main() -> Result<(), Box> { "ts" : 0, "tid" : 0, "cat" : "", - "pid" : data.metadata.process_id, + "pid" : data.metadata().process_id, "args": { - "sort_index" : data.metadata.start_time.duration_since(UNIX_EPOCH).unwrap().as_micros() as u64 + "sort_index" : data.metadata().start_time.duration_since(UNIX_EPOCH).unwrap().as_micros() as u64 } }); seq.serialize_element(&process_name)?; diff --git a/decodeme/Cargo.toml b/decodeme/Cargo.toml new file mode 100644 index 0000000..cebf2bb --- /dev/null +++ b/decodeme/Cargo.toml @@ -0,0 +1,13 @@ +[package] +name = "decodeme" +version = "10.0.0-alpha" +edition = "2018" + +# See more keys and their definitions at https://doc.rust-lang.org/cargo/reference/manifest.html + +[dependencies] +measureme = { path = "../measureme" } +memchr = "2" +rustc-hash = "1.0.1" +serde = { version = "1.0", features = [ "derive" ] } +serde_json = "1.0" diff --git a/analyzeme/src/event.rs b/decodeme/src/event.rs similarity index 100% rename from analyzeme/src/event.rs rename to decodeme/src/event.rs diff --git a/analyzeme/src/event_payload.rs b/decodeme/src/event_payload.rs similarity index 100% rename from analyzeme/src/event_payload.rs rename to decodeme/src/event_payload.rs diff --git a/decodeme/src/lib.rs b/decodeme/src/lib.rs new file mode 100644 index 0000000..8fddec1 --- /dev/null +++ b/decodeme/src/lib.rs @@ -0,0 +1,204 @@ +use std::convert::TryInto; +use std::{ + error::Error, + mem, + path::Path, + time::{Duration, SystemTime, UNIX_EPOCH}, +}; + +use event::Event; +use event_payload::EventPayload; +use lightweight_event::LightweightEvent; +use measureme::file_header::{verify_file_header, FILE_MAGIC_EVENT_STREAM}; + +pub mod event; +pub mod event_payload; +pub mod lightweight_event; +pub mod stringtable; + +// These re-exports allow us to use some types from the measureme version tied to this +// version of decodeme, with explicitly mentioning that measureme version in downstream +// Cargo.tomls. +pub use measureme::file_header::CURRENT_FILE_FORMAT_VERSION; +pub use measureme::file_header::FILE_HEADER_SIZE; +pub use measureme::file_header::FILE_MAGIC_TOP_LEVEL; +pub use measureme::PageTag; +pub use measureme::RawEvent; + +use serde::{Deserialize, Deserializer}; +use stringtable::StringTable; + +fn system_time_from_nanos<'de, D>(deserializer: D) -> Result +where + D: Deserializer<'de>, +{ + let duration_from_epoch = Duration::from_nanos(u64::deserialize(deserializer)?); + Ok(UNIX_EPOCH + .checked_add(duration_from_epoch) + .expect("a time that can be represented as SystemTime")) +} + +#[derive(Debug, Deserialize)] +pub struct Metadata { + #[serde(deserialize_with = "system_time_from_nanos")] + pub start_time: SystemTime, + pub process_id: u32, + pub cmd: String, +} + +#[must_use] +pub fn read_file_header( + bytes: &[u8], + expected_magic: &[u8; 4], + diagnostic_file_path: Option<&Path>, + stream_tag: &str, +) -> Result> { + // The implementation here relies on FILE_HEADER_SIZE to have the value 8. + // Let's make sure this assumption cannot be violated without being noticed. + assert_eq!(FILE_HEADER_SIZE, 8); + + let diagnostic_file_path = diagnostic_file_path.unwrap_or(Path::new("")); + + if bytes.len() < FILE_HEADER_SIZE { + let msg = format!( + "Error reading {} stream in file `{}`: Expected file to contain at least `{:?}` bytes but found `{:?}` bytes", + stream_tag, + diagnostic_file_path.display(), + FILE_HEADER_SIZE, + bytes.len() + ); + + return Err(From::from(msg)); + } + + let actual_magic = &bytes[0..4]; + + if actual_magic != expected_magic { + let msg = format!( + "Error reading {} stream in file `{}`: Expected file magic `{:?}` but found `{:?}`", + stream_tag, + diagnostic_file_path.display(), + expected_magic, + actual_magic + ); + + return Err(From::from(msg)); + } + + let file_format_version = u32::from_le_bytes(bytes[4..8].try_into().unwrap()); + + Ok(file_format_version) +} + +const RAW_EVENT_SIZE: usize = std::mem::size_of::(); + +#[derive(Debug)] +pub struct EventDecoder { + event_data: Vec, + stringtable: StringTable, + metadata: Metadata, +} + +impl EventDecoder { + pub fn new( + entire_file_data: Vec, + diagnostic_file_path: Option<&Path>, + ) -> Result> { + verify_file_header( + &entire_file_data, + FILE_MAGIC_TOP_LEVEL, + diagnostic_file_path, + "top-level", + )?; + + let mut split_data = measureme::split_streams(&entire_file_data[FILE_HEADER_SIZE..]); + + let string_data = split_data.remove(&PageTag::StringData).unwrap(); + let index_data = split_data.remove(&PageTag::StringIndex).unwrap(); + let event_data = split_data.remove(&PageTag::Events).unwrap(); + + Self::from_separate_buffers(string_data, index_data, event_data, diagnostic_file_path) + } + + pub fn from_separate_buffers( + string_data: Vec, + index_data: Vec, + event_data: Vec, + diagnostic_file_path: Option<&Path>, + ) -> Result> { + verify_file_header( + &event_data, + FILE_MAGIC_EVENT_STREAM, + diagnostic_file_path, + "event", + )?; + + let stringtable = StringTable::new(string_data, index_data, diagnostic_file_path)?; + + let metadata = stringtable.get_metadata().to_string(); + let metadata: Metadata = serde_json::from_str(&metadata)?; + + Ok(EventDecoder { + event_data, + stringtable, + metadata, + }) + } + + pub fn num_events(&self) -> usize { + let event_byte_count = self.event_data.len() - FILE_HEADER_SIZE; + assert!(event_byte_count % RAW_EVENT_SIZE == 0); + event_byte_count / RAW_EVENT_SIZE + } + + pub fn metadata(&self) -> &Metadata { + &self.metadata + } + + pub fn decode_full_event<'a>(&'a self, event_index: usize) -> Event<'a> { + let event_start_addr = event_index_to_addr(event_index); + let event_end_addr = event_start_addr.checked_add(RAW_EVENT_SIZE).unwrap(); + + let raw_event_bytes = &self.event_data[event_start_addr..event_end_addr]; + let raw_event = RawEvent::deserialize(raw_event_bytes); + + let stringtable = &self.stringtable; + + let payload = EventPayload::from_raw_event(&raw_event, self.metadata.start_time); + + let event_id = stringtable + .get(raw_event.event_id.to_string_id()) + .to_string(); + + // Parse out the label and arguments from the `event_id`. + let (label, additional_data) = Event::parse_event_id(event_id); + + Event { + event_kind: stringtable.get(raw_event.event_kind).to_string(), + label, + additional_data, + payload, + thread_id: raw_event.thread_id, + } + } + + pub fn decode_lightweight_event<'a>(&'a self, event_index: usize) -> LightweightEvent { + let event_start_addr = event_index_to_addr(event_index); + let event_end_addr = event_start_addr.checked_add(RAW_EVENT_SIZE).unwrap(); + + let raw_event_bytes = &self.event_data[event_start_addr..event_end_addr]; + let raw_event = RawEvent::deserialize(raw_event_bytes); + + let payload = EventPayload::from_raw_event(&raw_event, self.metadata.start_time); + + LightweightEvent { + event_index, + payload, + thread_id: raw_event.thread_id, + } + } +} + +fn event_index_to_addr(event_index: usize) -> usize { + FILE_HEADER_SIZE + event_index * mem::size_of::() +} diff --git a/decodeme/src/lightweight_event.rs b/decodeme/src/lightweight_event.rs new file mode 100644 index 0000000..3300eba --- /dev/null +++ b/decodeme/src/lightweight_event.rs @@ -0,0 +1,35 @@ +use crate::event_payload::{EventPayload, Timestamp}; +use std::time::{Duration, SystemTime}; + +#[derive(Clone, Debug, PartialEq, Eq, Hash)] +pub struct LightweightEvent { + pub event_index: usize, + pub thread_id: u32, + pub payload: EventPayload, +} + +impl LightweightEvent { + /// Returns true if the time interval of `self` completely contains the + /// time interval of `other`. + pub fn contains(&self, other: &LightweightEvent) -> bool { + self.payload.contains(&other.payload) + } + + pub fn duration(&self) -> Option { + self.payload.duration() + } + + // Returns start time if event is a timestamp + pub fn start(&self) -> Option { + self.payload.timestamp().map(|t| t.start()) + } + + // Returns end time if event is a timestamp + pub fn end(&self) -> Option { + self.payload.timestamp().map(|t| t.end()) + } + + pub fn timestamp(&self) -> Option { + self.payload.timestamp() + } +} diff --git a/analyzeme/src/stringtable.rs b/decodeme/src/stringtable.rs similarity index 100% rename from analyzeme/src/stringtable.rs rename to decodeme/src/stringtable.rs diff --git a/flamegraph/Cargo.toml b/flamegraph/Cargo.toml index 377e116..419d511 100644 --- a/flamegraph/Cargo.toml +++ b/flamegraph/Cargo.toml @@ -1,6 +1,6 @@ [package] name = "flamegraph" -version = "9.1.2" +version = "10.0.0-alpha" authors = ["Wesley Wiser ", "Michael Woerister "] edition = "2018" license = "MIT OR Apache-2.0" diff --git a/measureme/Cargo.toml b/measureme/Cargo.toml index 191f81e..b218637 100644 --- a/measureme/Cargo.toml +++ b/measureme/Cargo.toml @@ -1,6 +1,6 @@ [package] name = "measureme" -version = "9.1.2" +version = "10.0.0-alpha" authors = ["Wesley Wiser ", "Michael Woerister "] edition = "2018" description = "Support crate for rustc's self-profiling feature" diff --git a/measureme/src/file_header.rs b/measureme/src/file_header.rs index 92b47bd..8ad1928 100644 --- a/measureme/src/file_header.rs +++ b/measureme/src/file_header.rs @@ -5,7 +5,7 @@ use std::convert::TryInto; use std::error::Error; use std::path::Path; -pub const CURRENT_FILE_FORMAT_VERSION: u32 = 7; +pub const CURRENT_FILE_FORMAT_VERSION: u32 = 8; pub const FILE_MAGIC_TOP_LEVEL: &[u8; 4] = b"MMPD"; pub const FILE_MAGIC_EVENT_STREAM: &[u8; 4] = b"MMES"; diff --git a/measureme/src/stringtable.rs b/measureme/src/stringtable.rs index 9a862bf..a56bbcb 100644 --- a/measureme/src/stringtable.rs +++ b/measureme/src/stringtable.rs @@ -310,7 +310,7 @@ impl StringTableBuilder { self.index_sink.write_bytes_atomic(bytes); } - pub(crate) fn alloc_metadata(&self, s: &STR) { + pub fn alloc_metadata(&self, s: &STR) { let concrete_id = self.alloc(s); let virtual_id = StringId(METADATA_STRING_ID); assert!(virtual_id.is_virtual()); diff --git a/mmview/Cargo.toml b/mmview/Cargo.toml index 71acb58..87d9c63 100644 --- a/mmview/Cargo.toml +++ b/mmview/Cargo.toml @@ -1,6 +1,6 @@ [package] name = "mmview" -version = "9.1.2" +version = "10.0.0-alpha" authors = ["Wesley Wiser ", "Michael Woerister "] edition = "2018" license = "MIT OR Apache-2.0" diff --git a/mmview/src/main.rs b/mmview/src/main.rs index 6606873..ec04535 100644 --- a/mmview/src/main.rs +++ b/mmview/src/main.rs @@ -25,7 +25,7 @@ fn main() -> Result<(), Box> { continue; } } - print_event(&event.to_event(), global_start_time); + print_event(&data.to_full_event(&event), global_start_time); } } else { eprintln!("No events."); diff --git a/stack_collapse/Cargo.toml b/stack_collapse/Cargo.toml index b278ae0..c5986ce 100644 --- a/stack_collapse/Cargo.toml +++ b/stack_collapse/Cargo.toml @@ -1,6 +1,6 @@ [package] name = "stack_collapse" -version = "9.1.2" +version = "10.0.0-alpha" authors = ["Wesley Wiser ", "Michael Woerister "] edition = "2018" license = "MIT OR Apache-2.0" diff --git a/summarize/Cargo.toml b/summarize/Cargo.toml index f713118..30c8c8c 100644 --- a/summarize/Cargo.toml +++ b/summarize/Cargo.toml @@ -1,6 +1,6 @@ [package] name = "summarize" -version = "9.1.2" +version = "10.0.0-alpha" authors = ["Wesley Wiser ", "Michael Woerister "] edition = "2018" license = "MIT OR Apache-2.0" diff --git a/summarize/src/aggregate.rs b/summarize/src/aggregate.rs index ad59d93..80f7755 100644 --- a/summarize/src/aggregate.rs +++ b/summarize/src/aggregate.rs @@ -477,7 +477,7 @@ pub fn aggregate_profiles(profiles: Vec) { let aggregated_sample_intervals = AggregatedSampleIntervals::new( profiles .iter() - .map(|data| SamplePoints::new(data.iter().map(|event| event.to_event())).intervals()), + .map(|data| SamplePoints::new(data.iter_full()).intervals()), ); let mut intervals_count = 0; diff --git a/summarize/src/analysis.rs b/summarize/src/analysis.rs index f5b2566..48ef2e1 100644 --- a/summarize/src/analysis.rs +++ b/summarize/src/analysis.rs @@ -130,11 +130,7 @@ pub fn perform_analysis(data: ProfilingData) -> Results { } }; - for current_event in data - .iter() - .rev() - .map(|lightweight_event| lightweight_event.to_event()) - { + for current_event in data.iter_full().rev() { match current_event.payload { EventPayload::Timestamp(Timestamp::Instant(_)) => { if ¤t_event.event_kind[..] == QUERY_CACHE_HIT_EVENT_KIND { diff --git a/version_checker/Cargo.toml b/version_checker/Cargo.toml index 3137eaf..40366ad 100644 --- a/version_checker/Cargo.toml +++ b/version_checker/Cargo.toml @@ -1,6 +1,6 @@ [package] name = "version_checker" -version = "9.1.2" +version = "10.0.0-alpha" authors = ["Michael Woerister "] edition = "2018" license = "MIT OR Apache-2.0"