Skip to content

add event time column to summarize results #109

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 1 commit into from
Jan 15, 2020
Merged

add event time column to summarize results #109

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
6 changes: 6 additions & 0 deletions summarize/src/analysis.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -194,6 +194,7 @@ pub fn perform_analysis(data: ProfilingData) -> Results {
QUERY_EVENT_KIND | GENERIC_ACTIVITY_EVENT_KIND => {
record_event_data(&current_event.label, &|data| {
data.self_time += current_event_duration;
data.time += current_event_duration;
data.number_of_cache_misses += 1;
data.invocation_count += 1;
});
Expand All @@ -202,13 +203,15 @@ pub fn perform_analysis(data: ProfilingData) -> Results {
QUERY_BLOCKED_EVENT_KIND => {
record_event_data(&current_event.label, &|data| {
data.self_time += current_event_duration;
data.time += current_event_duration;
data.blocked_time += current_event_duration;
});
}

INCREMENTAL_LOAD_RESULT_EVENT_KIND => {
record_event_data(&current_event.label, &|data| {
data.self_time += current_event_duration;
data.time += current_event_duration;
data.incremental_load_time += current_event_duration;
});
}
Expand Down Expand Up @@ -493,6 +496,7 @@ mod tests {

assert_eq!(results.query_data_by_label("e1").self_time, Duration::from_nanos(100));
assert_eq!(results.query_data_by_label("e1").invocation_count, 3);
assert_eq!(results.query_data_by_label("e1").time, Duration::from_nanos(180));
}

#[test]
Expand All @@ -514,6 +518,7 @@ mod tests {

assert_eq!(results.query_data_by_label("q1").self_time, Duration::from_nanos(230));
assert_eq!(results.query_data_by_label("q1").blocked_time, Duration::from_nanos(130));
assert_eq!(results.query_data_by_label("q1").time, Duration::from_nanos(230));
}

#[test]
Expand All @@ -535,5 +540,6 @@ mod tests {

assert_eq!(results.query_data_by_label("q1").self_time, Duration::from_nanos(230));
assert_eq!(results.query_data_by_label("q1").incremental_load_time, Duration::from_nanos(230));
assert_eq!(results.query_data_by_label("q1").time, Duration::from_nanos(230));
}
}
6 changes: 6 additions & 0 deletions summarize/src/main.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -89,6 +89,8 @@ fn diff(opt: DiffOpt) -> Result<(), Box<dyn Error>> {
"Item",
"Self Time",
"Self Time Change",
"Time",
"Time Change",
"Item count",
"Cache hits",
"Blocked time",
Expand All @@ -105,6 +107,8 @@ fn diff(opt: DiffOpt) -> Result<(), Box<dyn Error>> {
query_data.label,
format!("{:.2?}", query_data.self_time),
format!("{:+.2}%", query_data.self_time_change),
format!("{:.2?}", query_data.time),
format!("{:+.2}%", query_data.time_change),
format!("{:+}", query_data.invocation_count),
format!("{:+}", query_data.number_of_cache_hits),
format!("{:.2?}", query_data.blocked_time),
Expand Down Expand Up @@ -151,6 +155,7 @@ fn summarize(opt: SummarizeOpt) -> Result<(), Box<dyn Error>> {
"Item",
"Self time",
"% of total time",
"Time",
"Item count",
"Cache hits",
"Blocked time",
Expand All @@ -172,6 +177,7 @@ fn summarize(opt: SummarizeOpt) -> Result<(), Box<dyn Error>> {
query_data.label,
format!("{:.2?}", query_data.self_time),
format!("{:.3}", curr_percent),
format!("{:.2?}", query_data.time),
format!("{}", query_data.invocation_count),
format!("{}", query_data.number_of_cache_hits),
format!("{:.2?}", query_data.blocked_time),
Expand Down
14 changes: 12 additions & 2 deletions summarize/src/query_data.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,7 @@ use std::time::Duration;
#[derive(Serialize, Deserialize, Clone, Debug)]
pub struct QueryData {
pub label: String,
pub time: Duration,
pub self_time: Duration,
pub number_of_cache_misses: usize,
pub number_of_cache_hits: usize,
Expand All @@ -18,6 +19,7 @@ impl QueryData {
pub fn new(label: String) -> QueryData {
QueryData {
label,
time: Duration::from_nanos(0),
self_time: Duration::from_nanos(0),
number_of_cache_misses: 0,
number_of_cache_hits: 0,
Expand All @@ -37,6 +39,8 @@ impl QueryData {

QueryDataDiff {
label: self.label.clone(),
time: invert(self.time),
time_change: -100.0,
self_time: invert(self.self_time),
self_time_change: -100.0,
number_of_cache_misses: -(self.number_of_cache_misses as i64),
Expand All @@ -50,6 +54,8 @@ impl QueryData {
pub fn as_query_data_diff(&self) -> QueryDataDiff {
QueryDataDiff {
label: self.label.clone(),
time: self.time.into(),
time_change: std::f64::INFINITY,
self_time: self.self_time.into(),
self_time_change: std::f64::INFINITY,
number_of_cache_misses: self.number_of_cache_misses as i64,
Expand All @@ -64,6 +70,8 @@ impl QueryData {
#[derive(Serialize, Deserialize)]
pub struct QueryDataDiff {
pub label: String,
pub time: SignedDuration,
pub time_change: f64,
pub self_time: SignedDuration,
pub self_time_change: f64,
pub number_of_cache_misses: i64,
Expand All @@ -89,6 +97,8 @@ impl Sub for QueryData {

QueryDataDiff {
label: self.label,
time: sd(self.time) - sd(rhs.time),
time_change: percentage_change(rhs.time, self.time),
self_time: sd(self.self_time) - sd(rhs.self_time),
self_time_change: percentage_change(rhs.self_time, self.self_time),
number_of_cache_misses: i(self.number_of_cache_misses) - i(rhs.number_of_cache_misses),
Expand All @@ -101,8 +111,8 @@ impl Sub for QueryData {
}

fn percentage_change(base: Duration, change: Duration) -> f64 {
let self_time_nanos = change.as_nanos() as i128 - base.as_nanos() as i128;
self_time_nanos as f64 / base.as_nanos() as f64 * 100.0
let nanos = change.as_nanos() as i128 - base.as_nanos() as i128;
nanos as f64 / base.as_nanos() as f64 * 100.0
}

#[derive(Serialize, Deserialize)]
Expand Down