commit e8deb62c0364fb884660602f36c75648d2541a46
author Radu Solea <radusolea@google.com> Fri Sep 22 17:37:19 2023 -0700
committer Radu Solea <radusolea@google.com> Fri Dec 08 17:16:46 2023 -0800
tree 9b21bb7b93328f8fd1a81db16ea2cf26cf442787
parent 4f852b749da74062ac625330cfc571a61e842dfa

Log kernel wakelock stats to logcat on resume

Log wakelock info from resume to resume into logcat.
Not meant for production builds, it helps to identify power issues in dogfood.

Bug: 301657457
Test: Manual build, run, check logs with and without property set.

Change-Id: Ib4795b26014a51a2bf6d1d10b61f345f9caab6f4
Signed-off-by: Radu Solea <radusolea@google.com>

suspend/1.0/default/SystemSuspend.cpp

diff --git a/suspend/1.0/default/SystemSuspend.cpp b/suspend/1.0/default/SystemSuspend.cpp
index 7dfa408..4aa5189 100644
--- a/suspend/1.0/default/SystemSuspend.cpp
+++ b/suspend/1.0/default/SystemSuspend.cpp
@@ -23,6 +23,7 @@
 #include <aidl/android/system/suspend/IWakeLock.h>
 #include <android-base/file.h>
 #include <android-base/logging.h>
+#include <android-base/properties.h>
 #include <android-base/stringprintf.h>
 #include <android-base/strings.h>
 #include <android/binder_manager.h>
@@ -31,6 +32,7 @@
 #include <sys/types.h>
 
 #include <chrono>
+#include <cstdlib>
 #include <string>
 #include <thread>
 using namespace std::chrono_literals;
@@ -38,6 +40,7 @@
 using ::aidl::android::system::suspend::ISystemSuspend;
 using ::aidl::android::system::suspend::IWakeLock;
 using ::aidl::android::system::suspend::WakeLockType;
+using ::android::base::CachedProperty;
 using ::android::base::Error;
 using ::android::base::ReadFdToString;
 using ::android::base::StringPrintf;
@@ -400,6 +403,8 @@
 
             mControlService->notifyWakeup(success, wakeupReasons);
 
+            logKernelWakeLockStats();
+
             // Take the lock before returning to the start of the loop
             autosuspendLock.lock();
         }
@@ -409,6 +414,25 @@
     LOG(INFO) << "automatic system suspend enabled";
 }
 
+void SystemSuspend::logKernelWakeLockStats() {
+    [[clang::no_destroy]] static CachedProperty logStatsProp("suspend.debug.wakestats_log.enabled");
+    std::string prop(logStatsProp.Get(NULL));
+
+    if ((prop.compare("true") != 0) && (prop.compare("1") != 0)) return;
+
+    std::stringstream klStats;
+    klStats << "Kernel wakesource stats: ";
+    std::vector<WakeLockInfo> wlStats;
+    mStatsList.getWakeLockStats(&wlStats);
+
+    for (const WakeLockInfo& wake : wlStats) {
+        if ((wake.isKernelWakelock) && (wake.activeCount > 0)) {
+            klStats << wake.name << "," << wake.totalTime << "," << wake.activeCount << ";";
+        }
+    }
+    LOG(INFO) << klStats.rdbuf();
+}
+
 /**
  * Updates sleep time depending on the result of suspend attempt.
  * Time (in milliseconds) between suspend attempts is described the formula

suspend/1.0/default/SystemSuspend.h

diff --git a/suspend/1.0/default/SystemSuspend.h b/suspend/1.0/default/SystemSuspend.h
index a3f9a00..5f69ce8 100644
--- a/suspend/1.0/default/SystemSuspend.h
+++ b/suspend/1.0/default/SystemSuspend.h
@@ -112,6 +112,7 @@
     void checkAutosuspendClientsLivenessLocked()
         EXCLUSIVE_LOCKS_REQUIRED(mAutosuspendClientTokensLock);
     bool hasAliveAutosuspendTokenLocked() EXCLUSIVE_LOCKS_REQUIRED(mAutosuspendClientTokensLock);
+    void logKernelWakeLockStats();
 
     std::condition_variable mAutosuspendCondVar GUARDED_BY(mAutosuspendLock);
     uint32_t mSuspendCounter GUARDED_BY(mAutosuspendLock);