@@ -29,6 +29,13 @@
#include "../base.h"
#include "power.h"
+/* Set default to 100 msecs */
+#ifdef CONFIG_SR_REPORT_TIME_LIMIT
+#define SR_REPORT_TIME_LIMIT CONFIG_SR_REPORT_TIME_LIMIT
+#else
+#define SR_REPORT_TIME_LIMIT 100
+#endif
+
/*
* The entries in the dpm_list list are in a depth first order, simply
* because children are guaranteed to be discovered after parents, and
@@ -324,7 +331,7 @@ static void pm_dev_err(struct device *dev, pm_message_t state, char *info,
kobject_name(&dev->kobj), pm_verb(state.event), info, error);
}
-static void dpm_show_time(ktime_t starttime, pm_message_t state, char *info)
+static void device_show_time(struct device *dev, ktime_t starttime, pm_message_t state, char *info)
{
ktime_t calltime;
s64 usecs64;
@@ -336,9 +343,10 @@ static void dpm_show_time(ktime_t starttime, pm_message_t state, char *info)
usecs = usecs64;
if (usecs == 0)
usecs = 1;
- pr_info("PM: %s%s%s of devices complete after %ld.%03ld msecs\n",
- info ?: "", info ? " " : "", pm_verb(state.event),
- usecs / USEC_PER_MSEC, usecs % USEC_PER_MSEC);
+ if ((usecs / USEC_PER_MSEC) > SR_REPORT_TIME_LIMIT)
+ pr_info("PM: %s%s%s of drv:%s dev:%s complete after %ld.%03ld msecs\n", info ?: "", info ? " " : "", pm_verb(state.event),
+ dev_driver_string(dev), dev_name(dev), usecs / USEC_PER_MSEC,
+ usecs % USEC_PER_MSEC);
}
/*------------------------- Resume routines -------------------------*/
@@ -354,6 +362,7 @@ static void dpm_show_time(ktime_t starttime, pm_message_t state, char *info)
static int device_resume_noirq(struct device *dev, pm_message_t state)
{
int error = 0;
+ ktime_t starttime = ktime_get();
TRACE_DEVICE(dev);
TRACE_RESUME(0);
@@ -364,6 +373,7 @@ static int device_resume_noirq(struct device *dev, pm_message_t state)
if (dev->bus->pm) {
pm_dev_dbg(dev, state, "EARLY ");
error = pm_noirq_op(dev, dev->bus->pm, state);
+ device_show_time(dev, starttime, state, "early");
}
End:
TRACE_RESUME(error);
@@ -380,7 +390,6 @@ static int device_resume_noirq(struct device *dev, pm_message_t state)
void dpm_resume_noirq(pm_message_t state)
{
struct device *dev;
- ktime_t starttime = ktime_get();
mutex_lock(&dpm_list_mtx);
transition_started = false;
@@ -394,7 +403,6 @@ void dpm_resume_noirq(pm_message_t state)
pm_dev_err(dev, state, " early", error);
}
mutex_unlock(&dpm_list_mtx);
- dpm_show_time(starttime, state, "early");
resume_device_irqs();
}
EXPORT_SYMBOL_GPL(dpm_resume_noirq);
@@ -407,6 +415,7 @@ EXPORT_SYMBOL_GPL(dpm_resume_noirq);
static int device_resume(struct device *dev, pm_message_t state)
{
int error = 0;
+ ktime_t starttime = ktime_get();
TRACE_DEVICE(dev);
TRACE_RESUME(0);
@@ -443,6 +452,7 @@ static int device_resume(struct device *dev, pm_message_t state)
error = dev->class->resume(dev);
}
}
+ device_show_time(dev, starttime, state, NULL);
End:
up(&dev->sem);
@@ -460,7 +470,6 @@ static int device_resume(struct device *dev, pm_message_t state)
static void dpm_resume(pm_message_t state)
{
struct list_head list;
- ktime_t starttime = ktime_get();
INIT_LIST_HEAD(&list);
mutex_lock(&dpm_list_mtx);
@@ -489,7 +498,6 @@ static void dpm_resume(pm_message_t state)
}
list_splice(&list, &dpm_list);
mutex_unlock(&dpm_list_mtx);
- dpm_show_time(starttime, state, NULL);
}
/**
@@ -604,6 +612,7 @@ static pm_message_t resume_event(pm_message_t sleep_state)
static int device_suspend_noirq(struct device *dev, pm_message_t state)
{
int error = 0;
+ ktime_t starttime = ktime_get();
if (!dev->bus)
return 0;
@@ -611,6 +620,7 @@ static int device_suspend_noirq(struct device *dev, pm_message_t state)
if (dev->bus->pm) {
pm_dev_dbg(dev, state, "LATE ");
error = pm_noirq_op(dev, dev->bus->pm, state);
+ device_show_time(dev, starttime, state, "late");
}
return error;
}
@@ -625,7 +635,6 @@ static int device_suspend_noirq(struct device *dev, pm_message_t state)
int dpm_suspend_noirq(pm_message_t state)
{
struct device *dev;
- ktime_t starttime = ktime_get();
int error = 0;
suspend_device_irqs();
@@ -641,8 +650,6 @@ int dpm_suspend_noirq(pm_message_t state)
mutex_unlock(&dpm_list_mtx);
if (error)
dpm_resume_noirq(resume_event(state));
- else
- dpm_show_time(starttime, state, "late");
return error;
}
EXPORT_SYMBOL_GPL(dpm_suspend_noirq);
@@ -655,6 +662,7 @@ EXPORT_SYMBOL_GPL(dpm_suspend_noirq);
static int device_suspend(struct device *dev, pm_message_t state)
{
int error = 0;
+ ktime_t starttime = ktime_get();
down(&dev->sem);
@@ -690,6 +698,7 @@ static int device_suspend(struct device *dev, pm_message_t state)
suspend_report_result(dev->bus->suspend, error);
}
}
+ device_show_time(dev, starttime, state, NULL);
End:
up(&dev->sem);
@@ -703,7 +712,6 @@ static int device_suspend(struct device *dev, pm_message_t state)
static int dpm_suspend(pm_message_t state)
{
struct list_head list;
- ktime_t starttime = ktime_get();
int error = 0;
INIT_LIST_HEAD(&list);
@@ -729,8 +737,6 @@ static int dpm_suspend(pm_message_t state)
}
list_splice(&list, dpm_list.prev);
mutex_unlock(&dpm_list_mtx);
- if (!error)
- dpm_show_time(starttime, state, NULL);
return error;
}
--
1.6.3.3
From 80ccbc89958661041ec09e13193c1a7cfe53d1f3 Mon Sep 17 00:00:00 2001
From: Rafael J. Wysocki <rjw@sisk.pl>
Date: Fri, 18 Dec 2009 01:57:47 +0100
Subject: [PATCH 1/2] PM: Measure device suspend and resume times
Measure and print the time of suspending and resuming all devices.
Signed-off-by: Rafael J. Wysocki <rjw@sisk.pl>
(cherry picked from commit ecf762b2581e12ac761d12a6e4e297c2224aa899)
Signed-off-by: Manoj Iyer <manoj.iyer@canonical.com>
---
drivers/base/power/main.c | 27 +++++++++++++++++++++++++++
1 files changed, 27 insertions(+), 0 deletions(-)
@@ -324,6 +324,23 @@ static void pm_dev_err(struct device *dev, pm_message_t state, char *info,
kobject_name(&dev->kobj), pm_verb(state.event), info, error);
}
+static void dpm_show_time(ktime_t starttime, pm_message_t state, char *info)
+{
+ ktime_t calltime;
+ s64 usecs64;
+ int usecs;
+
+ calltime = ktime_get();
+ usecs64 = ktime_to_ns(ktime_sub(calltime, starttime));
+ do_div(usecs64, NSEC_PER_USEC);
+ usecs = usecs64;
+ if (usecs == 0)
+ usecs = 1;
+ pr_info("PM: %s%s%s of devices complete after %ld.%03ld msecs\n",
+ info ?: "", info ? " " : "", pm_verb(state.event),
+ usecs / USEC_PER_MSEC, usecs % USEC_PER_MSEC);
+}
+
/*------------------------- Resume routines -------------------------*/
/**
@@ -363,6 +380,7 @@ static int device_resume_noirq(struct device *dev, pm_message_t state)
void dpm_resume_noirq(pm_message_t state)
{
struct device *dev;
+ ktime_t starttime = ktime_get();
mutex_lock(&dpm_list_mtx);
transition_started = false;
@@ -376,6 +394,7 @@ void dpm_resume_noirq(pm_message_t state)
pm_dev_err(dev, state, " early", error);
}
mutex_unlock(&dpm_list_mtx);
+ dpm_show_time(starttime, state, "early");
resume_device_irqs();
}
EXPORT_SYMBOL_GPL(dpm_resume_noirq);
@@ -441,6 +460,7 @@ static int device_resume(struct device *dev, pm_message_t state)
static void dpm_resume(pm_message_t state)
{
struct list_head list;
+ ktime_t starttime = ktime_get();
INIT_LIST_HEAD(&list);
mutex_lock(&dpm_list_mtx);
@@ -469,6 +489,7 @@ static void dpm_resume(pm_message_t state)
}
list_splice(&list, &dpm_list);
mutex_unlock(&dpm_list_mtx);
+ dpm_show_time(starttime, state, NULL);
}
/**
@@ -604,6 +625,7 @@ static int device_suspend_noirq(struct device *dev, pm_message_t state)
int dpm_suspend_noirq(pm_message_t state)
{
struct device *dev;
+ ktime_t starttime = ktime_get();
int error = 0;
suspend_device_irqs();
@@ -619,6 +641,8 @@ int dpm_suspend_noirq(pm_message_t state)
mutex_unlock(&dpm_list_mtx);
if (error)
dpm_resume_noirq(resume_event(state));
+ else
+ dpm_show_time(starttime, state, "late");
return error;
}
EXPORT_SYMBOL_GPL(dpm_suspend_noirq);
@@ -679,6 +703,7 @@ static int device_suspend(struct device *dev, pm_message_t state)
static int dpm_suspend(pm_message_t state)
{
struct list_head list;
+ ktime_t starttime = ktime_get();
int error = 0;
INIT_LIST_HEAD(&list);
@@ -704,6 +729,8 @@ static int dpm_suspend(pm_message_t state)
}
list_splice(&list, dpm_list.prev);
mutex_unlock(&dpm_list_mtx);
+ if (!error)
+ dpm_show_time(starttime, state, NULL);
return error;
}