PM / Sleep: new trace event to print device suspend and resume times
A new trace event is added to PM events to print the time it takes to
suspend and resume a device. It generates trace messages that
include device, driver, parent information in addition to the type of
PM ops invoked as well as the PM event and error status from the PM
ops. Example trace below:
bash-2239 [000] .... 290.883035: device_pm_report_time: backlight
acpi_video0 parent=0000:00:02.0 state=freeze ops=class nsecs=332 err=0
bash-2239 [000] .... 290.883041: device_pm_report_time: rfkill rf
kill3 parent=phy0 state=freeze ops=legacy class nsecs=216 err=0
bash-2239 [001] .... 290.973892: device_pm_report_time: ieee80211
phy0 parent=0000:01:00.0 state=freeze ops=legacy class nsecs=90846477 err=0
bash-2239 [001] .... 293.660129: device_pm_report_time: ieee80211 phy0 parent=0000:01:00.0 state=restore ops=legacy class nsecs=101295162 err=0
bash-2239 [001] .... 293.660147: device_pm_report_time: rfkill rfkill3 parent=phy0 state=restore ops=legacy class nsecs=1804 err=0
bash-2239 [001] .... 293.660157: device_pm_report_time: backlight acpi_video0 parent=0000:00:02.0 state=restore ops=class nsecs=757 err=0
Signed-off-by: Shuah Khan <shuah.kh@samsung.com>
Signed-off-by: Rafael J. Wysocki <rafael.j.wysocki@intel.com>
diff --git a/drivers/base/power/main.c b/drivers/base/power/main.c
index 5a9b656..9f098a8 100644
--- a/drivers/base/power/main.c
+++ b/drivers/base/power/main.c
@@ -28,6 +28,7 @@
#include <linux/sched.h>
#include <linux/async.h>
#include <linux/suspend.h>
+#include <trace/events/power.h>
#include <linux/cpuidle.h>
#include "../base.h"
#include "power.h"
@@ -56,6 +57,30 @@
static int async_error;
+static char *pm_verb(int event)
+{
+ switch (event) {
+ case PM_EVENT_SUSPEND:
+ return "suspend";
+ case PM_EVENT_RESUME:
+ return "resume";
+ case PM_EVENT_FREEZE:
+ return "freeze";
+ case PM_EVENT_QUIESCE:
+ return "quiesce";
+ case PM_EVENT_HIBERNATE:
+ return "hibernate";
+ case PM_EVENT_THAW:
+ return "thaw";
+ case PM_EVENT_RESTORE:
+ return "restore";
+ case PM_EVENT_RECOVER:
+ return "recover";
+ default:
+ return "(unknown PM event)";
+ }
+}
+
/**
* device_pm_sleep_init - Initialize system suspend-related device fields.
* @dev: Device object being initialized.
@@ -172,16 +197,21 @@
}
static void initcall_debug_report(struct device *dev, ktime_t calltime,
- int error)
+ int error, pm_message_t state, char *info)
{
- ktime_t delta, rettime;
+ ktime_t rettime;
+ s64 nsecs;
+
+ rettime = ktime_get();
+ nsecs = (s64) ktime_to_ns(ktime_sub(rettime, calltime));
if (pm_print_times_enabled) {
- rettime = ktime_get();
- delta = ktime_sub(rettime, calltime);
pr_info("call %s+ returned %d after %Ld usecs\n", dev_name(dev),
- error, (unsigned long long)ktime_to_ns(delta) >> 10);
+ error, (unsigned long long)nsecs >> 10);
}
+
+ trace_device_pm_report_time(dev, info, nsecs, pm_verb(state.event),
+ error);
}
/**
@@ -309,30 +339,6 @@
return NULL;
}
-static char *pm_verb(int event)
-{
- switch (event) {
- case PM_EVENT_SUSPEND:
- return "suspend";
- case PM_EVENT_RESUME:
- return "resume";
- case PM_EVENT_FREEZE:
- return "freeze";
- case PM_EVENT_QUIESCE:
- return "quiesce";
- case PM_EVENT_HIBERNATE:
- return "hibernate";
- case PM_EVENT_THAW:
- return "thaw";
- case PM_EVENT_RESTORE:
- return "restore";
- case PM_EVENT_RECOVER:
- return "recover";
- default:
- return "(unknown PM event)";
- }
-}
-
static void pm_dev_dbg(struct device *dev, pm_message_t state, char *info)
{
dev_dbg(dev, "%s%s%s\n", info, pm_verb(state.event),
@@ -379,7 +385,7 @@
error = cb(dev);
suspend_report_result(cb, error);
- initcall_debug_report(dev, calltime, error);
+ initcall_debug_report(dev, calltime, error, state, info);
return error;
}
@@ -1027,7 +1033,8 @@
* @cb: Suspend callback to execute.
*/
static int legacy_suspend(struct device *dev, pm_message_t state,
- int (*cb)(struct device *dev, pm_message_t state))
+ int (*cb)(struct device *dev, pm_message_t state),
+ char *info)
{
int error;
ktime_t calltime;
@@ -1037,7 +1044,7 @@
error = cb(dev, state);
suspend_report_result(cb, error);
- initcall_debug_report(dev, calltime, error);
+ initcall_debug_report(dev, calltime, error, state, info);
return error;
}
@@ -1097,7 +1104,8 @@
goto Run;
} else if (dev->class->suspend) {
pm_dev_dbg(dev, state, "legacy class ");
- error = legacy_suspend(dev, state, dev->class->suspend);
+ error = legacy_suspend(dev, state, dev->class->suspend,
+ "legacy class ");
goto End;
}
}
@@ -1108,7 +1116,8 @@
callback = pm_op(dev->bus->pm, state);
} else if (dev->bus->suspend) {
pm_dev_dbg(dev, state, "legacy bus ");
- error = legacy_suspend(dev, state, dev->bus->suspend);
+ error = legacy_suspend(dev, state, dev->bus->suspend,
+ "legacy bus ");
goto End;
}
}