From patchwork Wed Sep 9 23:39:21 2009 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Rafael Wysocki X-Patchwork-Id: 46493 Received: from vger.kernel.org (vger.kernel.org [209.132.176.167]) by demeter.kernel.org (8.14.2/8.14.2) with ESMTP id n89NiRrw022018 for ; Wed, 9 Sep 2009 23:44:28 GMT Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1754599AbZIIXmZ (ORCPT ); Wed, 9 Sep 2009 19:42:25 -0400 Received: (majordomo@vger.kernel.org) by vger.kernel.org id S1754602AbZIIXmE (ORCPT ); Wed, 9 Sep 2009 19:42:04 -0400 Received: from ogre.sisk.pl ([217.79.144.158]:36005 "EHLO ogre.sisk.pl" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1754557AbZIIXmB (ORCPT ); Wed, 9 Sep 2009 19:42:01 -0400 Received: from localhost (localhost.localdomain [127.0.0.1]) by ogre.sisk.pl (Postfix) with ESMTP id A7BFC1563DF; Wed, 9 Sep 2009 22:38:43 +0200 (CEST) Received: from ogre.sisk.pl ([127.0.0.1]) by localhost (ogre.sisk.pl [127.0.0.1]) (amavisd-new, port 10024) with ESMTP id 01372-09; Wed, 9 Sep 2009 22:38:17 +0200 (CEST) Received: from tosh.localnet (220-bem-13.acn.waw.pl [82.210.184.220]) (using TLSv1 with cipher DHE-RSA-AES256-SHA (256/256 bits)) (No client certificate requested) by ogre.sisk.pl (Postfix) with ESMTP id CE618157233; Wed, 9 Sep 2009 22:37:44 +0200 (CEST) From: "Rafael J. Wysocki" To: "linux-pm" Subject: [PATCH 7/9] PM: Measure device suspend and resume times Date: Thu, 10 Sep 2009 01:39:21 +0200 User-Agent: KMail/1.12.1 (Linux/2.6.31-rc9-rjw; KDE/4.3.1; x86_64; ; ) Cc: LKML , Linux PCI , ACPI Devel Maling List , Len Brown , Zhang Rui , Pavel Machek , Alan Stern , Arjan van de Ven , Ingo Molnar References: <200909100127.11252.rjw@sisk.pl> In-Reply-To: <200909100127.11252.rjw@sisk.pl> MIME-Version: 1.0 Message-Id: <200909100139.21954.rjw@sisk.pl> X-Virus-Scanned: amavisd-new at ogre.sisk.pl using MkS_Vir for Linux Sender: linux-pci-owner@vger.kernel.org Precedence: bulk List-ID: X-Mailing-List: linux-pci@vger.kernel.org From: Rafael J. Wysocki Measure and print the time of suspending and resuming all devices. Signed-off-by: Rafael J. Wysocki --- drivers/base/power/main.c | 56 +++++++++++++++++++++++++++++++++++++++++++++- include/linux/pm.h | 3 ++ kernel/power/swsusp.c | 6 ---- 3 files changed, 59 insertions(+), 6 deletions(-) -- To unsubscribe from this list: send the line "unsubscribe linux-pci" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Index: linux-2.6/kernel/power/swsusp.c =================================================================== --- linux-2.6.orig/kernel/power/swsusp.c +++ linux-2.6/kernel/power/swsusp.c @@ -169,14 +169,10 @@ int swsusp_swap_in_use(void) void swsusp_show_speed(struct timeval *start, struct timeval *stop, unsigned nr_pages, char *msg) { - s64 elapsed_centisecs64; - int centisecs; + int centisecs = pm_time_elapsed(start, stop); int k; int kps; - elapsed_centisecs64 = timeval_to_ns(stop) - timeval_to_ns(start); - do_div(elapsed_centisecs64, NSEC_PER_SEC / 100); - centisecs = elapsed_centisecs64; if (centisecs == 0) centisecs = 1; /* avoid div-by-zero */ k = nr_pages * (PAGE_SIZE / 1024); Index: linux-2.6/drivers/base/power/main.c =================================================================== --- linux-2.6.orig/drivers/base/power/main.c +++ linux-2.6/drivers/base/power/main.c @@ -28,6 +28,7 @@ #include #include #include +#include #include "../base.h" #include "power.h" @@ -434,6 +435,20 @@ static bool pm_op_started(struct device return ret; } +/** + * pm_time_elapsed - Compute time elapsed between two timestamps. + * @start: First timestamp. + * @stop: Second timestamp. + */ +int pm_time_elapsed(struct timeval *start, struct timeval *stop) +{ + s64 elapsed_centisecs64; + + elapsed_centisecs64 = timeval_to_ns(stop) - timeval_to_ns(start); + do_div(elapsed_centisecs64, NSEC_PER_SEC / 100); + return elapsed_centisecs64; +} + static char *pm_verb(int event) { switch (event) { @@ -458,6 +473,16 @@ static char *pm_verb(int event) } } +static void dpm_show_time(struct timeval *start, struct timeval *stop, + pm_message_t state, const char *info) +{ + int centisecs = pm_time_elapsed(start, stop); + + printk(KERN_INFO "PM: %s%s%s of devices complete in %d.%02d seconds\n", + info ? info : "", info ? " " : "", pm_verb(state.event), + centisecs / 100, centisecs % 100); +} + 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), @@ -580,6 +605,9 @@ static int device_resume_noirq(struct de void dpm_resume_noirq(pm_message_t state) { struct device *dev; + struct timeval start, stop; + + do_gettimeofday(&start); mutex_lock(&dpm_list_mtx); transition_started = false; @@ -595,6 +623,10 @@ void dpm_resume_noirq(pm_message_t state } dpm_synchronize_noirq(); mutex_unlock(&dpm_list_mtx); + + do_gettimeofday(&stop); + dpm_show_time(&start, &stop, state, "EARLY"); + resume_device_irqs(); } EXPORT_SYMBOL_GPL(dpm_resume_noirq); @@ -740,6 +772,9 @@ static int device_resume(struct device * static void dpm_resume(pm_message_t state) { struct list_head list; + struct timeval start, stop; + + do_gettimeofday(&start); INIT_LIST_HEAD(&list); mutex_lock(&dpm_list_mtx); @@ -770,6 +805,9 @@ static void dpm_resume(pm_message_t stat list_splice(&list, &dpm_list); mutex_unlock(&dpm_list_mtx); dpm_synchronize(); + + do_gettimeofday(&stop); + dpm_show_time(&start, &stop, state, NULL); } /** @@ -985,8 +1023,11 @@ static int device_suspend_noirq(struct d int dpm_suspend_noirq(pm_message_t state) { struct device *dev; + struct timeval start, stop; int error = 0; + do_gettimeofday(&start); + suspend_device_irqs(); mutex_lock(&dpm_list_mtx); pm_transition = state; @@ -1004,8 +1045,12 @@ int dpm_suspend_noirq(pm_message_t state } dpm_synchronize_noirq(); mutex_unlock(&dpm_list_mtx); - if (error) + if (error) { dpm_resume_noirq(resume_event(state)); + } else { + do_gettimeofday(&stop); + dpm_show_time(&start, &stop, state, "LATE"); + } return error; } EXPORT_SYMBOL_GPL(dpm_suspend_noirq); @@ -1157,8 +1202,11 @@ static int device_suspend(struct device static int dpm_suspend(pm_message_t state) { struct list_head list; + struct timeval start, stop; int error = 0; + do_gettimeofday(&start); + INIT_LIST_HEAD(&list); mutex_lock(&dpm_list_mtx); pm_transition = state; @@ -1188,6 +1236,12 @@ static int dpm_suspend(pm_message_t stat list_splice(&list, dpm_list.prev); mutex_unlock(&dpm_list_mtx); dpm_synchronize(); + + if (!error) { + do_gettimeofday(&stop); + dpm_show_time(&start, &stop, state, NULL); + } + return error; } Index: linux-2.6/include/linux/pm.h =================================================================== --- linux-2.6.orig/include/linux/pm.h +++ linux-2.6/include/linux/pm.h @@ -505,6 +505,9 @@ extern int sysdev_suspend(pm_message_t s extern int dpm_suspend_noirq(pm_message_t state); extern int dpm_suspend_start(pm_message_t state); +struct timeval; +extern int pm_time_elapsed(struct timeval *start, struct timeval *stop); + extern void __suspend_report_result(const char *function, void *fn, int ret); #define suspend_report_result(fn, ret) \