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

[Greg KH <gregkh@linuxfoundation.org>]

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@chromium.org>
> ---
>  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?  Can you not do time processing in
userspace?

confused,

greg k-h