More debug for issue #17310019: pause when launching settings

Dang, I missed a lot of opportunities to log!

Change-Id: I566597269fe73b0f798df4f00ad26d062021081d

services/core/java/com/android/server/am/ActivityManagerService.java

diff --git a/services/core/java/com/android/server/am/ActivityManagerService.java b/services/core/java/com/android/server/am/ActivityManagerService.java
index 6275f4d..86f227d 100755
--- a/services/core/java/com/android/server/am/ActivityManagerService.java
+++ b/services/core/java/com/android/server/am/ActivityManagerService.java
@@ -9091,9 +9091,11 @@
             boolean singleton;
             if (!providerRunning) {
                 try {
+                    checkTime(startTime, "getContentProviderImpl: before resolveContentProvider");
                     cpi = AppGlobals.getPackageManager().
                         resolveContentProvider(name,
                             STOCK_PM_FLAGS | PackageManager.GET_URI_PERMISSION_PATTERNS, userId);
+                    checkTime(startTime, "getContentProviderImpl: after resolveContentProvider");
                 } catch (RemoteException ex) {
                 }
                 if (cpi == null) {
@@ -9110,12 +9112,15 @@
                     userId = UserHandle.USER_OWNER;
                 }
                 cpi.applicationInfo = getAppInfoForUser(cpi.applicationInfo, userId);
+                checkTime(startTime, "getContentProviderImpl: got app info for user");
 
                 String msg;
+                checkTime(startTime, "getContentProviderImpl: before checkContentProviderPermission");
                 if ((msg = checkContentProviderPermissionLocked(cpi, r, userId, !singleton))
                         != null) {
                     throw new SecurityException(msg);
                 }
+                checkTime(startTime, "getContentProviderImpl: after checkContentProviderPermission");
 
                 if (!mProcessesReady && !mDidUpdate && !mWaitingUpdate
                         && !cpi.processName.equals("system")) {
@@ -9137,15 +9142,19 @@
                 }
 
                 ComponentName comp = new ComponentName(cpi.packageName, cpi.name);
+                checkTime(startTime, "getContentProviderImpl: before getProviderByClass");
                 cpr = mProviderMap.getProviderByClass(comp, userId);
+                checkTime(startTime, "getContentProviderImpl: after getProviderByClass");
                 final boolean firstClass = cpr == null;
                 if (firstClass) {
                     try {
+                        checkTime(startTime, "getContentProviderImpl: before getApplicationInfo");
                         ApplicationInfo ai =
                             AppGlobals.getPackageManager().
                                 getApplicationInfo(
                                         cpi.applicationInfo.packageName,
                                         STOCK_PM_FLAGS, userId);
+                        checkTime(startTime, "getContentProviderImpl: after getApplicationInfo");
                         if (ai == null) {
                             Slog.w(TAG, "No package info for content provider "
                                     + cpi.name);
@@ -9158,6 +9167,8 @@
                     }
                 }
 
+                checkTime(startTime, "getContentProviderImpl: now have ContentProviderRecord");
+
                 if (r != null && cpr.canRunHere(r)) {
                     // If this is a multiprocess provider, then just return its
                     // info and allow the caller to instantiate it.  Only do
@@ -9191,8 +9202,10 @@
                     try {
                         // Content provider is now in use, its package can't be stopped.
                         try {
+                            checkTime(startTime, "getContentProviderImpl: before set stopped state");
                             AppGlobals.getPackageManager().setPackageStoppedState(
                                     cpr.appInfo.packageName, false, userId);
+                            checkTime(startTime, "getContentProviderImpl: after set stopped state");
                         } catch (RemoteException e) {
                         } catch (IllegalArgumentException e) {
                             Slog.w(TAG, "Failed trying to unstop package "
@@ -9200,22 +9213,26 @@
                         }
 
                         // Use existing process if already started
+                        checkTime(startTime, "getContentProviderImpl: looking for process record");
                         ProcessRecord proc = getProcessRecordLocked(
                                 cpi.processName, cpr.appInfo.uid, false);
                         if (proc != null && proc.thread != null) {
                             if (DEBUG_PROVIDER) {
                                 Slog.d(TAG, "Installing in existing process " + proc);
                             }
+                            checkTime(startTime, "getContentProviderImpl: scheduling install");
                             proc.pubProviders.put(cpi.name, cpr);
                             try {
                                 proc.thread.scheduleInstallProvider(cpi);
                             } catch (RemoteException e) {
                             }
                         } else {
+                            checkTime(startTime, "getContentProviderImpl: before start process");
                             proc = startProcessLocked(cpi.processName,
                                     cpr.appInfo, false, 0, "content provider",
                                     new ComponentName(cpi.applicationInfo.packageName,
                                             cpi.name), false, false, false);
+                            checkTime(startTime, "getContentProviderImpl: after start process");
                             if (proc == null) {
                                 Slog.w(TAG, "Unable to launch app "
                                         + cpi.applicationInfo.packageName + "/"
@@ -9231,6 +9248,8 @@
                     }
                 }
 
+                checkTime(startTime, "getContentProviderImpl: updating data structures");
+
                 // Make sure the provider is published (the same provider class
                 // may be published under multiple names).
                 if (firstClass) {
@@ -9243,6 +9262,7 @@
                     conn.waiting = true;
                 }
             }
+            checkTime(startTime, "getContentProviderImpl: done!");
         }
 
         // Wait for the provider to be published...