Patchwork UBUNTU: SAUCE: PM report driver and device suspend/resume times.

login
register
mail settings
Submitter Manoj Iyer
Date Feb. 12, 2010, 7:32 p.m.
Message ID <alpine.DEB.2.00.1002121330450.11078@hungry>
Download mbox | patch
Permalink /patch/45208/
State Changes Requested
Delegated to: Andy Whitcroft
Headers show

Comments

Manoj Iyer - Feb. 12, 2010, 7:32 p.m.
Modified patch as per review comments, I will send out the CONFIG patch as 
soon as I figure out the right procedure.

The following changes since commit 
baaa7713d6701c4280d54a45fc89369c6945e60b:
   Rajiv Andrade (1):
         tpm_tis: TPM_STS_DATA_EXPECT workaround

are available in the git repository at:


ssh://zinc.canonical.com/srv/kernel.ubuntu.com/git/manjo/ubuntu-lucid.git 
srtimereport

Manoj Iyer (1):
       UBUNTU: SAUCE: PM report driver and device suspend/resume times.

Rafael J. Wysocki (1):
       PM: Measure device suspend and resume times

  drivers/base/power/main.c |   33 +++++++++++++++++++++++++++++++++
  1 files changed, 33 insertions(+), 0 deletions(-)


From 93ea296b84b6f6ae665c6bb0af596f27a6577297 Mon Sep 17 00:00:00 2001
From: Manoj Iyer <manoj.iyer@canonical.com>
Date: Fri, 12 Feb 2010 12:28:25 -0600
Subject: [PATCH 2/2] UBUNTU: SAUCE: PM report driver and device suspend/resume times.

Based on a patch from Rafael J. Wysocki. This patch prints suspend/resume
information for each driver/device to dmesg.

Signed-off-by: Manoj Iyer <manoj.iyer@canonical.com>
---
  drivers/base/power/main.c |   34 ++++++++++++++++++++--------------
  1 files changed, 20 insertions(+), 14 deletions(-)

Patch

diff --git a/drivers/base/power/main.c b/drivers/base/power/main.c
index d72d4b3..b6aaafb 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
+
  /*
   * 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,7 +331,7 @@  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)
+static void device_show_time(struct device *dev, ktime_t starttime, pm_message_t state, char *info)
  {
  	ktime_t calltime;
  	s64 usecs64;
@@ -336,9 +343,10 @@  static void dpm_show_time(ktime_t starttime, pm_message_t state, char *info)
  	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);
+	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 -------------------------*/
@@ -354,6 +362,7 @@  static void dpm_show_time(ktime_t starttime, 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);
@@ -364,6 +373,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);
@@ -380,7 +390,6 @@  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;
@@ -394,7 +403,6 @@  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);
@@ -407,6 +415,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);
@@ -443,6 +452,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);

@@ -460,7 +470,6 @@  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);
@@ -489,7 +498,6 @@  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 +612,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;
@@ -611,6 +620,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;
  }
@@ -625,7 +635,6 @@  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();
@@ -641,8 +650,6 @@  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);
@@ -655,6 +662,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);

@@ -690,6 +698,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);

@@ -703,7 +712,6 @@  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);
@@ -729,8 +737,6 @@  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;
  }

-- 
1.6.3.3

From 80ccbc89958661041ec09e13193c1a7cfe53d1f3 Mon Sep 17 00:00:00 2001
From: Rafael J. Wysocki <rjw@sisk.pl>
Date: Fri, 18 Dec 2009 01:57:47 +0100
Subject: [PATCH 1/2] PM: Measure device suspend and resume times

Measure and print the time of suspending and resuming all devices.

Signed-off-by: Rafael J. Wysocki <rjw@sisk.pl>
(cherry picked from commit ecf762b2581e12ac761d12a6e4e297c2224aa899)

Signed-off-by: Manoj Iyer <manoj.iyer@canonical.com>
---
  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;
  }