Re: [PATCH] power, trace: add tracing for device_resume

From: Sameer Nanda
Date: Fri May 18 2012 - 14:58:18 EST


On Fri, May 18, 2012 at 11:37 AM, Greg KH <gregkh@xxxxxxxxxxxxxxxxxxx> wrote:
> On Fri, May 18, 2012 at 11:27:23AM -0700, Sameer Nanda wrote:
>> Added event tracing for device_resume. This helps quickly pinpoint which
>> devices take a long time to resume.
>>
>> Signed-off-by: Sameer Nanda <snanda@xxxxxxxxxxxx>
>> ---
>> ÂDocumentation/trace/events-power.txt | Â 20 +++++++++++
>> Âdrivers/base/power/main.c      Â|  10 ++++++
>> Âinclude/trace/events/power.h     |  59 ++++++++++++++++++++++++++++++++++
>> Â3 files changed, 89 insertions(+), 0 deletions(-)
>>
>> diff --git a/Documentation/trace/events-power.txt b/Documentation/trace/events-power.txt
>> index cf794af..dbfb7f0 100644
>> --- a/Documentation/trace/events-power.txt
>> +++ b/Documentation/trace/events-power.txt
>> @@ -88,3 +88,23 @@ power_domain_target    Â"%s state=%lu cpu_id=%lu"
>> ÂThe first parameter gives the power domain name (e.g. "mpu_pwrdm").
>> ÂThe second parameter is the power domain target state.
>>
>> +4. Device resume events
>> +=======================
>> +The device resume events are used for measuring the time taken to resume
>> +devices.
>> +
>> +device_resume_in   "device=%s driver=%s"
>> +device_resume_waited "device=%s driver=%s time_delta=%lld"
>> +device_resume_out  Â"device=%s driver=%s time_delta=%lld"
>> +
>> +The first parameter is the device that is being resumed.
>> +
>> +The second parameter is the driver associated with the device being resumed.
>> +
>> +The third parameter in device_resume_waited is the time delta from the entry
>> +point of device_resume to the wait completion of parent device being resumed.
>> +The unit for time_delta is us.
>> +
>> +The third parameter in device_resume_out is the time delta from the wait
>> +completion of parent device being resumed to device_resume being completed.
>> +The unit for time_delta is us.
>> diff --git a/drivers/base/power/main.c b/drivers/base/power/main.c
>> index b462c0e..3ed01cd 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 "../base.h"
>> Â#include "power.h"
>> @@ -565,11 +566,19 @@ static int device_resume(struct device *dev, pm_message_t state, bool async)
>> Â Â Â char *info = NULL;
>> Â Â Â int error = 0;
>> Â Â Â bool put = false;
>> + Â Â s64 in_time = ktime_to_us(ktime_get());
>> + Â Â s64 wait_done_time;
>> +
>> + Â Â trace_device_resume_in(dev);
>>
>> Â Â Â TRACE_DEVICE(dev);
>> Â Â Â TRACE_RESUME(0);
>
> Don't these TRACE_DEVICE() and TRACE_RESUME() calls already provide you
> the same information you are wanting to determine above if you look at
> the timestamps of the events?

AFAICT, they are used for something completely different -- help solve
suspend/resume issues by saving a hash in the RTC of the last device
that suspended/resumed. They don't use the perf tracing mechanism at
all.

> ÂCan you not do time processing in
> userspace?

Did you mean by using the TRACE_DEVICE/TRACE_RESUME functionality or
something else?

>
> confused,
>
> greg k-h



--
Sameer
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/