From patchwork Mon Jan 25 01:05:53 2010 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Manoj Iyer X-Patchwork-Id: 43609 X-Patchwork-Delegate: apw@canonical.com Return-Path: X-Original-To: incoming@patchwork.ozlabs.org Delivered-To: patchwork-incoming@bilbo.ozlabs.org Received: from chlorine.canonical.com (chlorine.canonical.com [91.189.94.204]) by ozlabs.org (Postfix) with ESMTP id 622A71007D1 for ; Mon, 25 Jan 2010 12:06:14 +1100 (EST) Received: from localhost ([127.0.0.1] helo=chlorine.canonical.com) by chlorine.canonical.com with esmtp (Exim 4.69) (envelope-from ) id 1NZDP0-0006qN-0g; Mon, 25 Jan 2010 01:06:02 +0000 Received: from adelie.canonical.com ([91.189.90.139]) by chlorine.canonical.com with esmtp (Exim 4.69) (envelope-from ) id 1NZDOv-0006on-Nm for kernel-team@lists.ubuntu.com; Mon, 25 Jan 2010 01:05:57 +0000 Received: from hutte.canonical.com ([91.189.90.181]) by adelie.canonical.com with esmtp (Exim 4.69 #1 (Debian)) id 1NZDOv-0002y9-Lx for ; Mon, 25 Jan 2010 01:05:57 +0000 Received: from [70.114.236.114] (helo=hungry.local) by hutte.canonical.com with esmtpsa (TLS-1.0:DHE_RSA_AES_256_CBC_SHA1:32) (Exim 4.69) (envelope-from ) id 1NZDOv-0000Hr-A7 for kernel-team@lists.ubuntu.com; Mon, 25 Jan 2010 01:05:57 +0000 Date: Sun, 24 Jan 2010 19:05:53 -0600 (CST) From: Manoj Iyer To: Ubuntu Kernel Team Subject: [LUCID] [PATCH] PM: Measure device suspend and resume times Message-ID: User-Agent: Alpine 2.00 (DEB 1167 2008-08-23) MIME-Version: 1.0 X-BeenThere: kernel-team@lists.ubuntu.com X-Mailman-Version: 2.1.9 Precedence: list Reply-To: Manoj Iyer List-Id: Kernel team discussions List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Sender: kernel-team-bounces@lists.ubuntu.com Errors-To: kernel-team-bounces@lists.ubuntu.com The following patch from Rafael measures the suspend/resume times of devices. It logs the total suspend/resume times of devices as follows: [ 62.820296] PM: suspend of devices complete after 2108.836 msecs [ 62.820300] PM: suspend devices took 2.110 seconds [ 62.860107] PM: late suspend of devices complete after 39.801 msecs [ 63.440105] PM: early resume of devices complete after 20.013 msecs [ 67.337821] PM: resume of devices complete after 3887.665 msecs [ 67.338078] PM: resume devices took 3.890 seconds [ 67.338117] PM: Finishing wakeup. The following changes since commit 8275e80fb72b97750d338c905ed7575df8967b95: Rafael J. Wysocki (1): PM: Measure device suspend and resume times are available in the git repository at: ssh://zinc.canonical.com/srv/kernel.ubuntu.com/git/manjo/ubuntu-lucid.git suspendresume From 8275e80fb72b97750d338c905ed7575df8967b95 Mon Sep 17 00:00:00 2001 From: Rafael J. Wysocki Date: Fri, 18 Dec 2009 01:57:47 +0100 Subject: [PATCH] PM: Measure device suspend and resume times Measure and print the time of suspending and resuming all devices. Signed-off-by: Rafael J. Wysocki (cherry picked from commit ecf762b2581e12ac761d12a6e4e297c2224aa899) Signed-off-by: Manoj Iyer --- drivers/base/power/main.c | 27 +++++++++++++++++++++++++++ 1 files changed, 27 insertions(+), 0 deletions(-) diff --git a/drivers/base/power/main.c b/drivers/base/power/main.c index 8aa2443..d72d4b3 100644 --- a/drivers/base/power/main.c +++ b/drivers/base/power/main.c @@ -324,6 +324,23 @@ 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 dpm_show_time(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; + pr_info("PM: %s%s%s of devices complete after %ld.%03ld msecs\n", + info ?: "", info ? " " : "", pm_verb(state.event), + usecs / USEC_PER_MSEC, usecs % USEC_PER_MSEC); +} + /*------------------------- Resume routines -------------------------*/ /** @@ -363,6 +380,7 @@ static int device_resume_noirq(struct device *dev, pm_message_t state) void dpm_resume_noirq(pm_message_t state) { struct device *dev; + ktime_t starttime = ktime_get(); mutex_lock(&dpm_list_mtx); transition_started = false; @@ -376,6 +394,7 @@ void dpm_resume_noirq(pm_message_t state) pm_dev_err(dev, state, " early", error); } mutex_unlock(&dpm_list_mtx); + dpm_show_time(starttime, state, "early"); resume_device_irqs(); } EXPORT_SYMBOL_GPL(dpm_resume_noirq); @@ -441,6 +460,7 @@ static int device_resume(struct device *dev, pm_message_t state) static void dpm_resume(pm_message_t state) { struct list_head list; + ktime_t starttime = ktime_get(); INIT_LIST_HEAD(&list); mutex_lock(&dpm_list_mtx); @@ -469,6 +489,7 @@ static void dpm_resume(pm_message_t state) } list_splice(&list, &dpm_list); mutex_unlock(&dpm_list_mtx); + dpm_show_time(starttime, state, NULL); } /** @@ -604,6 +625,7 @@ static int device_suspend_noirq(struct device *dev, pm_message_t state) int dpm_suspend_noirq(pm_message_t state) { struct device *dev; + ktime_t starttime = ktime_get(); int error = 0; suspend_device_irqs(); @@ -619,6 +641,8 @@ int dpm_suspend_noirq(pm_message_t state) mutex_unlock(&dpm_list_mtx); if (error) dpm_resume_noirq(resume_event(state)); + else + dpm_show_time(starttime, state, "late"); return error; } EXPORT_SYMBOL_GPL(dpm_suspend_noirq); @@ -679,6 +703,7 @@ static int device_suspend(struct device *dev, pm_message_t state) static int dpm_suspend(pm_message_t state) { struct list_head list; + ktime_t starttime = ktime_get(); int error = 0; INIT_LIST_HEAD(&list); @@ -704,6 +729,8 @@ static int dpm_suspend(pm_message_t state) } list_splice(&list, dpm_list.prev); mutex_unlock(&dpm_list_mtx); + if (!error) + dpm_show_time(starttime, state, NULL); return error; }