[LUCID 1/2] UBUNTU: SAUCE: PM report driver and device suspend/resume times.
manoj.iyer at canonical.com
manoj.iyer at canonical.com
Fri Feb 12 16:37:24 UTC 2010
I had sent Rafael's patch earlier to the list, I will follow what amit,
cherry pick Rafael's, and merge my changes in and resend it.
Cheers
--- manjo
On Fri, 12 Feb 2010, Andy Whitcroft wrote:
> On Thu, Feb 11, 2010 at 01:55:35PM -0600, Manoj Iyer wrote:
>>
>> This patch is an extension to a resume report patch submitted to upstream
>> by Rafael J. Wysocki. cnd tested this kernel and reported that it prints
>> information correctly. The messages will be printed if suspend/resume of
>> driver/device took more than 100ms. This default can be changed in CONFIG.
>
> If we require another patch you should send it in here so we have the
> full history. If that patch is full contained in this one then we should
> likely pull that one out in its original form for both attribution and
> to avoid collisions when we rebase up to that version in the future.
>
>> Feb 11 13:23:05 cndougla kernel: [ 59.848676] PM: suspend of drv:sd
>> dev:0:0:0:0 complete after 978.535 msecs
>> Feb 11 13:23:05 cndougla kernel: [ 60.110097] PM: suspend of drv:HDA
>> Intel dev:0000:00:08.0 complete after 149.996 msecs
>> Feb 11 13:23:05 cndougla kernel: [ 60.110433] PM: suspend devices took
>> 1.320 seconds
>>
>> Feb 11 13:23:05 cndougla kernel: [ 61.313617] PM: resume of drv:battery
>> dev:PNP0C0A:00 complete after 141.572 msecs
>> Feb 11 13:23:05 cndougla kernel: [ 66.300578] PM: resume of drv:nvidia
>> dev:0000:02:00.0 complete after 4849.583 msecs
>
> Yeeks how slow is Nvidia. This is exactly the sort of information we
> are looking to get out of the debugging exercise.
>
>> Feb 11 13:23:05 cndougla kernel: [ 66.562640] PM: resume of drv:usb
>> dev:usb3 complete after 109.993 msecs
>> Feb 11 13:23:05 cndougla kernel: [ 66.672636] PM: resume of drv:usb
>> dev:usb4 complete after 109.980 msecs
>> Feb 11 13:23:05 cndougla kernel: [ 67.076900] PM: resume devices took
>> 5.900 seconds
>>
>>
>> The following changes since commit
>> a913ef9ba3b23aee8db094d5ab5804777c697ef1:
>> Andy Whitcroft (1):
>> UBUNTU: Ubuntu-2.6.32-13.18
>>
>> are available in the git repository at:
>>
>>
>> ssh://zinc.canonical.com/srv/kernel.ubuntu.com/git/manjo/ubuntu-lucid.git
>> srtime
>>
>> Manoj Iyer (2):
>> UBUNTU: SAUCE: PM report driver and device suspend/resume times.
>> UBUNTU: [Config] Added CONFIG_SR_REPORT_TIME_LIMIT
>>
>> debian.master/config/config.common.ubuntu | 1 +
>> drivers/base/power/main.c | 35
>> +++++++++++++++++++++++++++++
>> 2 files changed, 36 insertions(+), 0 deletions(-)
>>
>>
>> From b5c3874a49410d148d662b42bf2d305e83ddfc3e Mon Sep 17 00:00:00 2001
>> From: Manoj Iyer <manoj.iyer at canonical.com>
>> Date: Thu, 11 Feb 2010 13:35:42 -0600
>> Subject: [PATCH 1/2] UBUNTU: SAUCE: PM report driver and device suspend/resume times.
>>
>> This patch prints suspend/resume information for each driver/device to
>> dmesg. I don't think it adds much value to upstream.
>>
>> Signed-off-by: Manoj Iyer <manoj.iyer at canonical.com>
>> ---
>> drivers/base/power/main.c | 35 +++++++++++++++++++++++++++++++++++
>> 1 files changed, 35 insertions(+), 0 deletions(-)
>>
>> diff --git a/drivers/base/power/main.c b/drivers/base/power/main.c
>> index 8aa2443..578b43d 100644
>> --- a/drivers/base/power/main.c
>> +++ b/drivers/base/power/main.c
>> @@ -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
>> +
>
> If this is a configuration option you should be handling the default
> value in the definition of the confuration option and so shouldn't need
> this here. You should be able to rely on CONFIG_FOO existing and having
> a proper value and just use it in place below.
>
>> /*
>> * 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,6 +331,26 @@ 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 device_show_time(struct device *dev, 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;
>> + 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 -------------------------*/
>>
>> /**
>> @@ -337,6 +364,7 @@ static void pm_dev_err(struct device *dev, 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);
>> @@ -347,6 +375,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);
>> @@ -388,6 +417,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);
>> @@ -424,6 +454,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);
>>
>> @@ -583,6 +614,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;
>> @@ -590,6 +622,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;
>> }
>> @@ -631,6 +664,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);
>>
>> @@ -666,6 +700,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);
>>
>
> You introduce what appears to be a new CONFIG_ option but do not
> introduce a Kconfig fragment to create it? Where did that go?
>
> -apw
>
More information about the kernel-team
mailing list