Adds a couple functions for calculating time between two points. These
are used to profile the time spent on each hook when the PM_PROFILE
variable is "true".
Signed-off-by: Dan Nicholson <[EMAIL PROTECTED]>
---
Feel free to adapt this to your preference.
pm/pm-functions.in | 25 ++++++++++++++++++++++++-
src/pm-action.in | 12 ++++++++++++
2 files changed, 36 insertions(+), 1 deletions(-)
diff --git a/pm/pm-functions.in b/pm/pm-functions.in
index f5cc400..142f8b3 100644
--- a/pm/pm-functions.in
+++ b/pm/pm-functions.in
@@ -44,6 +44,7 @@ DROP_PARAMETERS=""
PARAMETERS="${STORAGEDIR}/parameters"
INHIBIT="${STORAGEDIR}/inhibit"
PM_CMDLINE="$*"
+PM_PROFILE=""
BEFORE_HOOKS=""
MODULE_HELP=""
SUSPEND_MODULE=""
@@ -95,6 +96,19 @@ log()
printf "$fmt" "$*"
}
+# Get the current time for profiling.
+get_current_time()
+{
+ date '+%s.%N'
+}
+
+# Get time spent between two points.
+get_time_spent()
+{
+ [ -z "$1" ] || [ -z "$2" ] && return 1
+ perl -e "printf \"%.3f\n\", $2 - $1"
+}
+
add_before_hooks() {
[ -z "$BEFORE_HOOKS" ] && BEFORE_HOOKS="$*" || \
BEFORE_HOOKS="$BEFORE_HOOKS $*"
@@ -184,6 +198,8 @@ run_hooks() {
local sort="sort"
local base
local hook
+ local status
+ local t1 t2 time
local oifs="${IFS}"
# the next two lines are not a typo or a formatting error!
local nifs="
@@ -208,10 +224,17 @@ run_hooks() {
hook="$phooks/$base"
fi
log -n "${hook} $2: "
+ [ "$PM_PROFILE" = true ] && t1=$(get_current_time)
hook_ok "$hook" && "${hook}" $2
+ status=$?
+ [ "$PM_PROFILE" = true ] && {
+ t2=$(get_current_time)
+ time=$(get_time_spent "$t1" "$t2")
+ }
# if the hook exited with an unknown exit code inhibit,
# otherwise record this as the last hook that ran.
- hook_exit_status $? && LAST_HOOK="$base" || inhibit
+ hook_exit_status $status && LAST_HOOK="$base" || inhibit
+ [ "$PM_PROFILE" = true ] && log "$hook $2: $time sec"
IFS="${nifs}"
done
IFS="${oifs}"
diff --git a/src/pm-action.in b/src/pm-action.in
index 88bdb4e..dd71a67 100755
--- a/src/pm-action.in
+++ b/src/pm-action.in
@@ -93,7 +93,13 @@ load_hook_parameters
# run the sleep hooks
log "$(date): Running hooks for $ACTION."
+[ "$PM_PROFILE" = true ] && t1=$(get_current_time)
if run_hooks sleep "$ACTION $METHOD"; then
+ [ "$PM_PROFILE" = true ] && {
+ t2=$(get_current_time)
+ time=$(get_time_spent "$t1" "$t2")
+ log "Time for $ACTION hooks: $time sec"
+ }
# Sleep only if we know how and if a hook did not inhibit us.
log "$(date): performing $METHOD"
sync
@@ -103,8 +109,14 @@ else
log "$(date): Inhibit found, will not perform $METHOD"
fi
log "$(date): Running hooks for $REVERSE"
+[ "$PM_PROFILE" = true ] && t1=$(get_current_time)
# run the sleep hooks in reverse with the wakeup action
if run_hooks sleep "$REVERSE $METHOD" reverse; then
+ [ "$PM_PROFILE" = true ] && {
+ t2=$(get_current_time)
+ time=$(get_time_spent "$t1" "$t2")
+ log "Time for $REVERSE hooks: $time sec"
+ }
log "$(date): Finished."
else
exit 1
--
1.5.6.5
_______________________________________________
Pm-utils mailing list
[email protected]
http://lists.freedesktop.org/mailman/listinfo/pm-utils
