Add tracing for UserState and a few services.

Both BackupManager and AppWidgetManager internals are taking a long
time to process user unlock events, so add tracing details.  Also add
general tracing to show all UserState changes.

Bug: 32859180
Test: builds, boots
Change-Id: I82f4f7220ccb695941acd6bc45cd67a5fae8a4d2
diff --git a/services/appwidget/java/com/android/server/appwidget/AppWidgetServiceImpl.java b/services/appwidget/java/com/android/server/appwidget/AppWidgetServiceImpl.java
index aad4431..7ebda35 100644
--- a/services/appwidget/java/com/android/server/appwidget/AppWidgetServiceImpl.java
+++ b/services/appwidget/java/com/android/server/appwidget/AppWidgetServiceImpl.java
@@ -68,6 +68,7 @@
 import android.os.Process;
 import android.os.RemoteException;
 import android.os.SystemClock;
+import android.os.Trace;
 import android.os.UserHandle;
 import android.os.UserManager;
 import android.os.storage.StorageManager;
@@ -2645,8 +2646,12 @@
             return;
         }
         synchronized (mLock) {
+            Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, "appwidget ensure");
             ensureGroupStateLoadedLocked(userId);
+            Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
+            Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, "appwidget reload");
             reloadWidgetsMaskedStateForGroup(mSecurityPolicy.getGroupParent(userId));
+            Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
 
             final int N = mProviders.size();
             for (int i = 0; i < N; i++) {
@@ -2658,10 +2663,13 @@
                 }
 
                 if (provider.widgets.size() > 0) {
+                    Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
+                            "appwidget init " + provider.info.provider.getPackageName());
                     sendEnableIntentLocked(provider);
                     int[] appWidgetIds = getWidgetIds(provider.widgets);
                     sendUpdateIntentLocked(provider, appWidgetIds);
                     registerForBroadcastsLocked(provider, appWidgetIds);
+                    Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
                 }
             }
         }
diff --git a/services/backup/java/com/android/server/backup/BackupManagerService.java b/services/backup/java/com/android/server/backup/BackupManagerService.java
index 5c180f1..77d3cd3 100644
--- a/services/backup/java/com/android/server/backup/BackupManagerService.java
+++ b/services/backup/java/com/android/server/backup/BackupManagerService.java
@@ -98,6 +98,7 @@
 import android.os.SELinux;
 import android.os.ServiceManager;
 import android.os.SystemClock;
+import android.os.Trace;
 import android.os.UserHandle;
 import android.os.WorkSource;
 import android.os.storage.IStorageManager;
@@ -397,9 +398,12 @@
         @Override
         public void onUnlockUser(int userId) {
             if (userId == UserHandle.USER_SYSTEM) {
+                Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, "backup init");
                 sInstance.initialize(userId);
+                Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
 
                 // Migrate legacy setting
+                Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, "backup migrate");
                 if (!backupSettingMigrated(userId)) {
                     if (DEBUG) {
                         Slog.i(TAG, "Backup enable apparently not migrated");
@@ -420,12 +424,15 @@
                         }
                     }
                 }
+                Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
 
+                Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, "backup enable");
                 try {
                     sInstance.setBackupEnabled(readBackupEnableState(userId));
                 } catch (RemoteException e) {
                     // can't happen; it's a local object
                 }
+                Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
             }
         }
     }
diff --git a/services/core/java/com/android/server/am/UserState.java b/services/core/java/com/android/server/am/UserState.java
index b89586d..2e27387 100644
--- a/services/core/java/com/android/server/am/UserState.java
+++ b/services/core/java/com/android/server/am/UserState.java
@@ -20,6 +20,7 @@
 import static com.android.server.am.ActivityManagerDebugConfig.TAG_WITH_CLASS_NAME;
 
 import android.app.IStopUserCallback;
+import android.os.Trace;
 import android.os.UserHandle;
 import android.util.ArrayMap;
 import android.util.Slog;
@@ -81,9 +82,18 @@
         if (newState == state) {
             return;
         }
-        Slog.i(TAG, "User " + mHandle.getIdentifier() + " state changed from "
+        final int userId = mHandle.getIdentifier();
+        if (state != STATE_BOOTING) {
+            Trace.asyncTraceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER,
+                    stateToString(state) + " " + userId, userId);
+        }
+        if (newState != STATE_SHUTDOWN) {
+            Trace.asyncTraceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
+                    stateToString(newState) + " " + userId, userId);
+        }
+        Slog.i(TAG, "User " + userId + " state changed from "
                 + stateToString(state) + " to " + stateToString(newState));
-        EventLogTags.writeAmUserStateChanged(mHandle.getIdentifier(), newState);
+        EventLogTags.writeAmUserStateChanged(userId, newState);
         lastState = state;
         state = newState;
     }