commit 96e8322f4d11af8538d6d0db5f1a11338b8aee9d
author Colin Cross <ccross@android.com> Fri Apr 15 14:29:55 2016 -0700
committer Colin Cross <ccross@android.com> Fri Apr 15 14:29:55 2016 -0700
tree 461acff6624b23b44433fe4033c5d26e40af4a45
parent 9eb286a074a8b2764b69339b0958dc5b176f1a8d

Log when binder thread pool is starved

Log when the number of threads executing binder commands is equal to the
maximium size of the thread pool for >100ms.

Bug: 28201939
Change-Id: I892863d8a81c06e362d4ae18ab08485fdec3c0bb

libs/binder/IPCThreadState.cpp

diff --git a/libs/binder/IPCThreadState.cpp b/libs/binder/IPCThreadState.cpp
index 1cbcfe4..d90798f 100644
--- a/libs/binder/IPCThreadState.cpp
+++ b/libs/binder/IPCThreadState.cpp
@@ -24,12 +24,14 @@
 
 #include <cutils/sched_policy.h>
 #include <utils/Log.h>
+#include <utils/SystemClock.h>
 #include <utils/threads.h>
 
 #include <private/binder/binder_module.h>
 #include <private/binder/Static.h>
 
 #include <errno.h>
+#include <inttypes.h>
 #include <pthread.h>
 #include <sched.h>
 #include <signal.h>
@@ -434,12 +436,25 @@
 
         pthread_mutex_lock(&mProcess->mThreadCountLock);
         mProcess->mExecutingThreadsCount++;
+        if (mProcess->mExecutingThreadsCount >= mProcess->mMaxThreads &&
+                mProcess->mStarvationStartTimeMs == 0) {
+            mProcess->mStarvationStartTimeMs = uptimeMillis();
+        }
         pthread_mutex_unlock(&mProcess->mThreadCountLock);
 
         result = executeCommand(cmd);
 
         pthread_mutex_lock(&mProcess->mThreadCountLock);
         mProcess->mExecutingThreadsCount--;
+        if (mProcess->mExecutingThreadsCount < mProcess->mMaxThreads &&
+                mProcess->mStarvationStartTimeMs != 0) {
+            int64_t starvationTimeMs = uptimeMillis() - mProcess->mStarvationStartTimeMs;
+            if (starvationTimeMs > 100) {
+                ALOGE("binder thread pool (%zu threads) starved for %" PRId64 " ms",
+                      mProcess->mMaxThreads, starvationTimeMs);
+            }
+            mProcess->mStarvationStartTimeMs = 0;
+        }
         pthread_cond_broadcast(&mProcess->mThreadCountDecrement);
         pthread_mutex_unlock(&mProcess->mThreadCountLock);
 

libs/binder/ProcessState.cpp

diff --git a/libs/binder/ProcessState.cpp b/libs/binder/ProcessState.cpp
index b221e51..f13f49f 100644
--- a/libs/binder/ProcessState.cpp
+++ b/libs/binder/ProcessState.cpp
@@ -343,6 +343,7 @@
     , mThreadCountDecrement(PTHREAD_COND_INITIALIZER)
     , mExecutingThreadsCount(0)
     , mMaxThreads(DEFAULT_MAX_BINDER_THREADS)
+    , mStarvationStartTimeMs(0)
     , mManagesContexts(false)
     , mBinderContextCheckFunc(NULL)
     , mBinderContextUserData(NULL)