[PATCH 1/3] PM: runtime: add additional suspend/resume metrics

[Joshua Crofts <crofts@kernel.org>]

The current implementation only logs the total accumulated time a device
spends in suspended or active states.

Add tracking for:
- resume_count : number of successful transitions to active
- suspend_count: number of successful transitions to suspended
- last_suspended_time: duration of the most recent sleep cycle (ns)
- min_suspended_time / max_suspended_sleep: shortest and longest sleep
  cycle durations to help detect power thrashing (ns)

Signed-off-by: Joshua Crofts <crofts@kernel.org>
---
 drivers/base/power/runtime.c | 70 +++++++++++++++++++++++++++++++++++++++++---
 include/linux/pm.h           | 12 ++++++++
 2 files changed, 78 insertions(+), 4 deletions(-)

diff --git a/drivers/base/power/runtime.c b/drivers/base/power/runtime.c
index 304a2b12342082ffacce32aa9c2e863466b0d4ae..5087a52f1784f7b4493896bce147ebcb0424d17c 100644
--- a/drivers/base/power/runtime.c
+++ b/drivers/base/power/runtime.c
@@ -5,6 +5,8 @@
  * Copyright (c) 2009 Rafael J. Wysocki <rjw@sisk.pl>, Novell Inc.
  * Copyright (C) 2010 Alan Stern <stern@rowland.harvard.edu>
  */
+#include <linux/pm.h>
+#include <linux/timekeeping.h>
 #include <linux/sched/mm.h>
 #include <linux/ktime.h>
 #include <linux/hrtimer.h>
@@ -103,11 +105,62 @@ static void update_pm_runtime_accounting(struct device *dev)
 		dev->power.active_time += delta;
 }
 
+static void rpm_account_suspend(struct device *dev)
+{
+	dev->power.suspend_time = ktime_get_mono_fast_ns();
+	dev->power.suspend_count++;
+}
+
+static void rpm_account_sleep_end(struct device *dev)
+{
+	u64 now, duration;
+
+	if (!dev->power.suspend_time)
+		return;
+
+	now = ktime_get_mono_fast_ns();
+	if (now <= dev->power.suspend_time)
+		return;
+
+	duration = now - dev->power.suspend_time;
+	dev->power.last_suspended_time = duration;
+
+	/* Update min/max extrema at the exact same moment as last_suspended_time */
+	if (!dev->power.min_suspended_time || duration < dev->power.min_suspended_time)
+		dev->power.min_suspended_time = duration;
+
+	if (duration > dev->power.max_suspended_time)
+		dev->power.max_suspended_time = duration;
+}
+
+static void rpm_account_resume_complete(struct device *dev)
+{
+	dev->power.resume_count++;
+	dev->power.suspend_time = 0;
+}
+
 static void __update_runtime_status(struct device *dev, enum rpm_status status)
 {
+	enum rpm_status old_status = dev->power.runtime_status;
+
 	update_pm_runtime_accounting(dev);
 	trace_rpm_status(dev, status);
 	dev->power.runtime_status = status;
+
+	if (dev->power.disable_depth > 0)
+		return;
+
+	if ((old_status == RPM_SUSPENDING || old_status == RPM_ACTIVE) &&
+	    status == RPM_SUSPENDED)
+		rpm_account_suspend(dev);
+	else if (old_status == RPM_RESUMING && status == RPM_SUSPENDED)
+		dev->power.suspend_time = ktime_get_mono_fast_ns();
+	else if (old_status == RPM_SUSPENDED && status != RPM_SUSPENDED)
+		rpm_account_sleep_end(dev);
+
+	if ((old_status == RPM_RESUMING || old_status == RPM_SUSPENDED) &&
+	    status == RPM_ACTIVE)
+		rpm_account_resume_complete(dev);
 }
 
 static u64 rpm_get_accounted_time(struct device *dev, bool suspended)
@@ -1589,10 +1642,12 @@ void pm_runtime_enable(struct device *dev)
 	dev->power.last_status = RPM_INVALID;
 	dev->power.accounting_timestamp = ktime_get_mono_fast_ns();
 
-	if (dev->power.runtime_status == RPM_SUSPENDED &&
-	    !dev->power.ignore_children &&
-	    atomic_read(&dev->power.child_count) > 0)
-		dev_warn(dev, "Enabling runtime PM for inactive device with active children\n");
+	if (dev->power.runtime_status == RPM_SUSPENDED) {
+		dev->power.suspend_time = dev->power.accounting_timestamp;
+		if (!dev->power.ignore_children &&
+		    atomic_read(&dev->power.child_count) > 0)
+			dev_warn(dev, "Enabling runtime PM for inactive device with active children\n");
+	}
 
 out:
 	spin_unlock_irqrestore(&dev->power.lock, flags);
@@ -1861,6 +1916,13 @@ void pm_runtime_init(struct device *dev)
 	pm_suspend_ignore_children(dev, false);
 	dev->power.runtime_auto = true;
 
+	dev->power.resume_count = 0;
+	dev->power.suspend_count = 0;
+	dev->power.suspend_time = 0;
+	dev->power.last_suspended_time = 0;
+	dev->power.min_suspended_time = 0;
+	dev->power.max_suspended_time = 0;
+
 	dev->power.request_pending = false;
 	dev->power.request = RPM_REQ_NONE;
 	dev->power.deferred_resume = false;
diff --git a/include/linux/pm.h b/include/linux/pm.h
index ef3f1310e749c34d4aff75a2fd7e95b9f2ef3a10..7cd1350ea327be4e800175c2fc0e3b3e35c3ea57 100644
--- a/include/linux/pm.h
+++ b/include/linux/pm.h
@@ -747,6 +747,12 @@ struct pm_subsys_data {
  *   state.
  * @accounting_timestamp: Timestamp in nanoseconds of the last runtime PM state
  *   accounting update.
+ * @resume_count: Number of transitions from suspended -> active
+ * @suspend_count: Number of transitions from active -> suspended
+ * @suspend_time: Timestamp when device entered RPM_SUSPENDED
+ * @last_suspended_time: Residency of the last sleep period (ns)
+ * @min_suspended_time: Shortest sleep duration
+ * @max_suspended_time: Longest sleep duration
  * @subsys_data: Subsystem-specific power management data.
  * @set_latency_tolerance: Callback for setting latency tolerance.
  * @qos: Per-device PM Quality of Service (QoS) constraints.
@@ -816,6 +822,12 @@ struct dev_pm_info {
 	u64			active_time;
 	u64			suspended_time;
 	u64			accounting_timestamp;
+	u64			resume_count;
+	u64			suspend_count;
+	u64			suspend_time;
+	u64			last_suspended_time;
+	u64			min_suspended_time;
+	u64			max_suspended_time;
 #endif
 	struct pm_subsys_data	*subsys_data;  /* Owned by the subsystem. */
 	void (*set_latency_tolerance)(struct device *, s32);

-- 
2.47.3