From a4d089f2d09370ffa39119226417550f52e5148e Mon Sep 17 00:00:00 2001
From: Hui Yu <huiyu@google.com>
Date: Tue, 2 Apr 2019 16:19:12 -0700
Subject: [PATCH] Add a list to track unfinished tasks and dumpStackTraces

Previously exception message only prints unstarted tasks in the thread
pool. We also want to know the started but unfinished tasks. Add an
array list mPendingTask to track all unfinished tasks.

Also dumpStackTraces() so we can tell why the task in the threadpool
failed to finish on time.

This will help us to find root cause of IllegalStateException in
SystemServerInitThreadPool.shutdown().

Bug: 128928718
Test: Reboot device, adb logcat | grep SystemServerInitThreadPool. Force
a task to sleep for 30 seconds, observe IllegalStateException with
unfinished task printed and stack traces is dumped in a ANR file.

Change-Id: I98ba86e58ae1f2e1ab2b3f8ea3724c6b70a796eb
---
 .../server/SystemServerInitThreadPool.java    | 58 ++++++++++++++-----
 1 file changed, 44 insertions(+), 14 deletions(-)

diff --git a/services/core/java/com/android/server/SystemServerInitThreadPool.java b/services/core/java/com/android/server/SystemServerInitThreadPool.java
index 5cc9bfd52b13e..6bb3200f7cc10 100644
--- a/services/core/java/com/android/server/SystemServerInitThreadPool.java
+++ b/services/core/java/com/android/server/SystemServerInitThreadPool.java
@@ -22,9 +22,10 @@ import android.util.Slog;
 
 import com.android.internal.util.ConcurrentUtils;
 import com.android.internal.util.Preconditions;
+import com.android.server.am.ActivityManagerService;
 
+import java.util.ArrayList;
 import java.util.List;
-import java.util.concurrent.Callable;
 import java.util.concurrent.ExecutorService;
 import java.util.concurrent.Future;
 import java.util.concurrent.TimeUnit;
@@ -47,6 +48,8 @@ public class SystemServerInitThreadPool {
     private ExecutorService mService = ConcurrentUtils.newFixedThreadPool(4,
             "system-server-init-thread", Process.THREAD_PRIORITY_FOREGROUND);
 
+    private List<String> mPendingTasks = new ArrayList<>();
+
     public static synchronized SystemServerInitThreadPool get() {
         if (sInstance == null) {
             sInstance = new SystemServerInitThreadPool();
@@ -57,19 +60,26 @@ public class SystemServerInitThreadPool {
     }
 
     public Future<?> submit(Runnable runnable, String description) {
-        if (IS_DEBUGGABLE) {
-            return mService.submit(() -> {
-                Slog.d(TAG, "Started executing " + description);
-                try {
-                    runnable.run();
-                } catch (RuntimeException e) {
-                    Slog.e(TAG, "Failure in " + description + ": " + e, e);
-                    throw e;
-                }
-                Slog.d(TAG, "Finished executing "  + description);
-            });
+        synchronized (mPendingTasks) {
+            mPendingTasks.add(description);
         }
-        return mService.submit(runnable);
+        return mService.submit(() -> {
+            if (IS_DEBUGGABLE) {
+                Slog.d(TAG, "Started executing " + description);
+            }
+            try {
+                runnable.run();
+            } catch (RuntimeException e) {
+                Slog.e(TAG, "Failure in " + description + ": " + e, e);
+                throw e;
+            }
+            synchronized (mPendingTasks) {
+                mPendingTasks.remove(description);
+            }
+            if (IS_DEBUGGABLE) {
+                Slog.d(TAG, "Finished executing " + description);
+            }
+        });
     }
 
     static synchronized void shutdown() {
@@ -81,16 +91,36 @@ public class SystemServerInitThreadPool {
                         TimeUnit.MILLISECONDS);
             } catch (InterruptedException e) {
                 Thread.currentThread().interrupt();
+                dumpStackTraces();
                 throw new IllegalStateException(TAG + " init interrupted");
             }
+            if (!terminated) {
+                // dump stack must be called before shutdownNow() to collect stacktrace of threads
+                // in the thread pool.
+                dumpStackTraces();
+            }
             List<Runnable> unstartedRunnables = sInstance.mService.shutdownNow();
             if (!terminated) {
+                final List<String> copy = new ArrayList<>();
+                synchronized (sInstance.mPendingTasks) {
+                    copy.addAll(sInstance.mPendingTasks);
+                }
                 throw new IllegalStateException("Cannot shutdown. Unstarted tasks "
-                        + unstartedRunnables);
+                        + unstartedRunnables + " Unfinished tasks " + copy);
             }
             sInstance.mService = null; // Make mService eligible for GC
+            sInstance.mPendingTasks = null;
             Slog.d(TAG, "Shutdown successful");
         }
     }
 
+    /**
+     * A helper function to call ActivityManagerService.dumpStackTraces().
+     */
+    private static void dumpStackTraces() {
+        final ArrayList<Integer> pids = new ArrayList<>();
+        pids.add(Process.myPid());
+        ActivityManagerService.dumpStackTraces(
+                pids, null, null, null);
+    }
 }