Merge branch 'pm-sleep'

* pm-sleep:
  PM / Sleep: new trace event to print device suspend and resume times
  PM / Sleep: increase ftrace coverage in suspend/resume
This commit is contained in:
Rafael J. Wysocki 2013-08-27 01:41:47 +02:00
commit e894245c78
3 changed files with 82 additions and 36 deletions

View File

@ -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 pm_message_t pm_transition;
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 ktime_t initcall_debug_start(struct device *dev)
}
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 @@ static pm_callback_t pm_noirq_op(const struct dev_pm_ops *ops, pm_message_t stat
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 @@ static int dpm_run_callback(pm_callback_t cb, struct device *dev,
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 @@ EXPORT_SYMBOL_GPL(dpm_suspend_end);
* @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 @@ static int legacy_suspend(struct device *dev, pm_message_t state,
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 @@ static int __device_suspend(struct device *dev, pm_message_t state, bool async)
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 @@ static int __device_suspend(struct device *dev, pm_message_t state, bool async)
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;
}
}

View File

@ -66,6 +66,43 @@ TRACE_EVENT(machine_suspend,
TP_printk("state=%lu", (unsigned long)__entry->state)
);
TRACE_EVENT(device_pm_report_time,
TP_PROTO(struct device *dev, const char *pm_ops, s64 ops_time,
char *pm_event_str, int error),
TP_ARGS(dev, pm_ops, ops_time, pm_event_str, error),
TP_STRUCT__entry(
__string(device, dev_name(dev))
__string(driver, dev_driver_string(dev))
__string(parent, dev->parent ? dev_name(dev->parent) : "none")
__string(pm_ops, pm_ops ? pm_ops : "none ")
__string(pm_event_str, pm_event_str)
__field(s64, ops_time)
__field(int, error)
),
TP_fast_assign(
const char *tmp = dev->parent ? dev_name(dev->parent) : "none";
const char *tmp_i = pm_ops ? pm_ops : "none ";
__assign_str(device, dev_name(dev));
__assign_str(driver, dev_driver_string(dev));
__assign_str(parent, tmp);
__assign_str(pm_ops, tmp_i);
__assign_str(pm_event_str, pm_event_str);
__entry->ops_time = ops_time;
__entry->error = error;
),
/* ops_str has an extra space at the end */
TP_printk("%s %s parent=%s state=%s ops=%snsecs=%lld err=%d",
__get_str(driver), __get_str(device), __get_str(parent),
__get_str(pm_event_str), __get_str(pm_ops),
__entry->ops_time, __entry->error)
);
DECLARE_EVENT_CLASS(wakeup_source,
TP_PROTO(const char *name, unsigned int state),

View File

@ -210,6 +210,7 @@ static int suspend_enter(suspend_state_t state, bool *wakeup)
goto Platform_wake;
}
ftrace_stop();
error = disable_nonboot_cpus();
if (error || suspend_test(TEST_CPUS))
goto Enable_cpus;
@ -232,6 +233,7 @@ static int suspend_enter(suspend_state_t state, bool *wakeup)
Enable_cpus:
enable_nonboot_cpus();
ftrace_start();
Platform_wake:
if (need_suspend_ops(state) && suspend_ops->wake)
@ -265,7 +267,6 @@ int suspend_devices_and_enter(suspend_state_t state)
goto Close;
}
suspend_console();
ftrace_stop();
suspend_test_start();
error = dpm_suspend_start(PMSG_SUSPEND);
if (error) {
@ -285,7 +286,6 @@ int suspend_devices_and_enter(suspend_state_t state)
suspend_test_start();
dpm_resume_end(PMSG_RESUME);
suspend_test_finish("resume devices");
ftrace_start();
resume_console();
Close:
if (need_suspend_ops(state) && suspend_ops->end)