power: send_metrics_on_resume: fix for veyron
None of the messages for the start of resume or the end of suspend show up on
veyron, so this adds one for that. It also simplifies the code for finding the
start time of resume and the end time of suspend since these are assumed to be
the same.
BUG=chrome-os-partner:35862
TEST=run power_Resume on jerry and sanity check results
Change-Id: Ibc2227e091293811513d2a35e8ecd73eb3a3958c
Reviewed-on: https://chromium-review.googlesource.com/261040
Reviewed-by: Dan Erat <derat@chromium.org>
Commit-Queue: Derek Basehore <dbasehore@chromium.org>
Tested-by: Derek Basehore <dbasehore@chromium.org>
diff --git a/power_manager/tools/send_metrics_on_resume b/power_manager/tools/send_metrics_on_resume
index 4730f53..9105d87 100755
--- a/power_manager/tools/send_metrics_on_resume
+++ b/power_manager/tools/send_metrics_on_resume
@@ -163,23 +163,9 @@
get_timestamp "${1}" "Freezing user space"
}
-# Find a message related to the end of suspend and parse out its
-# timestamp. Since there are multiple possible messages, this function searches
-# for each one in order. It returns the time stamp of the message it found or
-# nothing.
-# Arguments:
-# $1 - Path to messages for most recent resume onward.
-get_end_suspend_time() {
- [ -n "${1}" ] || return
- get_timestamp "${1}" \
- "Back to C!" \
- "Low-level resume complete" \
- "Entering suspend state" \
- "sleep: irq wakeup masks:"
-}
-
-# Find a message related to the start of resume and parse out its timestamp. It
-# returns the time stamp of the message it found or nothing.
+# Find the message related to the start of resume/end of suspend and parse its
+# timestamp. The start of resume and the end of suspend are assumed to be the
+# same thing.
# Arguments:
# $1 - Path to messages for most recent resume onward.
get_start_resume_time() {
@@ -187,9 +173,12 @@
get_timestamp "${1}" \
"Back to C!" \
"Low-level resume complete" \
+ "Entering suspend state" \
+ "sleep: irq wakeup masks:" \
"Suspended for", \
"Resume caused by" \
- "post sleep, preparing to return"
+ "post sleep, preparing to return" \
+ "Enabling non-boot CPUs ..."
}
# Find a message related to the end of resume and parse out its timestamp. It
@@ -231,26 +220,26 @@
# Greps the timestamps.
local start_suspend_time=$(get_start_suspend_time "$recent_messages")
- local end_suspend_time=$(get_end_suspend_time "$recent_messages")
local start_resume_time=$(get_start_resume_time "$recent_messages")
local end_resume_time=$(get_end_resume_time "$recent_messages")
local cpu_ready_time=$(get_cpu_ready_time "$recent_messages")
log_metric start_suspend_time $start_suspend_time
- log_metric end_suspend_time $end_suspend_time
+ # end_suspend_time and start_resume_time are the same value.
+ log_metric end_suspend_time $start_resume_time
log_metric start_resume_time $start_resume_time
log_metric end_resume_time $end_resume_time
log_metric cpu_ready_time $cpu_ready_time
[ -z "$start_suspend_time" ] && log_msg "Unable to get start_suspend_time"
- [ -z "$end_suspend_time" ] && log_msg "Unable to get end_suspend_time"
+ [ -z "$start_resume_time" ] && log_msg "Unable to get start_resume_time"
[ -z "$end_resume_time" ] && log_msg "Unable to get end_resume_time"
# Calculates the time intervals in milliseconds.
- [ -n "$start_suspend_time" ] && [ -n "$end_suspend_time" ] &&
- local kernel_suspend_time=$(echo $start_suspend_time $end_suspend_time |
+ [ -n "$start_suspend_time" ] && [ -n "$start_resume_time" ] &&
+ local kernel_suspend_time=$(echo $start_suspend_time $start_resume_time |
/usr/bin/awk '{ if (NF == 2 && $1 < $2) print int(($2 - $1) * 1000) }')
- [ -n "$end_suspend_time" ] && [ -n "$end_resume_time" ] &&
- local kernel_resume_time=$(echo $end_suspend_time $end_resume_time |
+ [ -n "$start_resume_time" ] && [ -n "$end_resume_time" ] &&
+ local kernel_resume_time=$(echo $start_resume_time $end_resume_time |
/usr/bin/awk '{ if (NF == 2 && $1 < $2) print int(($2 - $1) * 1000) }')
local firmware_resume_time=$(calculate_firmware_resume_time)
