diff --git a/src/analytics/mod.rs b/src/analytics/mod.rs index 68f5a513..fc8741f0 100644 --- a/src/analytics/mod.rs +++ b/src/analytics/mod.rs @@ -5,6 +5,9 @@ use crate::data::common::data_formats::ProcessedData; use rule_templates::{ key_value_key_expected_rule::KeyValueKeyExpectedRule, key_value_key_run_comparison_rule::KeyValueKeyRunComparisonRule, + profile_metadata_comparison_rule::ProfileMetadataComparisonRule, + profile_metadata_expected_rule::ProfileMetadataExpectedRule, + profile_stack_frame_threshold_rule::ProfileStackFrameThresholdRule, time_series_data_point_threshold_rule::TimeSeriesDataPointThresholdRule, time_series_stat_intra_run_comparison_rule::TimeSeriesStatIntraRunComparisonRule, time_series_stat_run_comparison_rule::TimeSeriesStatRunComparisonRule, @@ -14,8 +17,10 @@ use rule_templates::{ use crate::data::common::processed_data_accessor::ProcessedDataAccessor; pub use rule_templates::{ key_value_key_expected_rule, key_value_key_run_comparison_rule, - time_series_data_point_threshold_rule, time_series_stat_intra_run_comparison_rule, - time_series_stat_run_comparison_rule, time_series_stat_threshold_rule, + profile_metadata_comparison_rule, profile_metadata_expected_rule, + profile_stack_frame_threshold_rule, time_series_data_point_threshold_rule, + time_series_stat_intra_run_comparison_rule, time_series_stat_run_comparison_rule, + time_series_stat_threshold_rule, }; use rules::multi_data_rules::get_multi_data_rules; use serde::{Deserialize, Serialize}; @@ -233,7 +238,10 @@ analytical_rules!( TimeSeriesDataPointThresholdRule, KeyValueKeyRunComparisonRule, KeyValueKeyExpectedRule, - TimeSeriesStatIntraRunComparisonRule + TimeSeriesStatIntraRunComparisonRule, + ProfileStackFrameThresholdRule, + ProfileMetadataExpectedRule, + ProfileMetadataComparisonRule ); macro_rules! multi_data_analytical_rules { diff --git a/src/analytics/rule_templates.rs b/src/analytics/rule_templates.rs index 02cb3a4a..4461493d 100644 --- a/src/analytics/rule_templates.rs +++ b/src/analytics/rule_templates.rs @@ -1,5 +1,8 @@ pub mod key_value_key_expected_rule; pub mod key_value_key_run_comparison_rule; +pub mod profile_metadata_comparison_rule; +pub mod profile_metadata_expected_rule; +pub mod profile_stack_frame_threshold_rule; pub mod time_series_data_point_threshold_rule; pub mod time_series_stat_intra_run_comparison_rule; pub mod time_series_stat_run_comparison_rule; diff --git a/src/analytics/rule_templates/profile_metadata_comparison_rule.rs b/src/analytics/rule_templates/profile_metadata_comparison_rule.rs new file mode 100644 index 00000000..11f5113b --- /dev/null +++ b/src/analytics/rule_templates/profile_metadata_comparison_rule.rs @@ -0,0 +1,188 @@ +use crate::analytics; +use crate::analytics::{AnalyticalFinding, Analyze, DataFindings}; +use crate::data::common::data_formats::{AperfData, ProcessedData}; +use crate::data::common::processed_data_accessor::ProcessedDataAccessor; +use log::debug; +use std::collections::HashMap; +use std::fmt; +use std::fmt::Formatter; + +/// This rule compares metadata field values between runs. Generates a finding if the values of the metadata between a run and +/// the base run are different. It will also generate a finding if a field is expected (should_exist = true) to exist but doesn't. +/// Metadata has the same structure as KeyValueData. +pub struct ProfileMetadataComparisonRule { + pub rule_name: &'static str, + pub group: &'static str, + pub key: &'static str, + pub should_exist: bool, + pub score: f64, + pub message: &'static str, +} + +macro_rules! profile_metadata_comparison { + { + name: $rule_name:literal, + group: $group:literal, + key: $key:literal, + should_exist: $should_exist:literal, + score: $score:expr, + message: $message:literal, + } => { + AnalyticalRule::ProfileMetadataComparisonRule( + ProfileMetadataComparisonRule { + rule_name: $rule_name, + group: $group, + key: $key, + should_exist: $should_exist, + score: $score.as_f64(), + message: $message, + } + ) + }; +} +pub(crate) use profile_metadata_comparison; + +impl fmt::Display for ProfileMetadataComparisonRule { + fn fmt(&self, f: &mut Formatter<'_>) -> fmt::Result { + write!( + f, + "ProfileMetadataComparisonRule {} ", + self.rule_name, self.group, self.key, + ) + } +} + +impl Analyze for ProfileMetadataComparisonRule { + fn analyze( + &self, + report_findings: &mut DataFindings, + processed_data: &ProcessedData, + _processed_data_accessor: &mut ProcessedDataAccessor, + ) { + let base_run_name = analytics::get_base_run_name(); + + let base_run_data = match processed_data.runs.get(&base_run_name) { + Some(data) => data, + None => { + if processed_data.runs.keys().len() > 0 { + debug!("{self} failed to analyze: base run does not exist"); + } + return; + } + }; + + // Map base values from all profiles in the first record + let base_values: HashMap = + if let AperfData::Graph(graph_data) = base_run_data { + graph_data + .profiler_data_map + .iter() + .filter_map(|(key, profiler_data)| { + profiler_data + .metadata + .key_value_groups + .get(self.group) + .and_then(|group| group.key_values.get(self.key)) + .map(|value| (key.clone(), value.clone())) + }) + .collect() + } else { + HashMap::new() + }; + + if base_values.is_empty() { + if self.should_exist { + report_findings.insert_finding( + &base_run_name, + self.rule_name, + AnalyticalFinding::new( + self.rule_name.to_string(), + self.score, + format!( + "Event type '{}' field '{}' not found in run {}.", + self.group, self.key, base_run_name + ), + self.message.to_string(), + ), + ); + } + return; + } + + for (run_name, run_data) in &processed_data.runs { + if *run_name == base_run_name { + continue; + } + + let AperfData::Graph(graph_data) = run_data else { + continue; + }; + + let comparison_values: HashMap = graph_data + .profiler_data_map + .iter() + .filter_map(|(key, profiler_data)| { + profiler_data + .metadata + .key_value_groups + .get(self.group) + .and_then(|group| group.key_values.get(self.key)) + .map(|value| (key.clone(), value.clone())) + }) + .collect(); + + // If both runs have exactly one key-value pair, compare values regardless of key match + if base_values.len() == 1 && comparison_values.len() == 1 { + let (base_key, base_value) = base_values.iter().next().unwrap(); + let (comp_key, comp_value) = comparison_values.iter().next().unwrap(); + + if comp_value != base_value { + report_findings.insert_finding( + run_name, + comp_key, + AnalyticalFinding::new( + self.rule_name.to_string(), + self.score, + format!( + "Event type '{}' field '{}' in {} for '{}' (\"{}\") differs from {} for '{}' (\"{}\")", + self.group, self.key, run_name, comp_key, comp_value, base_run_name, base_key, base_value + ), + self.message.to_string(), + ), + ); + } + continue; + } + + // Otherwise try to match and compare keys + for (key, base_value) in &base_values { + let value = comparison_values.get(key); + + let finding_description = match value { + Some(v) if v != base_value => Some(format!( + "Event type '{}' field '{}' in {} for '{}' (\"{}\") differs from {} (\"{}\")", + self.group, self.key, run_name, key, v, base_run_name, base_value + )), + None if self.should_exist => Some(format!( + "Event type '{}' field '{}' not found in {} for '{}', while its value in {} is \"{}\"", + self.group, self.key, run_name, key, base_run_name, base_value + )), + _ => None, + }; + + if let Some(description) = finding_description { + report_findings.insert_finding( + run_name, + key, + AnalyticalFinding::new( + self.rule_name.to_string(), + self.score, + description, + self.message.to_string(), + ), + ); + } + } + } + } +} diff --git a/src/analytics/rule_templates/profile_metadata_expected_rule.rs b/src/analytics/rule_templates/profile_metadata_expected_rule.rs new file mode 100644 index 00000000..6e7c40ef --- /dev/null +++ b/src/analytics/rule_templates/profile_metadata_expected_rule.rs @@ -0,0 +1,118 @@ +use crate::analytics::{AnalyticalFinding, Analyze, DataFindings}; +use crate::data::common::data_formats::{AperfData, ProcessedData}; +use crate::data::common::processed_data_accessor::ProcessedDataAccessor; +use log::debug; +use regex::Regex; +use std::fmt; +use std::fmt::Formatter; + +/// This rule checks if expected metadata fields exists and also checks the expected value in profile data. It generates +/// a finding if the value does not match the expected_value regex. A finding will also be generated if the value cannot +/// be found and should_exist is true. +pub struct ProfileMetadataExpectedRule { + pub rule_name: &'static str, + pub group: &'static str, + pub key: &'static str, + pub expected_value: &'static str, + pub should_exist: bool, + pub score: f64, + pub message: &'static str, +} + +macro_rules! profile_metadata_expected { + { + name: $rule_name:literal, + group: $group:literal, + key: $key:literal, + expected_value: $expected:literal, + should_exist: $should_exist:literal, + score: $score:expr, + message: $message:literal, + } => { + AnalyticalRule::ProfileMetadataExpectedRule( + ProfileMetadataExpectedRule { + rule_name: $rule_name, + group: $group, + key: $key, + expected_value: $expected, + should_exist: $should_exist, + score: $score.as_f64(), + message: $message, + } + ) + }; +} +pub(crate) use profile_metadata_expected; + +impl fmt::Display for ProfileMetadataExpectedRule { + fn fmt(&self, _f: &mut Formatter<'_>) -> fmt::Result { + Ok(()) + } +} + +impl Analyze for ProfileMetadataExpectedRule { + fn analyze( + &self, + report_findings: &mut DataFindings, + processed_data: &ProcessedData, + _processed_data_accessor: &mut ProcessedDataAccessor, + ) { + let regex = match Regex::new(self.expected_value) { + Ok(re) => Some(re), + Err(e) => { + debug!( + "Error: Failed to compile regex '{}' in rule '{}': {}", + self.expected_value, self.rule_name, e + ); + None + } + }; + + for (run_name, run_data) in &processed_data.runs { + let AperfData::Graph(graph_data) = run_data else { + continue; + }; + for (key, profiler_data) in &graph_data.profiler_data_map { + let metadata_value = profiler_data + .metadata + .key_value_groups + .get(self.group) + .and_then(|group| group.key_values.get(self.key)) + .cloned(); + + let field_exists = metadata_value.is_some(); + let value_matches = matches!((&metadata_value, ®ex), (Some(value), Some(re)) if re.is_match(value)); + + // Report finding if value doesn't match, or if it should exist but doesnt + if (field_exists && !value_matches) || (self.should_exist && !field_exists) { + let finding_description = if field_exists { + format!( + "Event type '{}' field '{}' in {} should match pattern '{}', found: {:?}", + self.group, + self.key, + key, + self.expected_value, + metadata_value.unwrap_or_default() + ) + } else { + format!( + "Event type '{}' field '{}' not found in profile data", + self.group, self.key + ) + }; + + report_findings.insert_finding( + run_name, + key, + AnalyticalFinding::new( + self.rule_name.to_string(), + self.score, + finding_description, + self.message.to_string(), + ), + ); + } + } + } + } +} diff --git a/src/analytics/rule_templates/profile_stack_frame_threshold_rule.rs b/src/analytics/rule_templates/profile_stack_frame_threshold_rule.rs new file mode 100644 index 00000000..118a0e30 --- /dev/null +++ b/src/analytics/rule_templates/profile_stack_frame_threshold_rule.rs @@ -0,0 +1,140 @@ +use crate::analytics::{AnalyticalFinding, Analyze, DataFindings}; +use crate::data::common::data_formats::{AperfData, ProcessedData}; +use crate::data::common::processed_data_accessor::ProcessedDataAccessor; +use crate::profiling::{FrameType, ThreadState}; +use std::fmt; +use std::fmt::Formatter; + +/// This rule compares the % samples in a stack frame against a threshold, and generates a finding if samples > threshold. +/// stack_frame - list of stack frame patterns; each pattern is a list of frames (root is index 0, leaf frame is last index) +/// frame_type - For JFR, specify the frame type to match against the leaf frame. For other stacks, use Native or Any +/// thread_states - For JFR, specify the thread states to include samples for. For other stacks, select None or leave empty. +/// total_samples - Use total samples in function if true, otherwise use self samples +/// aggregate_occurences - Use the sum of all stack frame patterns if true, otherwise check threshold for patterns individually +/// threshold - % samples to generate finding +pub struct ProfileStackFrameThresholdRule { + pub rule_name: &'static str, + pub graph_group: &'static str, + pub stack_frame: &'static [&'static [&'static str]], + pub frame_type: Option, + pub thread_states: &'static [ThreadState], + pub aggregate_occurences: bool, + pub total_samples: bool, + pub threshold: f64, + pub score: f64, + pub message: &'static str, +} + +macro_rules! profile_stack_frame_threshold { + { + name: $rule_name:literal, + graph_group: $graph_group:literal, + stack_frame: [$([$($frame:literal),+]),+], + frame_type: $frame_type:expr, + $(thread_states: [$($state:expr),*],)? + aggregate_occurences: $aggregate_occurences:literal, + total_samples: $total_samples:literal, + threshold: $threshold:expr, + score: $score:expr, + message: $message:literal, + } => { + AnalyticalRule::ProfileStackFrameThresholdRule( + ProfileStackFrameThresholdRule { + rule_name: $rule_name, + graph_group: $graph_group, + stack_frame: &[$(&[$($frame),+]),+], + frame_type: $frame_type, + thread_states: &[$($($state),*)?], + aggregate_occurences: $aggregate_occurences, + total_samples: $total_samples, + threshold: $threshold, + score: $score.as_f64(), + message: $message, + } + ) + }; +} +pub(crate) use profile_stack_frame_threshold; + +impl fmt::Display for ProfileStackFrameThresholdRule { + fn fmt(&self, _f: &mut Formatter<'_>) -> fmt::Result { + Ok(()) + } +} + +impl Analyze for ProfileStackFrameThresholdRule { + fn analyze( + &self, + report_findings: &mut DataFindings, + processed_data: &ProcessedData, + _processed_data_accessor: &mut ProcessedDataAccessor, + ) { + for (run_name, run_data) in &processed_data.runs { + let AperfData::Graph(graph_data) = run_data else { + continue; + }; + + for (key, profiler_data) in &graph_data.profiler_data_map { + if !profiler_data.profiles.contains_key(self.graph_group) { + continue; + } + let total_samples = + profiler_data.get_total_samples(self.graph_group, self.thread_states); + + let (sample_count, matched_pattern) = + self.stack_frame + .iter() + .fold((0u64, None), |(acc, acc_pat), pattern| { + let count = profiler_data.get_samples( + self.graph_group, + pattern, + self.frame_type, + self.thread_states, + self.total_samples, + ); + if self.aggregate_occurences { + (acc + count, None) + } else if count > acc { + (count, Some(pattern)) + } else { + (acc, acc_pat) + } + }); + + let percentage = if total_samples > 0 { + (sample_count as f64 / total_samples as f64) * 100.0 + } else { + 0.0 + }; + + if percentage >= self.threshold { + let pattern_str = if let Some(pat) = matched_pattern { + format!("[{}]", pat.join(", ")) + } else { + let all: Vec = self + .stack_frame + .iter() + .map(|p| format!("[{}]", p.join(", "))) + .collect(); + all.join(", ") + }; + let finding_description = format!( + "Stack pattern {} accounts for {:.2}% of samples in {} (threshold: {:.2}%)", + pattern_str, percentage, self.graph_group, self.threshold + ); + + report_findings.insert_finding( + run_name, + key, + AnalyticalFinding::new( + self.rule_name.to_string(), + self.score, + finding_description, + self.message.to_string(), + ), + ); + } + } + } + } +} diff --git a/src/analytics/rules/flamegraphs.rs b/src/analytics/rules/flamegraphs.rs index 00a94165..d51041d7 100644 --- a/src/analytics/rules/flamegraphs.rs +++ b/src/analytics/rules/flamegraphs.rs @@ -1,4 +1,21 @@ +use crate::analytics::rule_templates::profile_stack_frame_threshold_rule::profile_stack_frame_threshold; +use crate::analytics::{AnalyticalRule, ProfileStackFrameThresholdRule, Score}; use crate::data::flamegraphs::Flamegraph; use crate::data::AnalyzeData; -impl AnalyzeData for Flamegraph {} +impl AnalyzeData for Flamegraph { + fn get_analytical_rules(&self) -> Vec { + vec![profile_stack_frame_threshold! { + name: "Place Holder", + graph_group: "default", + stack_frame: [["place_holder_frame"]], + frame_type: None, + thread_states: [], + aggregate_occurences: true, + total_samples: true, + threshold: 100.0, + score: Score::Poor, + message: "Resolution", + }] + } +} diff --git a/src/analytics/rules/java_profile.rs b/src/analytics/rules/java_profile.rs index ba932103..d62c9ca1 100644 --- a/src/analytics/rules/java_profile.rs +++ b/src/analytics/rules/java_profile.rs @@ -1,4 +1,49 @@ +use crate::analytics::rule_templates::profile_metadata_comparison_rule::profile_metadata_comparison; +use crate::analytics::rule_templates::profile_metadata_expected_rule::profile_metadata_expected; +use crate::analytics::rule_templates::profile_stack_frame_threshold_rule::profile_stack_frame_threshold; +use crate::analytics::{ + AnalyticalRule, ProfileMetadataComparisonRule, ProfileMetadataExpectedRule, + ProfileStackFrameThresholdRule, Score, +}; use crate::data::java_profile::JavaProfile; use crate::data::AnalyzeData; +use crate::profiling::ThreadState; -impl AnalyzeData for JavaProfile {} +impl AnalyzeData for JavaProfile { + fn get_analytical_rules(&self) -> Vec { + vec![ + // Anti-Pattern Rules + // If rule for cpu or alloc group, use only ThreadState::AsyncDefault + profile_stack_frame_threshold! { + name: "Excessive Exceptions", + graph_group: "cpu", + stack_frame: [[r"java\.lang\.(Throwable\.(fillInStackTrace|getStackTrace|getOurStackTrace)|StackTraceElement\.)|\w+(\.\w+)*\.((\w*Exception|\w*Error|Throwable)\.)"]], + frame_type: None, + thread_states: [ThreadState::AsyncDefault], + aggregate_occurences: true, + total_samples: true, + threshold: 5.0, + score: Score::Critical, + message: "We recommend not to use Java exceptions as control flow, and to remove exceptions when they appear in the hot-code path. Overhead can be mitigated some by using the -XX:+OmitStackTraceInFastThrow JVM flag to allow the Java runtime to optimize the exception flow for some hot paths. The best solution is to avoid the exceptions as much as possible.", + }, + // Other Rules + profile_metadata_expected! { + name: "Tiered Compilation Check", + group: "jdk.JVMInformation", + key: "jvmArguments", + expected_value: ".*-XX:(-|\\+)TieredCompilation.*", + should_exist: true, + score: Score::Poor, + message: "If your code has a large instruction footprint, try setting this argument. This feature enables the runtime to more adaptively use the just-in-time (JIT) compiler to achieve better performance.", + }, + profile_metadata_comparison! { + name: "JVM Version Comparison", + group: "jdk.JVMInformation", + key: "jvmVersion", + should_exist: true, + score: Score::Critical, + message: "JVM versions are different across runs, which may significantly affect performance. Ensure that this is intentional, or run comparison using consistent versions.", + }, + ] + } +} diff --git a/src/data/common/data_formats.rs b/src/data/common/data_formats.rs index a7fd395c..5af79feb 100644 --- a/src/data/common/data_formats.rs +++ b/src/data/common/data_formats.rs @@ -1,4 +1,5 @@ use crate::computations::{serialize_f64_vec_fixed2, Statistics}; +use crate::profiling::Profile; use serde::{Deserialize, Serialize}; use std::collections::HashMap; use strum_macros::Display; @@ -159,6 +160,7 @@ pub struct KeyValueGroup { #[derive(Serialize, Deserialize, Debug, Default, Clone)] pub struct GraphData { pub graph_groups: Vec, + pub profiler_data_map: HashMap, } /// Contents of a graph group, which contains all graphs to be displayed together. @@ -199,3 +201,32 @@ pub struct TextData { /// All lines of the text content. pub lines: Vec, } + +// ---------------------------------------- PROFILER DATA ------------------------------------------ +/// Time-bucketed profiling data supporting JFR and perf record sources. +/// Enables per-block sample lookups (for heatmaps and time range selection) and call graph traversal +/// (for self/total sample computation). +/// +/// See [`crate::profiling`] for the implementation of profile building and querying. +#[derive(Debug, Clone, Serialize, Deserialize)] +pub struct ProfilerData { + /// Start time of the profile in milliseconds since epoch + pub start_time_ms: i64, + /// Duration of each block in milliseconds + pub block_width_ms: u64, + /// Additional metadata (e.g., source, architecture, JVM version) + pub metadata: KeyValueData, + /// Profiling type (e.g., "cpu", "wall", "allocation") -> Profile + pub profiles: HashMap, +} + +impl ProfilerData { + pub fn new(start_time_ms: i64, block_width_ms: u64) -> Self { + ProfilerData { + start_time_ms, + block_width_ms, + metadata: KeyValueData::default(), + profiles: HashMap::new(), + } + } +} diff --git a/src/data/flamegraphs.rs b/src/data/flamegraphs.rs index 22d92341..42683074 100644 --- a/src/data/flamegraphs.rs +++ b/src/data/flamegraphs.rs @@ -2,6 +2,7 @@ use crate::data::common::data_formats::{AperfData, Graph, GraphData, GraphGroup} use crate::data::{Data, ProcessData}; use crate::visualizer::ReportParams; use anyhow::Result; +use log::error; use serde::{Deserialize, Serialize}; use std::path::PathBuf; #[cfg(target_os = "linux")] @@ -10,7 +11,8 @@ use { crate::{get_file_name, PDError}, inferno::collapse::{perf::Folder, Collapse}, inferno::flamegraph::{self, Direction, Options}, - log::{debug, error, info}, + log::{debug, info}, + std::fs, std::fs::File, std::io::Write, std::process::Command, @@ -83,6 +85,7 @@ impl CollectData for FlamegraphRaw { } Ok(_) => { info!("Creating flamegraph..."); + // TODO: extract metadata from perf record and generate script -> ProfilerData let script_loc = data_dir.join("script.out"); let out = Command::new("perf") .stdout(File::create(&script_loc)?) @@ -96,9 +99,12 @@ impl CollectData for FlamegraphRaw { } Ok(_) => { let collapse_loc = data_dir.join("collapse.out"); + // TODO: move flamegraph generation to report phase using ProfilerData (so user specifies time range) + Folder::default().collapse_file( + Some(script_loc.clone()), + File::create(&collapse_loc)?, + )?; - Folder::default() - .collapse_file(Some(script_loc), File::create(&collapse_loc)?)?; // Generate icicle graph as default let mut reverse_options = Options::default(); reverse_options.direction = Direction::Inverted; @@ -116,6 +122,11 @@ impl CollectData for FlamegraphRaw { &[collapse_loc.to_path_buf()], reverse_fg_out, )?; + + // Clean up intermediate files after creating flamegraphs and saving + for file in [&script_loc, &perf_jit_loc, &collapse_loc] { + fs::remove_file(file).ok(); + } } } } @@ -176,6 +187,8 @@ impl ProcessData for Flamegraph { let mut graph_data = GraphData::default(); + // TODO: Populate graph_data profiler_data_map from record serialized profiler data + copy_and_add_to_graph_group( ¶ms, format!("{}-flamegraph.svg", params.run_name), diff --git a/src/data/java_profile.rs b/src/data/java_profile.rs index e7af9611..3e97788d 100644 --- a/src/data/java_profile.rs +++ b/src/data/java_profile.rs @@ -1,10 +1,13 @@ -use crate::data::common::data_formats::{AperfData, Graph, GraphData, GraphGroup}; +use crate::data::common::data_formats::{AperfData, Graph, GraphData, GraphGroup, ProfilerData}; #[cfg(target_os = "linux")] use crate::data::common::utils::get_data_name_from_type; use crate::data::{Data, ProcessData}; +use crate::profiling::{jfr, BUCKET_WIDTH_MS}; use crate::visualizer::ReportParams; use anyhow::Result; +use log::error; use serde::{Deserialize, Serialize}; +use serde_json::Value; use std::collections::HashMap; use std::fs; use std::path::PathBuf; @@ -12,7 +15,7 @@ use std::path::PathBuf; use { crate::data::{CollectData, CollectorParams}, crate::PDError, - log::{debug, error}, + log::debug, nix::{sys::signal, unistd::Pid}, std::fs::File, std::io::Write, @@ -256,6 +259,44 @@ impl CollectData for JavaProfileRaw { .join(format!("{}-java-profile-{}.jfr", params.run_name, key)); if fs::exists(&jfr_path).expect("Can't check existence of jfr file") { + // Extract metadata JSON string from JFR + let metadata_events = [ + "jdk.ActiveRecording", + "jdk.ActiveSetting", + "jdk.CheckPoint", + "jdk.Metadata", + "jdk.JVMInformation", + "jdk.NativeLibrary", + ]; + let metadata_json = match Command::new("jfr") + .args([ + "print", + "--json", + "--events", + &metadata_events.join(","), + &jfr_path.to_string_lossy(), + ]) + .output() + { + Err(e) => { + error!("'jfr' metadata extraction failed for {}: {}", key, e); + Value::Null + } + Ok(output) => { + if !output.status.success() { + error!( + "'jfr' metadata extraction failed for {}: {}", + key, + String::from_utf8_lossy(&output.stderr) + ); + Value::Null + } else { + serde_json::from_slice(&output.stdout).unwrap_or(Value::Null) + } + } + }; + + // Generate heatmaps for each profiling type for metric in PROFILE_METRICS { let html_path = data_dir.join(format!( "{}-java-profile-{}-{}.html", @@ -267,6 +308,7 @@ impl CollectData for JavaProfileRaw { &format!("--{metric}"), "-o", "heatmap", + "--dot", &jfr_path.to_string_lossy(), html_path.to_str().unwrap(), ]) @@ -296,6 +338,23 @@ impl CollectData for JavaProfileRaw { } } + // Generate ProfilerData from JFR + let profiler_data_path = params.data_dir.join(format!( + "{}-java-profile-{}-profiler-data.json", + params.run_name, key + )); + match jfr::jfr_to_profiler_data(&jfr_path, BUCKET_WIDTH_MS) { + Ok(mut profiler_data) => { + profiler_data.metadata = jfr::parse_jfr_metadata(&metadata_json); + if let Ok(json) = serde_json::to_string(&profiler_data) { + fs::write(&profiler_data_path, json).ok(); + } + } + Err(e) => { + error!("Failed to build ProfilerData for {}: {}", key, e); + } + } + let jfr_dest = data_dir.join(format!("{}-java-profile-{}.jfr", params.run_name, key)); fs::copy(&jfr_path, jfr_dest).ok(); @@ -411,6 +470,23 @@ impl ProcessData for JavaProfile { graph_data.graph_groups.push(graph_group); } + // Load profiler data for Java profiles + for (process, _) in &process_map { + let profiler_data_path = params.data_dir.join(format!( + "{}-java-profile-{}-profiler-data.json", + params.run_name, process + )); + if let Ok(json) = fs::read_to_string(&profiler_data_path) { + if let Ok(profiler_data) = serde_json::from_str::(&json) { + if let Some(name) = deduped_names.get(process) { + graph_data + .profiler_data_map + .insert(name.clone(), profiler_data); + } + } + } + } + Ok(AperfData::Graph(graph_data)) } } diff --git a/src/lib.rs b/src/lib.rs index 3a469f2c..6f9a79b9 100644 --- a/src/lib.rs +++ b/src/lib.rs @@ -7,6 +7,7 @@ pub mod computations; pub mod data; #[cfg(target_os = "linux")] pub mod pmu; +pub mod profiling; #[cfg(target_os = "linux")] pub mod record; pub mod report; diff --git a/src/profiling/jfr/convert.rs b/src/profiling/jfr/convert.rs new file mode 100644 index 00000000..50702175 --- /dev/null +++ b/src/profiling/jfr/convert.rs @@ -0,0 +1,476 @@ +use crate::data::common::data_formats::{KeyValueData, ProfilerData}; +use crate::profiling::jfr::{ExecSampleType, JfrEvent, JfrReader}; +use crate::profiling::{FrameType, ThreadState}; +use anyhow::Result; +use serde_json::Value; +use std::collections::HashMap; +use std::fmt::Write; +use std::path::Path; + +/// This converts a JFR to string output, and should be equivalent to jfr print function. +/// Only used for validating data parsing. +pub fn format_jfr(path: &Path) -> Result { + let mut out = String::new(); + let mut reader = JfrReader::open(path.to_str().unwrap())?; + + writeln!(out, "start_nanos: {}", reader.start_nanos)?; + writeln!(out, "end_nanos: {}", reader.end_nanos)?; + writeln!( + out, + "chunk ticks_per_sec: {}", + reader.chunk_info.ticks_per_sec + )?; + writeln!(out, "threads: {}", reader.threads.len())?; + writeln!(out, "methods: {}", reader.methods.len())?; + writeln!(out, "stack_traces: {}", reader.stack_traces.len())?; + writeln!(out, "classes: {}", reader.classes.len())?; + writeln!(out, "strings: {}", reader.strings.len())?; + writeln!(out, "enums: {:?}", reader.enums)?; + writeln!(out, "settings: {:?}", reader.settings)?; + writeln!(out, "---")?; + + loop { + match reader.read_event() { + Ok(JfrEvent::EndOfChunk) => { + if !reader.has_more_chunks().unwrap_or(false) { + break; + } + } + Ok(event) => { + let time_nanos = reader.chunk_info.event_time_to_nanos(event.time()); + let secs = time_nanos / 1_000_000_000; + let nanos_rem = (time_nanos % 1_000_000_000).unsigned_abs(); + let h = (secs / 3600) % 24; + let m = (secs / 60) % 60; + let s = secs % 60; + let ms = nanos_rem / 1_000_000; + let time_str = format!("{:02}:{:02}:{:02}.{:03}", h, m, s, ms); + + let tid = event.tid(); + let thread_name = reader.resolve_thread(tid as i64).unwrap_or_default(); + let java_tid = reader.java_thread_ids.get(&(tid as i64)).copied(); + + match &event { + JfrEvent::ExecutionSample(e) => { + let state = reader + .enums + .get("jdk.types.ThreadState") + .and_then(|m| m.get(&e.thread_state)) + .cloned() + .unwrap_or_else(|| format!("STATE_{}", e.thread_state)); + let type_name = match e.sample_type { + ExecSampleType::Execution => "jdk.ExecutionSample", + ExecSampleType::NativeMethod => "jdk.NativeMethodSample", + ExecSampleType::WallClock => "profiler.WallClockSample", + ExecSampleType::CpuTime => "jdk.CPUTimeSample", + }; + writeln!(out, "{} {{", type_name)?; + writeln!(out, " startTime = {}", time_str)?; + write_thread_field(&mut out, "sampledThread", &thread_name, tid, java_tid)?; + writeln!(out, " state = \"{}\"", state)?; + if e.sample_type == ExecSampleType::WallClock { + writeln!(out, " samples = {}", e.samples)?; + } + } + JfrEvent::AllocationSample(e) => { + let cls = jvm_type_to_human(&reader.resolve_class(e.class_id as i64)); + let type_name = if e.tlab_size > 0 { + "jdk.ObjectAllocationInNewTLAB" + } else { + "jdk.ObjectAllocationOutsideTLAB" + }; + writeln!(out, "{} {{", type_name)?; + writeln!(out, " startTime = {}", time_str)?; + writeln!(out, " objectClass = {} (classLoader = null)", cls)?; + writeln!( + out, + " allocationSize = {}", + format_bytes(e.allocation_size) + )?; + if e.tlab_size > 0 { + writeln!(out, " tlabSize = {}", format_bytes(e.tlab_size))?; + } + write_thread_field(&mut out, "eventThread", &thread_name, tid, java_tid)?; + } + JfrEvent::ContendedLock(e) => { + let cls = jvm_type_to_human(&reader.resolve_class(e.class_id as i64)); + writeln!(out, "jdk.JavaMonitorEnter {{")?; + writeln!(out, " startTime = {}", time_str)?; + writeln!(out, " duration = {} ns", e.duration)?; + writeln!(out, " monitorClass = {}", cls)?; + write_thread_field(&mut out, "eventThread", &thread_name, tid, java_tid)?; + } + JfrEvent::LiveObject(e) => { + let cls = jvm_type_to_human(&reader.resolve_class(e.class_id as i64)); + writeln!(out, "profiler.LiveObject {{")?; + writeln!(out, " startTime = {}", time_str)?; + writeln!(out, " objectClass = {}", cls)?; + writeln!( + out, + " allocationSize = {}", + format_bytes(e.allocation_size) + )?; + writeln!(out, " allocationTime = {}", e.allocation_time)?; + } + JfrEvent::MallocEvent(e) => { + let type_name = if e.size > 0 { + "profiler.Malloc" + } else { + "profiler.Free" + }; + writeln!(out, "{} {{", type_name)?; + writeln!(out, " startTime = {}", time_str)?; + writeln!(out, " address = 0x{:x}", e.address)?; + if e.size > 0 { + writeln!(out, " size = {}", format_bytes(e.size))?; + } + } + JfrEvent::MethodTrace(e) => { + writeln!(out, "jdk.MethodTrace {{")?; + writeln!(out, " startTime = {}", time_str)?; + writeln!(out, " duration = {} ns", e.duration)?; + writeln!(out, " method = {}", e.method)?; + } + JfrEvent::NativeLock(e) => { + writeln!(out, "profiler.NativeLock {{")?; + writeln!(out, " startTime = {}", time_str)?; + writeln!(out, " duration = {} ns", e.duration)?; + writeln!(out, " address = 0x{:x}", e.address)?; + } + JfrEvent::Custom(_) => { + writeln!(out, "CustomEvent {{")?; + writeln!(out, " startTime = {}", time_str)?; + } + JfrEvent::EndOfChunk => unreachable!(), + } + + if let Some(trace) = reader.stack_traces.get(&(event.stack_trace_id() as i64)) { + writeln!(out, " stackTrace = [")?; + for (i, &method_id) in trace.methods.iter().enumerate() { + let loc = trace.locations[i]; + let line = loc >> 16; + if let Some((cls, method, sig)) = reader.resolve_method(method_id) { + let sig_str = if sig.is_empty() || sig.starts_with("[unknown") { + String::new() + } else { + format_signature(&sig) + }; + writeln!( + out, + " {}.{}({}) line: {}", + cls.replace('/', "."), + method, + sig_str, + line + )?; + } else { + writeln!(out, " [unknown:{}]() line: {}", method_id, line)?; + } + } + writeln!(out, " ]")?; + } + + writeln!(out, "}}")?; + writeln!(out)?; + } + Err(e) => return Err(e.into()), + } + } + Ok(out) +} + +fn write_thread_field( + out: &mut String, + field: &str, + name: &str, + tid: i32, + java_tid: Option, +) -> std::fmt::Result { + if name.is_empty() { + return writeln!(out, " {} = N/A", field); + } + if let Some(jtid) = java_tid { + if jtid > 0 { + return writeln!(out, " {} = \"{}\" (javaThreadId = {})", field, name, jtid); + } + } + writeln!(out, " {} = \"{}\" (osThreadId = {})", field, name, tid) +} + +fn jvm_type_to_human(name: &str) -> String { + let mut s = name; + let mut dims = 0; + while s.starts_with('[') { + dims += 1; + s = &s[1..]; + } + let base = match s { + "B" if dims > 0 => "byte", + "C" if dims > 0 => "char", + "D" if dims > 0 => "double", + "F" if dims > 0 => "float", + "I" if dims > 0 => "int", + "J" if dims > 0 => "long", + "S" if dims > 0 => "short", + "Z" if dims > 0 => "boolean", + other => { + let stripped = other + .strip_prefix('L') + .and_then(|s| s.strip_suffix(';')) + .unwrap_or(other); + return format!("{}{}", stripped.replace('/', "."), "[]".repeat(dims)); + } + }; + format!("{}{}", base, "[]".repeat(dims)) +} + +fn round_half_up_1(v: f64) -> f64 { + (v * 10.0 + 0.5).floor() / 10.0 +} + +fn format_bytes(bytes: i64) -> String { + let b = bytes as f64; + if b >= 1_048_576.0 { + format!("{:.1} MB", round_half_up_1(b / 1_048_576.0)) + } else if b >= 1024.0 { + format!("{:.1} kB", round_half_up_1(b / 1024.0)) + } else { + format!("{} bytes", bytes) + } +} + +fn format_signature(sig: &str) -> String { + if !sig.starts_with('(') { + return String::new(); + } + let end = sig.find(')').unwrap_or(sig.len()); + let params = &sig[1..end]; + let mut result = Vec::new(); + let mut chars = params.chars().peekable(); + while chars.peek().is_some() { + result.push(parse_type(&mut chars)); + } + result.join(", ") +} + +fn parse_type(chars: &mut std::iter::Peekable) -> String { + match chars.next() { + Some('B') => "byte".into(), + Some('C') => "char".into(), + Some('D') => "double".into(), + Some('F') => "float".into(), + Some('I') => "int".into(), + Some('J') => "long".into(), + Some('S') => "short".into(), + Some('Z') => "boolean".into(), + Some('V') => "void".into(), + Some('[') => format!("{}[]", parse_type(chars)), + Some('L') => { + let mut name = String::new(); + for c in chars.by_ref() { + if c == ';' { + break; + } + name.push(if c == '/' { '.' } else { c }); + } + name.rsplit('.').next().unwrap_or(&name).to_string() + } + _ => "?".into(), + } +} + +/// This function uses JfrReader to parse async-profiler generated JFR files into +/// APerf ProfilerData. +pub fn jfr_to_profiler_data(path: &Path, block_width_ms: u64) -> Result { + let mut reader = JfrReader::open(path.to_str().unwrap())?; + let start_time_ms = reader.start_nanos / 1_000_000; + + let frame_type_suffix: HashMap = reader + .enums + .get("jdk.types.FrameType") + .map(|m| { + m.iter() + .map(|(&k, v)| (k as u8, FrameType::from_jfr_name(v).literal_suffix())) + .collect() + }) + .unwrap_or_default(); + + let thread_state_map = reader + .enums + .get("jdk.types.ThreadState") + .cloned() + .unwrap_or_default(); + + let mut profiler_data = ProfilerData::new(start_time_ms, block_width_ms); + + loop { + match reader.read_event() { + Ok(JfrEvent::EndOfChunk) => { + if !reader.has_more_chunks().unwrap_or(false) { + break; + } + } + Ok(event) => { + let sample_time_ms = reader.chunk_info.event_time_to_millis(event.time()); + + let (profile_type, thread_state, samples) = match &event { + JfrEvent::ExecutionSample(e) => { + let ptype = match e.sample_type { + ExecSampleType::Execution + | ExecSampleType::NativeMethod + | ExecSampleType::CpuTime => "cpu", + ExecSampleType::WallClock => "wall", + }; + let state_name = thread_state_map + .get(&e.thread_state) + .map(|s| s.as_str()) + .unwrap_or(""); + (ptype, ThreadState::from_str(state_name), e.samples as u64) + } + JfrEvent::AllocationSample(_) => ("alloc", ThreadState::None, 1u64), + _ => continue, + }; + + if let Some(trace) = reader.stack_traces.get(&(event.stack_trace_id() as i64)) { + let mut frames: Vec = trace + .methods + .iter() + .zip(trace.types.iter()) + .rev() + .map(|(&mid, &ftype)| { + let suffix = frame_type_suffix.get(&ftype).copied().unwrap_or(""); + if let Some((cls, method, _)) = reader.resolve_method(mid) { + if ftype == 3 || ftype == 4 || cls.is_empty() { + format!("{}{}", method, suffix) + } else if method.is_empty() { + format!("{}{}", cls.replace('/', "."), suffix) + } else { + format!("{}.{}{}", cls.replace('/', "."), method, suffix) + } + } else { + format!("[unknown:{}]{}", mid, suffix) + } + }) + .collect(); + + if let JfrEvent::AllocationSample(e) = &event { + let cls = jvm_type_to_human(&reader.resolve_class(e.class_id as i64)); + frames.push(format!("{}{}", cls, FrameType::Inlined.literal_suffix())); + } + + if !frames.is_empty() { + profiler_data.insert_stack( + profile_type, + sample_time_ms, + thread_state, + &frames, + samples, + ); + } + } + } + Err(e) => return Err(e.into()), + } + } + + Ok(profiler_data) +} + +// Reference: https://github.com/async-profiler/async-profiler/blob/master/src/jfrMetadata.h#L46-L70 +fn jfr_event_type_name(id: &str) -> Option<&'static str> { + match id { + "101" => Some("Execution Sample"), + "102" => Some("Alloc in New TLAB"), + "103" => Some("Alloc Outside TLAB"), + "104" => Some("Monitor Enter"), + "105" => Some("Thread Park"), + "106" => Some("CPU Load"), + "107" => Some("Active Recording"), + "108" => Some("Active Setting"), + "109" => Some("OS Information"), + "110" => Some("CPU Information"), + "111" => Some("JVM Information"), + "112" => Some("Initial System Property"), + "113" => Some("Native Library"), + "114" => Some("GC Heap Summary"), + "115" => Some("Method Trace"), + "116" => Some("Log"), + "117" => Some("Window"), + "118" => Some("Live Object"), + "119" => Some("Wall Clock Sample"), + "120" => Some("Malloc"), + "121" => Some("Free"), + "122" => Some("User Event"), + "123" => Some("Process Sample"), + "124" => Some("Native Lock"), + _ => None, + } +} + +/// Parse JFR metadata JSON into KeyValueData. +pub fn parse_jfr_metadata(metadata_json: &Value) -> KeyValueData { + let mut key_value_data = KeyValueData::default(); + + let Some(events) = metadata_json + .get("recording") + .and_then(|r| r.get("events")) + .and_then(|e| e.as_array()) + else { + return key_value_data; + }; + + let json_to_string = |v: &Value| match v { + Value::String(s) => s.clone(), + _ => v.to_string(), + }; + + for event in events { + let Some(event_type) = event.get("type").and_then(|t| t.as_str()) else { + continue; + }; + let Some(values) = event.get("values").and_then(|v| v.as_object()) else { + continue; + }; + + match event_type { + "jdk.JVMInformation" | "jdk.ActiveRecording" => { + let group = key_value_data + .key_value_groups + .entry(event_type.to_string()) + .or_default(); + for (key, value) in values.iter().filter(|(k, _)| *k != "startTime") { + group.key_values.insert(key.clone(), json_to_string(value)); + } + } + "jdk.ActiveSetting" => { + if let (Some(name), Some(id)) = (values.get("name"), values.get("id")) { + let event_id = json_to_string(id); + let event_name = jfr_event_type_name(&event_id) + .map(|s| s.to_string()) + .unwrap_or_else(|| format!("Event ID: {}", event_id)); + let value_str = values + .get("value") + .map(&json_to_string) + .unwrap_or_else(|| "null".to_string()); + let setting = format!("{} : {}", name.as_str().unwrap_or(""), value_str); + + let settings_group = key_value_data + .key_value_groups + .entry("jdk.ActiveSetting".to_string()) + .or_default(); + settings_group + .key_values + .entry(event_name) + .and_modify(|s| { + s.push('\n'); + s.push_str(&setting); + }) + .or_insert(setting); + } + } + _ => {} + } + } + + key_value_data +} diff --git a/src/profiling/jfr/mod.rs b/src/profiling/jfr/mod.rs new file mode 100644 index 00000000..3f5912b8 --- /dev/null +++ b/src/profiling/jfr/mod.rs @@ -0,0 +1,14 @@ +//! JFR (Java Flight Recorder) binary format parser. +//! +//! Provides [`JfrReader`] for iterating over chunks and events in JFR files +//! produced by async-profiler, and [`jfr_to_profiler_data`] for converting +//! them into APerf's [`ProfilerData`](crate::data::common::data_formats::ProfilerData) format. + +mod convert; +mod reader; +mod types; + +pub use convert::{format_jfr, jfr_to_profiler_data, parse_jfr_metadata}; + +pub use reader::JfrReader; +pub use types::*; diff --git a/src/profiling/jfr/reader.rs b/src/profiling/jfr/reader.rs new file mode 100644 index 00000000..2003bac7 --- /dev/null +++ b/src/profiling/jfr/reader.rs @@ -0,0 +1,965 @@ +use anyhow::{bail, Result}; +use std::collections::HashMap; +use std::fs::File; +use std::io::Read; + +use super::types::*; + +const CHUNK_HEADER_SIZE: usize = 68; +const CHUNK_SIGNATURE: u32 = 0x464c5200; + +#[derive(Debug, PartialEq, Eq, Clone, Copy, Default)] +enum State { + #[default] + NewChunk, + Reading, + Eof, + Incomplete, +} + +/// JFR binary format reader. Iterates chunk-by-chunk, event-by-event. +/// Based on async-profiler implementation: https://github.com/async-profiler/async-profiler/tree/master +/// src/converter/one/jfr +/// +/// Usage: +/// +/// ```ignore +/// let mut reader = JfrReader::open("recording.jfr")?; +/// while reader.has_more_chunks()? { +/// loop { +/// match reader.read_event()? { +/// JfrEvent::EndOfChunk => break, +/// event => { /* process event */ } +/// } +/// } +/// } +/// ``` +#[derive(Default)] +pub struct JfrReader { + data: Vec, + pos: usize, + + pub start_nanos: i64, + pub end_nanos: i64, + pub chunk_info: ChunkInfo, + + // Constant pools — public for consumers to resolve IDs + pub types: HashMap, + pub types_by_name: HashMap, + pub threads: HashMap, + pub java_thread_ids: HashMap, + pub classes: HashMap, + pub strings: HashMap, + pub symbols: HashMap>, + pub methods: HashMap, + pub stack_traces: HashMap, + pub settings: HashMap, + pub enums: HashMap>, + + // Cached event type IDs for this chunk + execution_sample: i32, + native_method_sample: i32, + wall_clock_sample: i32, + method_trace: i32, + alloc_in_new_tlab: i32, + alloc_outside_tlab: i32, + alloc_sample: i32, + live_object: i32, + monitor_enter: i32, + thread_park: i32, + active_setting: i32, + malloc: i32, + free: i32, + cpu_time_sample: i32, + native_lock: i32, + has_wall_time_span: bool, + + state: State, + chunk_end: usize, // absolute position of current chunk end +} + +// Public API and Event Readers +impl JfrReader { + /// Opens a JFR file at `path`, reads it into memory, and parses the first chunk + /// (header, metadata, and constant pools). Returns a ready-to-iterate reader. + pub fn open(path: &str) -> Result { + let mut file = File::open(path)?; + let mut data = Vec::new(); + file.read_to_end(&mut data)?; + Self::from_bytes(data) + } + + /// Creates a [`JfrReader`] from raw JFR bytes and parses the first chunk. + pub fn from_bytes(data: Vec) -> Result { + let mut reader = JfrReader::default(); + reader.data = data; + reader.start_nanos = i64::MAX; + reader.end_nanos = i64::MIN; + reader.chunk_info.ticks_per_sec = 1; + reader.execution_sample = -1; + reader.native_method_sample = -1; + reader.wall_clock_sample = -1; + reader.method_trace = -1; + reader.alloc_in_new_tlab = -1; + reader.alloc_outside_tlab = -1; + reader.alloc_sample = -1; + reader.live_object = -1; + reader.monitor_enter = -1; + reader.thread_park = -1; + reader.active_setting = -1; + reader.malloc = -1; + reader.free = -1; + reader.cpu_time_sample = -1; + reader.native_lock = -1; + + if !reader.read_chunk()? { + bail!("Incomplete JFR file"); + } + Ok(reader) + } + + /// Returns `true` if there are more chunks to read. When the current chunk + /// is exhausted (i.e., [`read_event`](Self::read_event) returned `EndOfChunk`), + /// call this to advance to the next chunk. + pub fn has_more_chunks(&mut self) -> Result { + if self.state == State::NewChunk { + self.read_chunk() + } else { + Ok(self.state == State::Reading) + } + } + + /// Returns the next event in the current chunk, or `EndOfChunk` when the chunk + /// is exhausted. Internal events (e.g., `ActiveSetting`) are consumed + /// silently and not returned. Call [`has_more_chunks`](Self::has_more_chunks) + /// after `EndOfChunk` to advance to the next chunk. + pub fn read_event(&mut self) -> Result { + loop { + if self.pos + 4 > self.data.len() || self.pos >= self.chunk_end { + if self.pos < self.data.len() { + self.state = State::NewChunk; + } else { + self.state = State::Eof; + } + return Ok(JfrEvent::EndOfChunk); + } + + let event_start = self.pos; + let size = self.get_varint() as usize; + let type_id = self.get_varint(); + + if size == 0 { + bail!("Corrupted JFR: invalid event size"); + } + + // Check for chunk boundary + if type_id == 'L' as i32 && event_start + 4 <= self.data.len() { + let sig = u32::from_be_bytes([ + self.data[event_start], + self.data[event_start + 1], + self.data[event_start + 2], + self.data[event_start + 3], + ]); + if sig == CHUNK_SIGNATURE { + self.pos = event_start; + self.state = State::NewChunk; + return Ok(JfrEvent::EndOfChunk); + } + } + + let event_end = event_start + size; + + let result = self.parse_event(type_id); + self.pos = event_end; // always advance past event + + if let Some(event) = result { + return Ok(event); + } + // Unknown event type or active setting — skip and continue + } + } + + fn parse_event(&mut self, type_id: i32) -> Option { + if type_id == self.execution_sample { + Some(JfrEvent::ExecutionSample( + self.read_execution_sample(false, ExecSampleType::Execution), + )) + } else if type_id == self.native_method_sample { + Some(JfrEvent::ExecutionSample( + self.read_execution_sample(false, ExecSampleType::NativeMethod), + )) + } else if type_id == self.wall_clock_sample { + Some(JfrEvent::ExecutionSample( + self.read_execution_sample(true, ExecSampleType::WallClock), + )) + } else if type_id == self.method_trace { + Some(JfrEvent::MethodTrace(self.read_method_trace())) + } else if type_id == self.alloc_in_new_tlab { + Some(JfrEvent::AllocationSample( + self.read_allocation_sample(true), + )) + } else if type_id == self.alloc_outside_tlab || type_id == self.alloc_sample { + Some(JfrEvent::AllocationSample( + self.read_allocation_sample(false), + )) + } else if type_id == self.cpu_time_sample { + Some(JfrEvent::ExecutionSample(self.read_cpu_time_sample())) + } else if type_id == self.malloc { + Some(JfrEvent::MallocEvent(self.read_malloc_event(true))) + } else if type_id == self.free { + Some(JfrEvent::MallocEvent(self.read_malloc_event(false))) + } else if type_id == self.live_object { + Some(JfrEvent::LiveObject(self.read_live_object())) + } else if type_id == self.monitor_enter { + Some(JfrEvent::ContendedLock(self.read_contended_lock(false))) + } else if type_id == self.thread_park { + Some(JfrEvent::ContendedLock(self.read_contended_lock(true))) + } else if type_id == self.native_lock { + Some(JfrEvent::NativeLock(self.read_native_lock_event())) + } else if type_id == self.active_setting { + self.read_active_setting(); + None + } else { + None + } + } + + // Event readers + fn read_execution_sample( + &mut self, + wall: bool, + sample_type: ExecSampleType, + ) -> ExecutionSample { + let time = self.get_varlong(); + let tid = self.get_varint(); + let stack_trace_id = self.get_varint(); + let thread_state = self.get_varint(); + let samples = if wall { self.get_varint() } else { 1 }; + if wall && self.has_wall_time_span { + self.get_varlong(); // timeSpan ignored + } + ExecutionSample { + time, + tid, + stack_trace_id, + thread_state, + samples, + sample_type, + } + } + + fn read_method_trace(&mut self) -> MethodTraceEvent { + let time = self.get_varlong(); + let duration = self.get_varlong(); + let tid = self.get_varint(); + let stack_trace_id = self.get_varint(); + let method = self.get_varint(); + MethodTraceEvent { + time, + tid, + stack_trace_id, + method, + duration, + } + } + + fn read_allocation_sample(&mut self, tlab: bool) -> AllocationSample { + let time = self.get_varlong(); + let tid = self.get_varint(); + let stack_trace_id = self.get_varint(); + let class_id = self.get_varint(); + let allocation_size = self.get_varlong(); + let tlab_size = if tlab { self.get_varlong() } else { 0 }; + AllocationSample { + time, + tid, + stack_trace_id, + class_id, + allocation_size, + tlab_size, + } + } + + fn read_cpu_time_sample(&mut self) -> ExecutionSample { + let time = self.get_varlong(); + let stack_trace_id = self.get_varint(); + let tid = self.get_varint(); + let _failed = self.get_byte() != 0; + let _sampling_period = self.get_varlong(); + let _biased = self.get_byte() != 0; + ExecutionSample { + time, + tid, + stack_trace_id, + thread_state: 254, + samples: 1, + sample_type: ExecSampleType::CpuTime, + } + } + + fn read_malloc_event(&mut self, has_size: bool) -> MallocEvent { + let time = self.get_varlong(); + let tid = self.get_varint(); + let stack_trace_id = self.get_varint(); + let address = self.get_varlong(); + let size = if has_size { self.get_varlong() } else { 0 }; + MallocEvent { + time, + tid, + stack_trace_id, + address, + size, + } + } + + fn read_live_object(&mut self) -> LiveObject { + let time = self.get_varlong(); + let tid = self.get_varint(); + let stack_trace_id = self.get_varint(); + let class_id = self.get_varint(); + let allocation_size = self.get_varlong(); + let allocation_time = self.get_varlong(); + LiveObject { + time, + tid, + stack_trace_id, + class_id, + allocation_size, + allocation_time, + } + } + + fn read_contended_lock(&mut self, has_timeout: bool) -> ContendedLock { + let time = self.get_varlong(); + let duration = self.get_varlong(); + let tid = self.get_varint(); + let stack_trace_id = self.get_varint(); + let class_id = self.get_varint(); + if has_timeout { + self.get_varlong(); + } + let _until = self.get_varlong(); + let _address = self.get_varlong(); + ContendedLock { + time, + tid, + stack_trace_id, + duration, + class_id, + } + } + + fn read_native_lock_event(&mut self) -> NativeLockEvent { + let time = self.get_varlong(); + let duration = self.get_varlong(); + let tid = self.get_varint(); + let stack_trace_id = self.get_varint(); + let address = self.get_varlong(); + NativeLockEvent { + time, + tid, + stack_trace_id, + address, + duration, + } + } + + fn read_active_setting(&mut self) { + // Skip fields until we reach "id", then read name + value strings + if let Some(cls) = self.types_by_name.get("jdk.ActiveSetting").cloned() { + for field in &cls.fields { + self.get_varlong(); + if field.name == "id" { + break; + } + } + } + let name = self.get_string(); + let value = self.get_string(); + if let (Some(n), Some(v)) = (name, value) { + self.settings.insert(n, v); + } + } +} + +// Chunk and Constant Pool Parsing +impl JfrReader { + /// Reads the chunk header, metadata and constant pool. Then sets the read pointer + /// to the start of the events and sets state to Reading. + /// + /// JFR Chunk: + /// ```text + /// ┌─── Header ──────────────────────┐ + /// │ signature u32 │ + /// │ version u32 │ + /// │ chunkSize i64 │ + /// │ cpOffset i64 │ + /// │ metaOffset i64 │ + /// │ chunkStartNanos i64 │ + /// │ durationNanos i64 │ + /// │ chunkStartTicks i64 │ + /// │ ticksPerSec i64 │ + /// ├─── Metadata ────────────────────┤ + /// │ size varint │ + /// │ type varint │ + /// │ startTicks varlong │ + /// │ durationTicks varlong │ + /// │ metadataId varlong │ + /// │ stringCount varint │ + /// │ strings string* │ ← interned string table used as + /// │ │ keys/values in element attributes + /// │ elements element* │ ← recursive tree of typed nodes + /// │ │ that describe the schema of events + /// │ │ and constant pool entries in this + /// │ │ chunk. We only process class and + /// │ │ field elements. Others:[root, region, + /// │ │ metadata, annotation, setting] + /// ├─── Constant Pool ───────────────┤ + /// │ size varint │ + /// │ type varint │ + /// │ startTicks varlong │ + /// │ durationTicks varlong │ + /// │ delta varlong │ + /// │ flush varint │ + /// │ poolCount varint │ + /// │ pools pool* │ ← id-keyed lookup tables for shared + /// │ │ objects: threads, classes, strings, + /// │ │ symbols, methods, stack traces, and + /// │ │ enum values. Events reference these + /// │ │ by id to avoid duplication. + /// ├─── Events ──────────────────────┤ + /// │ events event* │ + /// └─────────────────────────────────┘ + /// ``` + fn read_chunk(&mut self) -> Result { + if self.pos + CHUNK_HEADER_SIZE > self.data.len() { + bail!("Not a valid JFR file"); + } + + let sig = self.get_u32_be_at(self.pos); + if sig != CHUNK_SIGNATURE { + bail!("Not a valid JFR file"); + } + + let version = self.get_u32_be_at(self.pos + 4); + if version < 0x20000 || version > 0x2ffff { + bail!( + "Unsupported JFR version: {}.{}", + version >> 16, + version & 0xffff + ); + } + + let chunk_start = self.pos; + let chunk_size = self.get_i64_be_at(self.pos + 8) as usize; + if chunk_start + chunk_size > self.data.len() { + self.state = State::Incomplete; + return Ok(false); + } + + let cp_offset = self.get_i64_be_at(self.pos + 16) as usize; + let meta_offset = self.get_i64_be_at(self.pos + 24) as usize; + if cp_offset == 0 || meta_offset == 0 { + self.state = State::Incomplete; + return Ok(false); + } + + let chunk_start_nanos = self.get_i64_be_at(self.pos + 32); + let duration_nanos = self.get_i64_be_at(self.pos + 40); + let chunk_start_ticks = self.get_i64_be_at(self.pos + 48); + let ticks_per_sec = self.get_i64_be_at(self.pos + 56); + + self.chunk_info = ChunkInfo { + start_nanos: chunk_start_nanos, + end_nanos: chunk_start_nanos + duration_nanos, + start_ticks: chunk_start_ticks, + ticks_per_sec, + }; + + self.start_nanos = self.start_nanos.min(chunk_start_nanos); + self.end_nanos = self.end_nanos.max(chunk_start_nanos + duration_nanos); + + self.chunk_end = chunk_start + chunk_size; + + self.types.clear(); + self.types_by_name.clear(); + + self.read_meta(chunk_start + meta_offset)?; + self.read_constant_pool(chunk_start + cp_offset)?; + self.cache_event_types(); + + self.pos = chunk_start + CHUNK_HEADER_SIZE; + self.state = State::Reading; + Ok(true) + } + + /// Reads chunk specific metadata and elements. + /// Parses the metadata event at `offset`. Reads the interned string table, + /// then walks the element tree via [`read_element`](Self::read_element) to + /// populate [`types`](Self::types) and [`types_by_name`](Self::types_by_name). + fn read_meta(&mut self, offset: usize) -> Result<()> { + self.pos = offset; + let _size = self.get_varint(); + let _type = self.get_varint(); + let _start_ticks = self.get_varlong(); + let _duration_ticks = self.get_varlong(); + let _metadata_id = self.get_varlong(); + + let string_count = self.get_varint() as usize; + let mut meta_strings = Vec::with_capacity(string_count); + for _ in 0..string_count { + meta_strings.push(self.get_string().unwrap_or_default()); + } + self.read_element(&meta_strings); + Ok(()) + } + + /// Reads a serialized tree of N metadata elements, each comprising attributes + /// (key/value pairs) and sub-elements. + /// ```text + /// Root + /// ├── Metadata + /// │ ├── Class 1 + /// │ ├── Class 2 + /// │ │ ... + /// │ └── Class N + /// │ ├── Annotation 1 ... N + /// │ ├── Setting 1 ... N + /// │ └── Field 1 ... N + /// │ └── Annotation 1 ... N + /// └── Region + /// ``` + fn read_element(&mut self, strings: &[String]) -> Element { + let name_idx = self.get_varint() as usize; + let name = strings.get(name_idx).cloned().unwrap_or_default(); + + let attr_count = self.get_varint() as usize; + let mut attributes = HashMap::with_capacity(attr_count); + for _ in 0..attr_count { + let k = strings + .get(self.get_varint() as usize) + .cloned() + .unwrap_or_default(); + let v = strings + .get(self.get_varint() as usize) + .cloned() + .unwrap_or_default(); + attributes.insert(k, v); + } + + let child_count = self.get_varint() as usize; + let mut children = Vec::with_capacity(child_count); + for _ in 0..child_count { + children.push(self.read_element(strings)); + } + + // Create types/fields from metadata + match name.as_str() { + "class" => { + let id: i32 = attributes + .get("id") + .and_then(|s| s.parse().ok()) + .unwrap_or(0); + let type_name = attributes.get("name").cloned().unwrap_or_default(); + let simple_type = attributes + .get("simpleType") + .map(|s| s == "true") + .unwrap_or(false); + let has_super = attributes.contains_key("superType"); + + let mut fields = Vec::new(); + for child in &children { + if let Element::Field(f) = child { + fields.push(f.clone()); + } + } + + let cls = JfrClass { + id, + name: type_name.clone(), + simple_type, + fields, + }; + if !has_super { + self.types.insert(id as i64, cls.clone()); + } + self.types_by_name.insert(type_name, cls); + } + "field" => { + let field = JfrField { + name: attributes.get("name").cloned().unwrap_or_default(), + type_id: attributes + .get("class") + .and_then(|s| s.parse().ok()) + .unwrap_or(0), + constant_pool: attributes + .get("constantPool") + .map(|s| s == "true") + .unwrap_or(false), + }; + return Element::Field(field); + } + _ => {} + } + Element::Other + } + + /// Reads the constant pools from a JFR chunk. + /// Constant pools are stored as a list of pool deltas within the + /// chunk. Each node contains: + /// - A header (size, type, start ticks, duration, delta, flush) + /// - N pools, each identified by a type ID and containing entries + /// parsed according to the type's class definition from metadata + fn read_constant_pool(&mut self, mut cp_offset: usize) -> Result<()> { + loop { + self.pos = cp_offset; + let _size = self.get_varint(); + let _type = self.get_varint(); + let _start_ticks = self.get_varlong(); + let _duration = self.get_varlong(); + let delta = self.get_varlong(); + let _flush = self.get_varint(); + + let pool_count = self.get_varint(); + for _ in 0..pool_count { + let type_id = self.get_varint(); + if let Some(cls) = self.types.get(&(type_id as i64)).cloned() { + self.read_constants(&cls); + } else { + // Unknown type — skip its count entries + let count = self.get_varint(); + for _ in 0..count { + self.get_varlong(); // skip id + unknown fields + } + } + } + + if delta == 0 { + break; + } + cp_offset = (cp_offset as i64 + delta) as usize; + } + Ok(()) + } + + fn read_constants(&mut self, cls: &JfrClass) { + match cls.name.as_str() { + "jdk.types.ChunkHeader" => { + self.pos += CHUNK_HEADER_SIZE + 3; + } + "java.lang.Thread" => self.read_threads(cls.fields.len()), + "java.lang.Class" => self.read_classes(cls.fields.len()), + "java.lang.String" => self.read_strings(), + "jdk.types.Symbol" => self.read_symbols(), + "jdk.types.Method" => self.read_methods(), + "jdk.types.StackTrace" => self.read_stack_traces(), + _ => { + if cls.simple_type && cls.fields.len() == 1 { + self.read_enum_values(&cls.name.clone()); + } else { + self.read_other_constants(cls); + } + } + } + } + + fn read_threads(&mut self, field_count: usize) { + let count = self.get_varint() as usize; + self.threads.reserve(count); + self.java_thread_ids.reserve(count); + for _ in 0..count { + let id = self.get_varlong(); + let os_name = self.get_string(); + let _os_thread_id = self.get_varint(); + let java_name = self.get_string(); + let java_thread_id = self.get_varlong(); + // Skip remaining fields + for _ in 0..field_count.saturating_sub(4) { + self.get_varlong(); + } + let name = java_name.or(os_name).unwrap_or_default(); + self.threads.insert(id, name); + self.java_thread_ids.insert(id, java_thread_id); + } + } + + fn read_classes(&mut self, field_count: usize) { + let count = self.get_varint() as usize; + self.classes.reserve(count); + for _ in 0..count { + let id = self.get_varlong(); + let _loader = self.get_varlong(); + let name = self.get_varlong(); + let _pkg = self.get_varlong(); + let _modifiers = self.get_varint(); + for _ in 0..field_count.saturating_sub(4) { + self.get_varlong(); + } + self.classes.insert(id, ClassRef { name }); + } + } + + fn read_strings(&mut self) { + let count = self.get_varint() as usize; + self.strings.reserve(count); + for _ in 0..count { + let id = self.get_varlong(); + let s = self.get_string().unwrap_or_default(); + self.strings.insert(id, s); + } + } + + fn read_symbols(&mut self) { + let count = self.get_varint() as usize; + self.symbols.reserve(count); + for _ in 0..count { + let id = self.get_varlong(); + let _encoding = self.get_byte(); + let bytes = self.get_bytes(); + self.symbols.insert(id, bytes); + } + } + + fn read_methods(&mut self) { + let count = self.get_varint() as usize; + self.methods.reserve(count); + for _ in 0..count { + let id = self.get_varlong(); + let cls = self.get_varlong(); + let name = self.get_varlong(); + let sig = self.get_varlong(); + let _modifiers = self.get_varint(); + let _hidden = self.get_varint(); + self.methods.insert(id, MethodRef { cls, name, sig }); + } + } + + fn read_stack_traces(&mut self) { + let count = self.get_varint() as usize; + self.stack_traces.reserve(count); + for _ in 0..count { + let id = self.get_varlong(); + let _truncated = self.get_varint(); + let depth = self.get_varint() as usize; + let mut methods = Vec::with_capacity(depth); + let mut types = Vec::with_capacity(depth); + let mut locations = Vec::with_capacity(depth); + for _ in 0..depth { + methods.push(self.get_varlong()); + let line = self.get_varint(); + let bci = self.get_varint(); + locations.push((line << 16) | (bci & 0xffff)); + types.push(self.get_byte()); + } + self.stack_traces.insert( + id, + StackTrace { + methods, + types, + locations, + }, + ); + } + } + + fn read_enum_values(&mut self, type_name: &str) { + let count = self.get_varint() as usize; + let mut map = HashMap::with_capacity(count); + for _ in 0..count { + let key = self.get_varlong() as i32; + let value = self.get_string().unwrap_or_default(); + map.insert(key, value); + } + self.enums.insert(type_name.to_string(), map); + } + + fn read_other_constants(&mut self, cls: &JfrClass) { + let string_type_id = self.get_type_id("java.lang.String"); + let numeric: Vec = cls + .fields + .iter() + .map(|f| f.constant_pool || f.type_id != string_type_id) + .collect(); + let count = self.get_varint() as usize; + for _ in 0..count { + self.get_varlong(); // id + for &is_numeric in &numeric { + if is_numeric { + self.get_varlong(); + } else { + self.get_string(); + } + } + } + } + + fn cache_event_types(&mut self) { + self.execution_sample = self.get_type_id("jdk.ExecutionSample"); + self.native_method_sample = self.get_type_id("jdk.NativeMethodSample"); + self.wall_clock_sample = self.get_type_id("profiler.WallClockSample"); + self.method_trace = self.get_type_id("jdk.MethodTrace"); + self.alloc_in_new_tlab = self.get_type_id("jdk.ObjectAllocationInNewTLAB"); + self.alloc_outside_tlab = self.get_type_id("jdk.ObjectAllocationOutsideTLAB"); + self.alloc_sample = self.get_type_id("jdk.ObjectAllocationSample"); + self.live_object = self.get_type_id("profiler.LiveObject"); + self.monitor_enter = self.get_type_id("jdk.JavaMonitorEnter"); + self.thread_park = self.get_type_id("jdk.ThreadPark"); + self.active_setting = self.get_type_id("jdk.ActiveSetting"); + self.malloc = self.get_type_id("profiler.Malloc"); + self.free = self.get_type_id("profiler.Free"); + self.cpu_time_sample = self.get_type_id("jdk.CPUTimeSample"); + self.native_lock = self.get_type_id("profiler.NativeLock"); + + self.has_wall_time_span = self + .types_by_name + .get("profiler.WallClockSample") + .and_then(|c| c.field("timeSpan")) + .is_some(); + } + + fn get_type_id(&self, name: &str) -> i32 { + self.types_by_name.get(name).map(|c| c.id).unwrap_or(-1) + } +} + +// Primitive Decoders +// Helper functions to decode varints, strings, etc. at the current pointer. +impl JfrReader { + pub fn get_varint(&mut self) -> i32 { + let mut result: i32 = 0; + let mut shift = 0u32; + loop { + let b = self.data[self.pos] as i8; + self.pos += 1; + result |= ((b & 0x7f) as i32) << shift; + if b >= 0 { + return result; + } + shift += 7; + } + } + + pub fn get_varlong(&mut self) -> i64 { + let mut result: i64 = 0; + let mut shift = 0u32; + while shift < 56 { + let b = self.data[self.pos] as i8; + self.pos += 1; + result |= ((b & 0x7f) as i64) << shift; + if b >= 0 { + return result; + } + shift += 7; + } + let b = self.data[self.pos]; + self.pos += 1; + result | ((b as i64) << 56) + } + + pub fn get_byte(&mut self) -> u8 { + let b = self.data[self.pos]; + self.pos += 1; + b + } + + pub fn get_float(&mut self) -> f32 { + let bytes: [u8; 4] = self.data[self.pos..self.pos + 4].try_into().unwrap(); + self.pos += 4; + f32::from_be_bytes(bytes) + } + + pub fn get_string(&mut self) -> Option { + let encoding = self.get_byte(); + match encoding { + 0 => None, + 1 => Some(String::new()), + 2 => { + let id = self.get_varlong(); + self.strings.get(&id).cloned() + } + 3 => { + let bytes = self.get_bytes(); + Some(String::from_utf8_lossy(&bytes).into_owned()) + } + 4 => { + let len = self.get_varint() as usize; + let mut chars = String::with_capacity(len); + for _ in 0..len { + let c = self.get_varint() as u32; + if let Some(ch) = char::from_u32(c) { + chars.push(ch); + } + } + Some(chars) + } + 5 => { + let bytes = self.get_bytes(); + Some(bytes.iter().map(|&b| b as char).collect()) + } + _ => None, + } + } + + pub fn get_bytes(&mut self) -> Vec { + let len = self.get_varint() as usize; + let bytes = self.data[self.pos..self.pos + len].to_vec(); + self.pos += len; + bytes + } + + fn get_u32_be_at(&self, pos: usize) -> u32 { + u32::from_be_bytes(self.data[pos..pos + 4].try_into().unwrap()) + } + + fn get_i64_be_at(&self, pos: usize) -> i64 { + i64::from_be_bytes(self.data[pos..pos + 8].try_into().unwrap()) + } +} + +// Resolution Helper Methods +// This helps convert IDs to methods, symbols, etc from the constant pool +// and tracked by their respective maps. +impl JfrReader { + // Resolve a method ID to (class_name, method_name, signature). + pub fn resolve_method(&self, method_id: i64) -> Option<(String, String, String)> { + let method_ref = self.methods.get(&method_id)?; + let class_ref = self.classes.get(&method_ref.cls)?; + + let class_name = self.resolve_symbol(class_ref.name); + let method_name = self.resolve_symbol(method_ref.name); + let sig = self.resolve_symbol(method_ref.sig); + + Some((class_name, method_name, sig)) + } + + // Resolve a symbol ID — tries strings first, then symbols (byte arrays). + pub fn resolve_symbol(&self, id: i64) -> String { + if let Some(s) = self.strings.get(&id) { + return s.clone(); + } + if let Some(bytes) = self.symbols.get(&id) { + return String::from_utf8_lossy(bytes).into_owned(); + } + format!("[unknown:{}]", id) + } + + // Resolve a thread ID to its name. + pub fn resolve_thread(&self, tid: i64) -> Option { + self.threads.get(&tid).cloned() + } + + // Get the class name for a class constant pool ID. + pub fn resolve_class(&self, class_id: i64) -> String { + if let Some(class_ref) = self.classes.get(&class_id) { + self.resolve_symbol(class_ref.name) + } else { + format!("[class:{}]", class_id) + } + } +} + +// Internal element type for metadata parsing +enum Element { + Field(JfrField), + Other, +} diff --git a/src/profiling/jfr/types.rs b/src/profiling/jfr/types.rs new file mode 100644 index 00000000..bf39293d --- /dev/null +++ b/src/profiling/jfr/types.rs @@ -0,0 +1,222 @@ +// Chunk Constant Pool Types +// Each chunk has a constant pool with references to strings, classes, and other metadata. +// This is used to store frequently referenced objects—such as strings, class names, and +// stack traces to optimize space and reduce overhead. +#[derive(Debug, Clone)] +pub struct ClassRef { + pub name: i64, // index into strings +} + +#[derive(Debug, Clone)] +pub struct MethodRef { + pub cls: i64, // index into classes + pub name: i64, // index into strings/symbols + pub sig: i64, // index into strings/symbols +} + +#[derive(Debug, Clone)] +pub struct StackTrace { + pub methods: Vec, + pub types: Vec, + pub locations: Vec, // line << 16 | (bci & 0xffff) +} + +// Chunk Metadata Types +// Each chunk has metadata to describe its position in the file, start/end time, id, etc. +// Additionally, we record two types of metadata elements fields and classes in these structs. +#[derive(Debug, Clone)] +pub struct JfrField { + pub name: String, + pub type_id: i32, + pub constant_pool: bool, +} + +#[derive(Debug, Clone)] +pub struct JfrClass { + pub id: i32, + pub name: String, + pub simple_type: bool, + pub fields: Vec, +} + +impl JfrClass { + pub fn field(&self, name: &str) -> Option<&JfrField> { + self.fields.iter().find(|f| f.name == name) + } +} + +// Chunk Timing Info +// This struct contains the timing information for the currently processed chunk, +// which is used to convert between different time units (nanoseconds, milliseconds, etc.) +// and to determine the start and end times of the chunk. +#[derive(Debug, Clone, Copy, Default)] +pub struct ChunkInfo { + pub start_nanos: i64, + pub end_nanos: i64, + pub start_ticks: i64, + pub ticks_per_sec: i64, +} + +impl ChunkInfo { + pub fn event_time_to_nanos(&self, ticks: i64) -> i64 { + let nanos_per_tick = 1_000_000_000.0 / self.ticks_per_sec as f64; + self.start_nanos + ((ticks - self.start_ticks) as f64 * nanos_per_tick) as i64 + } + + pub fn event_time_to_millis(&self, ticks: i64) -> i64 { + let ms_from_start = (ticks - self.start_ticks) * 1_000 / self.ticks_per_sec; + self.start_nanos / 1_000_000 + ms_from_start + } +} + +// Sampling Events +// These are the JFR events collected by async-profiler. Each event contains different +// fields describing its information. Shared fields are time, tid, and stack_trace_id. +macro_rules! jfr_event { + ( $( $variant:ident($type:ty) ),* $(,)? ; $( $unit:ident ),* $(,)? ) => { + #[derive(Debug, Clone)] + pub enum JfrEvent { + $( $variant($type), )* + $( $unit, )* + } + + impl JfrEvent { + pub fn time(&self) -> i64 { + match self { + $( Self::$variant(e) => e.time, )* + $( Self::$unit => 0, )* + } + } + pub fn tid(&self) -> i32 { + match self { + $( Self::$variant(e) => e.tid, )* + $( Self::$unit => 0, )* + } + } + pub fn stack_trace_id(&self) -> i32 { + match self { + $( Self::$variant(e) => e.stack_trace_id, )* + $( Self::$unit => 0, )* + } + } + } + }; +} + +jfr_event!( + // jdk.ExecutionSample / jdk.NativeMethodSample / profiler.WallClockSample / jdk.CPUTimeSample + // CPU and wall-clock sampling of Java and native threads + ExecutionSample(ExecutionSample), + + // jdk.ObjectAllocationInNewTLAB / jdk.ObjectAllocationOutsideTLAB + // Heap allocation events with TLAB info + AllocationSample(AllocationSample), + + // jdk.JavaMonitorEnter + // Java monitor contention (synchronized block wait time) + ContendedLock(ContendedLock), + + // profiler.LiveObject + // Heap objects still alive at profiling time (for leak detection) + LiveObject(LiveObject), + + // profiler.Malloc / profiler.Free + // Native memory allocation and deallocation via malloc/free + MallocEvent(MallocEvent), + + // jdk.MethodTrace + // Method-level tracing with entry/exit duration + MethodTrace(MethodTraceEvent), + + // profiler.NativeLock + // Native (pthread) mutex contention + NativeLock(NativeLockEvent), + + // User-defined custom events with raw payload + Custom(CustomEvent), + ; + // Sentinel marking the end of a JFR chunk (not a real event) + EndOfChunk, +); + +#[derive(Debug, Clone, Copy, PartialEq, Eq)] +pub enum ExecSampleType { + Execution, + NativeMethod, + WallClock, + CpuTime, +} + +#[derive(Debug, Clone)] +pub struct ExecutionSample { + pub time: i64, + pub tid: i32, + pub stack_trace_id: i32, + pub thread_state: i32, + pub samples: i32, + pub sample_type: ExecSampleType, +} + +#[derive(Debug, Clone)] +pub struct AllocationSample { + pub time: i64, + pub tid: i32, + pub stack_trace_id: i32, + pub class_id: i32, + pub allocation_size: i64, + pub tlab_size: i64, +} + +#[derive(Debug, Clone)] +pub struct ContendedLock { + pub time: i64, + pub tid: i32, + pub stack_trace_id: i32, + pub duration: i64, + pub class_id: i32, +} + +#[derive(Debug, Clone)] +pub struct LiveObject { + pub time: i64, + pub tid: i32, + pub stack_trace_id: i32, + pub class_id: i32, + pub allocation_size: i64, + pub allocation_time: i64, +} + +#[derive(Debug, Clone)] +pub struct MallocEvent { + pub time: i64, + pub tid: i32, + pub stack_trace_id: i32, + pub address: i64, + pub size: i64, +} + +#[derive(Debug, Clone)] +pub struct MethodTraceEvent { + pub time: i64, + pub tid: i32, + pub stack_trace_id: i32, + pub method: i32, + pub duration: i64, +} + +#[derive(Debug, Clone)] +pub struct NativeLockEvent { + pub time: i64, + pub tid: i32, + pub stack_trace_id: i32, + pub address: i64, + pub duration: i64, +} + +#[derive(Debug, Clone)] +pub struct CustomEvent { + pub time: i64, + pub tid: i32, + pub stack_trace_id: i32, + pub raw_data: Vec, +} diff --git a/src/profiling/mod.rs b/src/profiling/mod.rs new file mode 100644 index 00000000..bf8bbdeb --- /dev/null +++ b/src/profiling/mod.rs @@ -0,0 +1,460 @@ +//! Profiling data format parsers, converters, and core profile structures. +//! +//! This module contains: +//! - Core profile data structures ([`Profile`], [`CCTree`], [`ThreadState`], etc.) +//! - [`jfr`] — JFR (Java Flight Recorder) binary format parser for async-profiler output. + +pub mod jfr; + +pub const BUCKET_WIDTH_MS: u64 = 100; + +use crate::data::common::data_formats::ProfilerData; +use regex::Regex; +use serde::{Deserialize, Serialize}; +use std::cell::OnceCell; +use std::collections::HashMap; + +/// A single profiling type's data (e.g., cpu, wall, allocation). +#[derive(Debug, Clone, Serialize, Deserialize)] +pub struct Profile { + /// Time-ordered blocks of sample data, [thread_state_id -> node_id (index into context_tree) -> sample count] + pub blocks: Vec>>, + /// Block number time range where profile node aggregate counts are calculated + pub time_range: (usize, usize), + /// Tree nodes, index 0 is the root (index is node_id) + pub context_tree: Vec, + /// Bidirectional map frame_id to Frame: each Frame stores its name and the node_ids that use it + pub frame_map: FrameMap, + /// Cache: thread_state_id -> total self_samples across all nodes (lazily computed in report time) + #[serde(skip)] + total_samples_per_thread_state: OnceCell>, +} + +/// A node in the call tree. Each node represents a unique call path. +#[derive(Debug, Clone, Serialize, Deserialize)] +pub struct CCTreeNode { + /// Index of parent node in the nodes vec, None for root + pub parent: Option, + /// Frame ID, indexes into frame_map to get frame name + pub frame_id: usize, + /// Map thread_state_id -> sample count for this frame for time_range specified in CCTree + pub sample_stats: HashMap, + /// Map from child frame_id -> child node_id for fast tree insertion + pub children: HashMap, +} + +#[derive(Debug, Clone, Serialize, Deserialize)] +pub struct SampleStats { + /// Number of samples in this frame, including children + pub total_samples: u64, + /// Number of samples in this frame, excluding children + pub self_samples: u64, +} + +/// Frame id to name bidirectional mapping, with name→index lookup for insertion. +#[derive(Debug, Clone, Serialize, Deserialize)] +pub struct FrameMap { + frame_id_to_frame: Vec, + #[serde(skip)] + frame_name_to_frame_id: HashMap, +} + +/// A frame: its name and all call tree nodes that have this frame. +#[derive(Debug, Clone, Serialize, Deserialize)] +pub struct Frame { + pub name: String, + pub node_ids: Vec, +} + +impl FrameMap { + pub fn new() -> Self { + Self { + frame_id_to_frame: Vec::new(), + frame_name_to_frame_id: HashMap::new(), + } + } + + /// Get or insert a frame name, returning its frame_id. + pub fn get_or_insert(&mut self, name: &str) -> usize { + if let Some(&id) = self.frame_name_to_frame_id.get(name) { + return id; + } + let id = self.frame_id_to_frame.len(); + self.frame_id_to_frame.push(Frame { + name: name.to_string(), + node_ids: Vec::new(), + }); + self.frame_name_to_frame_id.insert(name.to_string(), id); + id + } + + /// Get frame name by ID. + pub fn name(&self, id: usize) -> &str { + &self.frame_id_to_frame[id].name + } + + /// Get node IDs for a given frame id. + pub fn node_ids(&self, id: usize) -> &[usize] { + &self.frame_id_to_frame[id].node_ids + } + + /// Register a node_id under a frame. + pub fn add_node(&mut self, frame_id: usize, node_id: usize) { + self.frame_id_to_frame[frame_id].node_ids.push(node_id); + } + + pub fn len(&self) -> usize { + self.frame_id_to_frame.len() + } +} + +// Public functions for building ProfilerData +impl ProfilerData { + /// Insert a stack sample into the appropriate profile and time block. + /// + /// Computes the block index from `sample_time_ms` relative to `self.start_time` + /// and `self.block_width`, then delegates to [`Profile::insert_stack`]. + pub fn insert_stack( + &mut self, + profile_type: &str, + sample_time_ms: i64, + thread_state: ThreadState, + frames: &[String], + count: u64, + ) { + let profile = self + .profiles + .entry(profile_type.to_string()) + .or_insert_with(Profile::new); + profile.insert_stack( + sample_time_ms, + self.start_time_ms, + self.block_width_ms, + thread_state, + frames, + count, + ); + } + + /// Get sample count for a stack pattern in a specific profile type. + /// Returns 0 if the profile type doesn't exist. + pub fn get_samples( + &self, + profile_type: &str, + pattern: &[&str], + frame_type: Option, + thread_states: &[ThreadState], + total_samples: bool, + ) -> u64 { + self.profiles.get(profile_type).map_or(0, |p| { + p.get_samples(pattern, frame_type, thread_states, total_samples) + }) + } + + /// Get total samples across all nodes for a specific profile type. + /// Returns 0 if the profile type doesn't exist. + pub fn get_total_samples(&self, profile_type: &str, thread_states: &[ThreadState]) -> u64 { + self.profiles + .get(profile_type) + .map_or(0, |p| p.get_total_samples(thread_states)) + } +} + +impl Profile { + pub fn new() -> Self { + let mut frame_map = FrameMap::new(); + frame_map.get_or_insert("[root]"); + Self { + blocks: Vec::new(), + time_range: (0, 0), + context_tree: vec![CCTreeNode { + parent: None, + frame_id: 0, + sample_stats: HashMap::new(), + children: HashMap::new(), + }], + frame_map, + total_samples_per_thread_state: OnceCell::new(), + } + } + + /// Returns sum of sample counts for call graph nodes matching a stack pattern. + /// Pattern frames must appear in order walking from root to leaf (i.e., parent→child order). + /// Example: pattern ["A", "C"] matches nodes named "C" that have an ancestor named "A". + /// + /// Uses recursive DFS with regex index tracking: + /// - total_samples: stops at the shallowest full match (total_samples includes descendants). + /// - self_samples: continues to all nodes matching the last regex at any depth. + fn get_samples( + &self, + pattern: &[&str], + frame_type: Option, + thread_states: &[ThreadState], + total_samples: bool, + ) -> u64 { + if pattern.is_empty() { + return 0; + } + + // Convert patterns to regex with frame_type suffix added to last pattern. + let regexes: Vec = pattern + .iter() + .enumerate() + .map(|(idx, frame)| { + let suffix = if idx == pattern.len() - 1 { + frame_type.map_or(FrameType::any_regex_suffix(), |ft| ft.regex_suffix()) + } else { + FrameType::any_regex_suffix() + }; + Regex::new(&format!("^{}{}$", frame, suffix)).unwrap() + }) + .collect(); + + let thread_state_ids = self.resolve_thread_states(thread_states); + self.dfs_sum_samples(0, 0, ®exes, &thread_state_ids, total_samples) + } + + /// DFS with regex index tracking. On full pattern match: + /// - total_samples=true: sum total_samples, stop (already includes descendants). + /// - total_samples=false: sum self_samples, keep descending for deeper last-regex matches. + fn dfs_sum_samples( + &self, + node_id: usize, + regex_idx: usize, + regexes: &[Regex], + thread_state_ids: &[u8], + total_samples: bool, + ) -> u64 { + let mut result: u64 = 0; + for (&child_frame_id, &child_node_id) in &self.context_tree[node_id].children { + // Increment regex index if current frame matches + let next_idx = if regexes[regex_idx].is_match(self.frame_map.name(child_frame_id)) { + regex_idx + 1 + } else { + regex_idx + }; + + if next_idx == regexes.len() { + let node = &self.context_tree[child_node_id]; + result += thread_state_ids + .iter() + .filter_map(|ts| { + node.sample_stats.get(ts).map(|s| { + if total_samples { + s.total_samples + } else { + s.self_samples + } + }) + }) + .sum::(); + if !total_samples { + result += self.dfs_sum_samples( + child_node_id, + regex_idx, + regexes, + thread_state_ids, + false, + ); + } + } else { + result += self.dfs_sum_samples( + child_node_id, + next_idx, + regexes, + thread_state_ids, + total_samples, + ); + } + } + result + } + + /// Get total samples across all nodes for specified thread states. + /// If thread_states is empty, sums all thread states. + fn get_total_samples(&self, thread_states: &[ThreadState]) -> u64 { + let map = self.total_samples_per_thread_state.get_or_init(|| { + let mut m = HashMap::new(); + for node in &self.context_tree { + for (&thread_state_id, stats) in &node.sample_stats { + *m.entry(thread_state_id).or_default() += stats.self_samples; + } + } + m + }); + let thread_state_ids = self.resolve_thread_states(thread_states); + thread_state_ids + .iter() + .filter_map(|thread_state_id| map.get(thread_state_id)) + .sum() + } + + /// This function calculates the appropriate bucket index and inserts a stack frame with count + /// into Profile. + pub fn insert_stack( + &mut self, + sample_time_ms: i64, + start_time_ms: i64, + bucket_width_ms: u64, + thread_state: ThreadState, + frames: &[String], + count: u64, + ) { + // Calculate block index and extend blocks vec if necessary + let thread_state_id = thread_state.id(); + let offset_ms = (sample_time_ms - start_time_ms).max(0) as u64; + let block_idx = (offset_ms / bucket_width_ms) as usize; + + while self.blocks.len() <= block_idx { + self.blocks.push(HashMap::new()); + } + + // Iterate through tree layers by frame + let mut curr_node_id = 0usize; + + for frame_name in frames { + let frame_id = self.frame_map.get_or_insert(frame_name); + + curr_node_id = if let Some(&child_node_id) = + self.context_tree[curr_node_id].children.get(&frame_id) + { + child_node_id + } else { + // New call context found: insert new node, and update parent node and frames map + let new_node_id = self.context_tree.len(); + self.context_tree.push(CCTreeNode { + parent: Some(curr_node_id), + frame_id, + sample_stats: HashMap::new(), + children: HashMap::new(), + }); + self.context_tree[curr_node_id] + .children + .insert(frame_id, new_node_id); + self.frame_map.add_node(frame_id, new_node_id); + new_node_id + }; + + // Update sample stats total_samples for non-leaf nodes + self.context_tree[curr_node_id] + .sample_stats + .entry(thread_state_id) + .or_insert(SampleStats { + total_samples: 0, + self_samples: 0, + }) + .total_samples += count; + } + + // For the leaf node of stack, update self samples + self.context_tree[curr_node_id] + .sample_stats + .entry(thread_state_id) + .or_insert(SampleStats { + total_samples: 0, + self_samples: 0, + }) + .self_samples += count; + + // Update aggregate count in blocks vec + *self.blocks[block_idx] + .entry(thread_state_id) + .or_default() + .entry(curr_node_id) + .or_default() += count; + } + + fn resolve_thread_states(&self, thread_states: &[ThreadState]) -> Vec { + if thread_states.is_empty() { + ThreadState::ALL + .iter() + .map(|thread_state| thread_state.id()) + .collect() + } else { + thread_states + .iter() + .map(|thread_state| thread_state.id()) + .collect() + } + } +} + +#[derive(Debug, Clone, Copy)] +pub enum FrameType { + Jit, // _[j] + Inlined, // _[i] + Kernel, // _[k] + Interpreted, // _[0] + C1, // _[1] + Native, // no suffix +} + +impl FrameType { + pub(crate) fn literal_suffix(&self) -> &'static str { + match self { + FrameType::Jit => "_[j]", + FrameType::Inlined => "_[i]", + FrameType::Kernel => "_[k]", + FrameType::Interpreted => "_[0]", + FrameType::C1 => "_[1]", + FrameType::Native => "", + } + } + + pub(crate) fn regex_suffix(&self) -> &'static str { + match self { + FrameType::Jit => "_\\[j\\]", + FrameType::Inlined => "_\\[i\\]", + FrameType::Kernel => "_\\[k\\]", + FrameType::Interpreted => "_\\[0\\]", + FrameType::C1 => "_\\[1\\]", + FrameType::Native => "", + } + } + + /// Regex pattern that matches any frame type suffix (including none). + pub(crate) fn any_regex_suffix() -> &'static str { + "(_\\[(0|j|i|k|1)\\])?" + } + + pub(crate) fn from_jfr_name(name: &str) -> Self { + match name { + "Interpreted" => FrameType::Interpreted, + "JIT compiled" => FrameType::Jit, + "Inlined" => FrameType::Inlined, + "Kernel" => FrameType::Kernel, + "C1 compiled" => FrameType::C1, + _ => FrameType::Native, + } + } +} + +#[derive(Debug, Clone, Copy, PartialEq, Eq, Hash, Serialize, Deserialize)] +#[repr(u8)] +pub enum ThreadState { + None = 0, + AsyncRunnable = 1, + AsyncSleeping = 2, + AsyncDefault = 3, +} + +impl ThreadState { + pub const ALL: [ThreadState; 3] = [ + ThreadState::AsyncRunnable, + ThreadState::AsyncSleeping, + ThreadState::AsyncDefault, + ]; + + pub fn from_str(name: &str) -> Self { + match name { + "STATE_RUNNABLE" => ThreadState::AsyncRunnable, + "STATE_SLEEPING" => ThreadState::AsyncSleeping, + "STATE_DEFAULT" => ThreadState::AsyncDefault, + _ => ThreadState::None, + } + } + + pub fn id(self) -> u8 { + self as u8 + } +} diff --git a/tests/analytics/mod.rs b/tests/analytics/mod.rs index c3450cf8..e521554a 100644 --- a/tests/analytics/mod.rs +++ b/tests/analytics/mod.rs @@ -1,6 +1,9 @@ pub mod test_helpers; pub mod test_key_value_key_expected_rule; pub mod test_key_value_key_run_comparison_rule; +pub mod test_profile_metadata_comparison_rule; +pub mod test_profile_metadata_expected_rule; +pub mod test_profile_stack_frame_threshold_rule; pub mod test_time_series_data_point_threshold_rule; pub mod test_time_series_stat_intra_run_comparison_rule; pub mod test_time_series_stat_run_comparison_rule; diff --git a/tests/analytics/test_profile_metadata_comparison_rule.rs b/tests/analytics/test_profile_metadata_comparison_rule.rs new file mode 100644 index 00000000..ef7df8a9 --- /dev/null +++ b/tests/analytics/test_profile_metadata_comparison_rule.rs @@ -0,0 +1,216 @@ +use aperf::analytics::profile_metadata_comparison_rule::ProfileMetadataComparisonRule; +use aperf::analytics::{Analyze, DataFindings, Score, BASE_RUN_NAME}; +use aperf::data::common::data_formats::{ + AperfData, GraphData, KeyValueData, KeyValueGroup, ProfilerData, +}; +use aperf::data::common::processed_data_accessor::ProcessedDataAccessor; +use std::collections::HashMap; + +use super::test_helpers::{create_processed_data, DataFindingsExt}; + +fn set_base_run(name: &str) { + *BASE_RUN_NAME.lock().unwrap() = name.to_string(); +} + +fn create_key_value_data(group: &str, key: &str, value: Option<&str>) -> KeyValueData { + let mut key_values = HashMap::new(); + if let Some(v) = value { + key_values.insert(key.to_string(), v.to_string()); + } + + let mut key_value_groups = HashMap::new(); + key_value_groups.insert(group.to_string(), KeyValueGroup { key_values }); + + KeyValueData { key_value_groups } +} + +fn create_graph_data(metadata: Vec) -> GraphData { + let mut map = HashMap::new(); + for (i, data) in metadata.into_iter().enumerate() { + map.insert( + format!("profile_{}", i), + ProfilerData { + start_time_ms: 0, + block_width_ms: 0, + metadata: data, + profiles: HashMap::new(), + }, + ); + } + GraphData { + graph_groups: vec![], + profiler_data_map: map, + } +} + +#[test] +fn test_values_match_across_runs() { + set_base_run("run1"); + + let graph_data1 = create_graph_data(vec![create_key_value_data("cpu", "mode", Some("kernel"))]); + let graph_data2 = create_graph_data(vec![create_key_value_data("cpu", "mode", Some("kernel"))]); + let processed_data = create_processed_data( + "test_data", + vec![ + ("run1", AperfData::Graph(graph_data1)), + ("run2", AperfData::Graph(graph_data2)), + ], + ); + + let rule = ProfileMetadataComparisonRule { + rule_name: "test_rule", + group: "cpu", + key: "mode", + should_exist: true, + score: Score::Bad.as_f64(), + message: "Test message", + }; + + let mut findings = DataFindings::default(); + rule.analyze( + &mut findings, + &processed_data, + &mut ProcessedDataAccessor::new(), + ); + + assert_eq!(findings.num_runs_with_findings(), 0); +} + +#[test] +fn test_values_differ_across_runs() { + set_base_run("run1"); + + let graph_data1 = create_graph_data(vec![create_key_value_data("cpu", "mode", Some("kernel"))]); + let graph_data2 = create_graph_data(vec![create_key_value_data("cpu", "mode", Some("user"))]); + let processed_data = create_processed_data( + "test_data", + vec![ + ("run1", AperfData::Graph(graph_data1)), + ("run2", AperfData::Graph(graph_data2)), + ], + ); + + let rule = ProfileMetadataComparisonRule { + rule_name: "test_rule", + group: "cpu", + key: "mode", + should_exist: true, + score: Score::Bad.as_f64(), + message: "Test message", + }; + + let mut findings = DataFindings::default(); + rule.analyze( + &mut findings, + &processed_data, + &mut ProcessedDataAccessor::new(), + ); + + assert_eq!(findings.num_runs_with_findings(), 1); + assert!(findings.has_findings_for_run("run2")); +} + +#[test] +fn test_field_missing_in_non_base_run() { + set_base_run("run1"); + + let graph_data1 = create_graph_data(vec![create_key_value_data("cpu", "mode", Some("kernel"))]); + let graph_data2 = create_graph_data(vec![create_key_value_data("cpu", "mode", None)]); + let processed_data = create_processed_data( + "test_data", + vec![ + ("run1", AperfData::Graph(graph_data1)), + ("run2", AperfData::Graph(graph_data2)), + ], + ); + + let rule = ProfileMetadataComparisonRule { + rule_name: "test_rule", + group: "cpu", + key: "mode", + should_exist: true, + score: Score::Bad.as_f64(), + message: "Test message", + }; + + let mut findings = DataFindings::default(); + rule.analyze( + &mut findings, + &processed_data, + &mut ProcessedDataAccessor::new(), + ); + + assert_eq!(findings.num_runs_with_findings(), 1); + assert!(findings.has_findings_for_run("run2")); +} + +#[test] +fn test_field_missing_in_base_run() { + set_base_run("run1"); + + let graph_data1 = create_graph_data(vec![create_key_value_data("cpu", "mode", None)]); + let graph_data2 = create_graph_data(vec![create_key_value_data("cpu", "mode", Some("kernel"))]); + let processed_data = create_processed_data( + "test_data", + vec![ + ("run1", AperfData::Graph(graph_data1)), + ("run2", AperfData::Graph(graph_data2)), + ], + ); + + let rule = ProfileMetadataComparisonRule { + rule_name: "test_rule", + group: "cpu", + key: "mode", + should_exist: false, + score: Score::Bad.as_f64(), + message: "Test message", + }; + + let mut findings = DataFindings::default(); + rule.analyze( + &mut findings, + &processed_data, + &mut ProcessedDataAccessor::new(), + ); + + assert_eq!(findings.num_runs_with_findings(), 0); +} + +#[test] +fn test_multiple_non_base_runs() { + set_base_run("run1"); + + let graph_data1 = create_graph_data(vec![create_key_value_data("cpu", "mode", Some("kernel"))]); + let graph_data2 = create_graph_data(vec![create_key_value_data("cpu", "mode", Some("kernel"))]); + let graph_data3 = create_graph_data(vec![create_key_value_data("cpu", "mode", Some("user"))]); + let processed_data = create_processed_data( + "test_data", + vec![ + ("run1", AperfData::Graph(graph_data1)), + ("run2", AperfData::Graph(graph_data2)), + ("run3", AperfData::Graph(graph_data3)), + ], + ); + + let rule = ProfileMetadataComparisonRule { + rule_name: "test_rule", + group: "cpu", + key: "mode", + should_exist: true, + score: Score::Bad.as_f64(), + message: "Test message", + }; + + let mut findings = DataFindings::default(); + rule.analyze( + &mut findings, + &processed_data, + &mut ProcessedDataAccessor::new(), + ); + + assert_eq!(findings.num_runs_with_findings(), 1); + assert!(!findings.has_findings_for_run("run1")); + assert!(!findings.has_findings_for_run("run2")); + assert!(findings.has_findings_for_run("run3")); +} diff --git a/tests/analytics/test_profile_metadata_expected_rule.rs b/tests/analytics/test_profile_metadata_expected_rule.rs new file mode 100644 index 00000000..f72fc8c4 --- /dev/null +++ b/tests/analytics/test_profile_metadata_expected_rule.rs @@ -0,0 +1,184 @@ +use aperf::analytics::profile_metadata_expected_rule::ProfileMetadataExpectedRule; +use aperf::analytics::{Analyze, DataFindings, Score}; +use aperf::data::common::data_formats::{ + AperfData, GraphData, KeyValueData, KeyValueGroup, ProfilerData, +}; +use aperf::data::common::processed_data_accessor::ProcessedDataAccessor; +use std::collections::HashMap; + +use super::test_helpers::{create_processed_data, DataFindingsExt}; + +fn create_key_value_data(group: &str, key: &str, value: Option<&str>) -> KeyValueData { + let mut key_values = HashMap::new(); + if let Some(v) = value { + key_values.insert(key.to_string(), v.to_string()); + } + + let mut key_value_groups = HashMap::new(); + key_value_groups.insert(group.to_string(), KeyValueGroup { key_values }); + + KeyValueData { key_value_groups } +} + +fn create_graph_data(metadata: Vec) -> GraphData { + let mut map = HashMap::new(); + for (i, data) in metadata.into_iter().enumerate() { + map.insert( + format!("profile_{}", i), + ProfilerData { + start_time_ms: 0, + block_width_ms: 0, + metadata: data, + profiles: HashMap::new(), + }, + ); + } + GraphData { + graph_groups: vec![], + profiler_data_map: map, + } +} + +#[test] +fn test_field_matches_expected_value() { + let graph_data = create_graph_data(vec![create_key_value_data("cpu", "mode", Some("kernel"))]); + let processed_data = + create_processed_data("test_data", vec![("run1", AperfData::Graph(graph_data))]); + + let rule = ProfileMetadataExpectedRule { + rule_name: "test_rule", + group: "cpu", + key: "mode", + expected_value: "kernel", + should_exist: true, + score: Score::Good.as_f64(), + message: "Test message", + }; + + let mut findings = DataFindings::default(); + rule.analyze( + &mut findings, + &processed_data, + &mut ProcessedDataAccessor::new(), + ); + + assert_eq!(findings.num_runs_with_findings(), 0); +} + +#[test] +fn test_field_does_not_match_expected_value() { + let graph_data = create_graph_data(vec![create_key_value_data("cpu", "mode", Some("user"))]); + let processed_data = + create_processed_data("test_data", vec![("run1", AperfData::Graph(graph_data))]); + + let rule = ProfileMetadataExpectedRule { + rule_name: "test_rule", + group: "cpu", + key: "mode", + expected_value: "kernel", + should_exist: true, + score: Score::Bad.as_f64(), + message: "Test message", + }; + + let mut findings = DataFindings::default(); + rule.analyze( + &mut findings, + &processed_data, + &mut ProcessedDataAccessor::new(), + ); + + assert_eq!(findings.num_runs_with_findings(), 1); + assert!(findings.has_findings_for_run("run1")); +} + +#[test] +fn test_field_missing_should_exist() { + let graph_data = create_graph_data(vec![create_key_value_data("cpu", "mode", None)]); + let processed_data = + create_processed_data("test_data", vec![("run1", AperfData::Graph(graph_data))]); + + let rule = ProfileMetadataExpectedRule { + rule_name: "test_rule", + group: "cpu", + key: "mode", + expected_value: "kernel", + should_exist: true, + score: Score::Bad.as_f64(), + message: "Test message", + }; + + let mut findings = DataFindings::default(); + rule.analyze( + &mut findings, + &processed_data, + &mut ProcessedDataAccessor::new(), + ); + + assert_eq!(findings.num_runs_with_findings(), 1); + assert!(findings.has_findings_for_run("run1")); +} + +#[test] +fn test_regex_pattern_match() { + let graph_data = create_graph_data(vec![create_key_value_data( + "cpu", + "mode", + Some("kernel_mode"), + )]); + let processed_data = + create_processed_data("test_data", vec![("run1", AperfData::Graph(graph_data))]); + + let rule = ProfileMetadataExpectedRule { + rule_name: "test_rule", + group: "cpu", + key: "mode", + expected_value: "kernel.*", + should_exist: true, + score: Score::Good.as_f64(), + message: "Test message", + }; + + let mut findings = DataFindings::default(); + rule.analyze( + &mut findings, + &processed_data, + &mut ProcessedDataAccessor::new(), + ); + + assert_eq!(findings.num_runs_with_findings(), 0); +} + +#[test] +fn test_multiple_runs() { + let graph_data1 = create_graph_data(vec![create_key_value_data("cpu", "mode", Some("kernel"))]); + let graph_data2 = create_graph_data(vec![create_key_value_data("cpu", "mode", Some("user"))]); + let processed_data = create_processed_data( + "test_data", + vec![ + ("run1", AperfData::Graph(graph_data1)), + ("run2", AperfData::Graph(graph_data2)), + ], + ); + + let rule = ProfileMetadataExpectedRule { + rule_name: "test_rule", + group: "cpu", + key: "mode", + expected_value: "kernel", + should_exist: true, + score: Score::Bad.as_f64(), + message: "Test message", + }; + + let mut findings = DataFindings::default(); + rule.analyze( + &mut findings, + &processed_data, + &mut ProcessedDataAccessor::new(), + ); + + assert_eq!(findings.num_runs_with_findings(), 1); + assert!(!findings.has_findings_for_run("run1")); + assert!(findings.has_findings_for_run("run2")); +} diff --git a/tests/analytics/test_profile_stack_frame_threshold_rule.rs b/tests/analytics/test_profile_stack_frame_threshold_rule.rs new file mode 100644 index 00000000..0029f9e3 --- /dev/null +++ b/tests/analytics/test_profile_stack_frame_threshold_rule.rs @@ -0,0 +1,173 @@ +use aperf::analytics::profile_stack_frame_threshold_rule::ProfileStackFrameThresholdRule; +use aperf::analytics::{Analyze, DataFindings, Score}; +use aperf::data::common::data_formats::{AperfData, GraphData, ProfilerData}; +use aperf::data::common::processed_data_accessor::ProcessedDataAccessor; +use aperf::profiling::ThreadState; +use std::collections::HashMap; + +use super::test_helpers::{create_processed_data, DataFindingsExt}; + +/// Stacks: +/// frame1;frame2 100 +/// frame1;frame2;frame3 110 +/// frame4;frame5;frame6 75 +/// frame1;frame7 90 +fn create_profiler_data(group_name: &str) -> ProfilerData { + let mut pd = ProfilerData::new(0, 100); + let ts = ThreadState::from_str("STATE_DEFAULT"); + pd.insert_stack( + group_name, + 0, + ts, + &["frame1", "frame2"].map(String::from), + 100, + ); + pd.insert_stack( + group_name, + 0, + ts, + &["frame1", "frame2", "frame3"].map(String::from), + 110, + ); + pd.insert_stack( + group_name, + 0, + ts, + &["frame4", "frame5", "frame6"].map(String::from), + 75, + ); + pd.insert_stack( + group_name, + 0, + ts, + &["frame1", "frame7"].map(String::from), + 90, + ); + pd +} + +fn create_graph_data(group_name: &str) -> GraphData { + let mut profiler_data_map = HashMap::new(); + profiler_data_map.insert("profile_0".to_string(), create_profiler_data(group_name)); + GraphData { + graph_groups: vec![], + profiler_data_map, + } +} + +#[test] +fn test_below_threshold() { + let graph_data = create_graph_data("cpu"); + let processed_data = + create_processed_data("test_data", vec![("run1", AperfData::Graph(graph_data))]); + + let rule = ProfileStackFrameThresholdRule { + rule_name: "test_rule", + graph_group: "cpu", + stack_frame: &[&["frame5"]], + frame_type: None, + thread_states: &[], + aggregate_occurences: false, + total_samples: true, + threshold: 60.0, + score: Score::Bad.as_f64(), + message: "Test message", + }; + + let mut findings = DataFindings::default(); + rule.analyze( + &mut findings, + &processed_data, + &mut ProcessedDataAccessor::new(), + ); + assert_eq!(findings.num_runs_with_findings(), 0); +} + +#[test] +fn test_above_threshold() { + let graph_data = create_graph_data("cpu"); + let processed_data = + create_processed_data("test_data", vec![("run1", AperfData::Graph(graph_data))]); + + let rule = ProfileStackFrameThresholdRule { + rule_name: "test_rule", + graph_group: "cpu", + stack_frame: &[&["frame1"]], + frame_type: None, + thread_states: &[], + aggregate_occurences: false, + total_samples: true, + threshold: 50.0, + score: Score::Bad.as_f64(), + message: "Test message", + }; + + let mut findings = DataFindings::default(); + rule.analyze( + &mut findings, + &processed_data, + &mut ProcessedDataAccessor::new(), + ); + assert_eq!(findings.num_runs_with_findings(), 1); + assert!(findings.has_findings_for_run("run1")); +} + +#[test] +fn test_stack_pattern() { + let graph_data = create_graph_data("cpu"); + let processed_data = + create_processed_data("test_data", vec![("run1", AperfData::Graph(graph_data))]); + + let rule = ProfileStackFrameThresholdRule { + rule_name: "test_rule", + graph_group: "cpu", + stack_frame: &[&["frame1", "frame2", "frame3"]], + frame_type: None, + thread_states: &[], + aggregate_occurences: false, + total_samples: true, + threshold: 25.0, + score: Score::Bad.as_f64(), + message: "Test message", + }; + + let mut findings = DataFindings::default(); + rule.analyze( + &mut findings, + &processed_data, + &mut ProcessedDataAccessor::new(), + ); + assert_eq!(findings.num_runs_with_findings(), 1); + assert!(findings.has_findings_for_run("run1")); +} + +#[test] +fn test_missing_metric() { + let graph_data = GraphData { + graph_groups: vec![], + profiler_data_map: HashMap::new(), + }; + let processed_data = + create_processed_data("test_data", vec![("run1", AperfData::Graph(graph_data))]); + + let rule = ProfileStackFrameThresholdRule { + rule_name: "test_rule", + graph_group: "alloc", + stack_frame: &[&["frame1"]], + frame_type: None, + thread_states: &[], + aggregate_occurences: false, + total_samples: true, + threshold: 10.0, + score: Score::Bad.as_f64(), + message: "Test message", + }; + + let mut findings = DataFindings::default(); + rule.analyze( + &mut findings, + &processed_data, + &mut ProcessedDataAccessor::new(), + ); + assert_eq!(findings.num_runs_with_findings(), 0); +} diff --git a/tests/jfr_compare.rs b/tests/jfr_compare.rs new file mode 100644 index 00000000..ba0c750e --- /dev/null +++ b/tests/jfr_compare.rs @@ -0,0 +1,123 @@ +use aperf::profiling::jfr::format_jfr; +use std::collections::HashMap; +use std::fs; +use std::path::Path; +use std::process::Command; + +const JFR_EVENTS: &str = "jdk.ExecutionSample,jdk.NativeMethodSample,profiler.WallClockSample,jdk.MethodTrace,jdk.ObjectAllocationInNewTLAB,jdk.ObjectAllocationOutsideTLAB,jdk.ObjectAllocationSample,profiler.LiveObject,jdk.JavaMonitorEnter,jdk.ThreadPark,profiler.Malloc,profiler.Free,jdk.CPUTimeSample,profiler.NativeLock"; + +fn parse_events(output: &str) -> HashMap { + let text = if let Some(pos) = output.find("\n---\n") { + &output[pos + 5..] + } else { + output + }; + + let mut events: HashMap = HashMap::new(); + let mut current = Vec::new(); + + for line in text.lines() { + if line.trim().is_empty() && !current.is_empty() { + let event = current.join("\n").trim().to_string(); + if !event.is_empty() { + *events.entry(event).or_default() += 1; + } + current.clear(); + } else { + current.push(line); + } + } + if !current.is_empty() { + let event = current.join("\n").trim().to_string(); + if !event.is_empty() { + *events.entry(event).or_default() += 1; + } + } + events +} + +fn run_jfr_print(jfr_path: &Path) -> String { + let output = Command::new("jfr") + .args(["print", "--stack-depth", "999", "--events", JFR_EVENTS]) + .arg(jfr_path) + .output() + .expect("failed to run jfr"); + assert!( + output.status.success(), + "jfr print failed: {}", + String::from_utf8_lossy(&output.stderr) + ); + String::from_utf8(output.stdout).expect("jfr output not utf8") +} + +#[cfg(target_os = "linux")] +#[test] +fn compare_jfr_outputs() { + let fixtures = Path::new(env!("CARGO_MANIFEST_DIR")).join("tests/jfr_fixtures"); + let mut tested = 0; + + for entry in std::fs::read_dir(&fixtures).expect("cannot read jfr_fixtures dir") { + let path = entry.unwrap().path(); + if path.extension().and_then(|e| e.to_str()) != Some("jfr") { + continue; + } + + let name = path.file_name().unwrap().to_string_lossy(); + println!("Testing: {}", name); + + let gt_raw = run_jfr_print(&path); + let ours_raw = format_jfr(&path).expect("format_jfr failed"); + + let ground_truth = parse_events(>_raw); + let ours = parse_events(&ours_raw); + + let gt_total: usize = ground_truth.values().sum(); + let our_total: usize = ours.values().sum(); + + let mut only_gt = Vec::new(); + let mut only_ours = Vec::new(); + + for (event, &count) in &ground_truth { + let ours_count = ours.get(event).copied().unwrap_or(0); + if count > ours_count { + only_gt.push((count - ours_count, &event[..event.len().min(120)])); + } + } + for (event, &count) in &ours { + let gt_count = ground_truth.get(event).copied().unwrap_or(0); + if count > gt_count { + only_ours.push((count - gt_count, &event[..event.len().min(120)])); + } + } + + if !only_gt.is_empty() || !only_ours.is_empty() { + let dump_dir = Path::new("/tmp/aperf_java_testing"); + fs::create_dir_all(dump_dir).ok(); + let stem = path.file_stem().unwrap().to_string_lossy(); + fs::write(dump_dir.join(format!("{}_ground_truth.out", stem)), >_raw).ok(); + fs::write(dump_dir.join(format!("{}_ours.out", stem)), &ours_raw).ok(); + + let mut msg = + format!("MISMATCH in {name} (ground_truth: {gt_total}, ours: {our_total})\n"); + msg.push_str(&format!(" Outputs saved to {}\n", dump_dir.display())); + for (count, preview) in &only_gt { + msg.push_str(&format!( + " only in ground_truth [{count}x]: {}...\n", + preview.replace('\n', " | ") + )); + } + for (count, preview) in &only_ours { + msg.push_str(&format!( + " only in ours [{count}x]: {}...\n", + preview.replace('\n', " | ") + )); + } + panic!("{}", msg); + } + + println!(" PASS ({} events)", gt_total); + tested += 1; + } + + assert!(tested > 0, "No .jfr files found in {}", fixtures.display()); +} diff --git a/tests/jfr_fixtures/test_0.jfr b/tests/jfr_fixtures/test_0.jfr new file mode 100644 index 00000000..c4df7452 Binary files /dev/null and b/tests/jfr_fixtures/test_0.jfr differ