[1/n] Launcher Startup Latency: add StartupLatencyLogger to launcher3 and log startup latency
More details at "Log Startup Latency" section in go/launcher-startup-latency
Test: tested on phone, foldable and tablet, print latency logs in logcat
Bug: 278092752
Change-Id: Ibf269b0ecd6007d29b95e36f65ab6f02c45deb3a
diff --git a/quickstep/src/com/android/launcher3/uioverrides/QuickstepLauncher.java b/quickstep/src/com/android/launcher3/uioverrides/QuickstepLauncher.java
index d67dbae..eab44c4 100644
--- a/quickstep/src/com/android/launcher3/uioverrides/QuickstepLauncher.java
+++ b/quickstep/src/com/android/launcher3/uioverrides/QuickstepLauncher.java
@@ -1063,7 +1063,8 @@
}
@Override
- public void onInitialBindComplete(IntSet boundPages, RunnableList pendingTasks) {
+ public void onInitialBindComplete(IntSet boundPages, RunnableList pendingTasks,
+ int workspaceItemCount, boolean isBindSync) {
pendingTasks.add(() -> {
// This is added in pending task as we need to wait for views to be positioned
// correctly before registering them for the animation.
@@ -1073,7 +1074,7 @@
mLauncherUnfoldAnimationController.updateRegisteredViewsIfNeeded();
}
});
- super.onInitialBindComplete(boundPages, pendingTasks);
+ super.onInitialBindComplete(boundPages, pendingTasks, workspaceItemCount, isBindSync);
}
@Override
diff --git a/src/com/android/launcher3/Launcher.java b/src/com/android/launcher3/Launcher.java
index 4dfd918..86a5f9f 100644
--- a/src/com/android/launcher3/Launcher.java
+++ b/src/com/android/launcher3/Launcher.java
@@ -56,6 +56,14 @@
import static com.android.launcher3.logging.StatsLogManager.LauncherEvent.LAUNCHER_SWIPELEFT;
import static com.android.launcher3.logging.StatsLogManager.LauncherEvent.LAUNCHER_SWIPERIGHT;
import static com.android.launcher3.logging.StatsLogManager.LauncherEvent.LAUNCHER_WIDGET_RECONFIGURED;
+import static com.android.launcher3.logging.StatsLogManager.LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_ACTIVITY_ON_CREATE;
+import static com.android.launcher3.logging.StatsLogManager.LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_TOTAL_DURATION;
+import static com.android.launcher3.logging.StatsLogManager.LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_VIEW_INFLATION;
+import static com.android.launcher3.logging.StatsLogManager.LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_WORKSPACE_LOADER_ASYNC;
+import static com.android.launcher3.logging.StatsLogManager.LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_WORKSPACE_LOADER_SYNC;
+import static com.android.launcher3.logging.StatsLogManager.StatsLatencyLogger.LatencyType.COLD;
+import static com.android.launcher3.logging.StatsLogManager.StatsLatencyLogger.LatencyType.COLD_DEVICE_REBOOTING;
+import static com.android.launcher3.logging.StatsLogManager.StatsLatencyLogger.LatencyType.WARM;
import static com.android.launcher3.model.ItemInstallQueue.FLAG_ACTIVITY_PAUSED;
import static com.android.launcher3.model.ItemInstallQueue.FLAG_DRAG_AND_DROP;
import static com.android.launcher3.popup.SystemShortcut.APP_INFO;
@@ -64,7 +72,6 @@
import static com.android.launcher3.states.RotationHelper.REQUEST_LOCK;
import static com.android.launcher3.states.RotationHelper.REQUEST_NONE;
import static com.android.launcher3.util.Executors.MAIN_EXECUTOR;
-import static com.android.launcher3.util.Executors.MODEL_EXECUTOR;
import static com.android.launcher3.util.ItemInfoMatcher.forFolderMatch;
import android.animation.Animator;
@@ -111,6 +118,7 @@
import android.view.MotionEvent;
import android.view.View;
import android.view.ViewGroup;
+import android.view.ViewTreeObserver;
import android.view.ViewTreeObserver.OnPreDrawListener;
import android.view.WindowManager.LayoutParams;
import android.view.accessibility.AccessibilityEvent;
@@ -157,6 +165,7 @@
import com.android.launcher3.logging.FileLog;
import com.android.launcher3.logging.InstanceId;
import com.android.launcher3.logging.InstanceIdSequence;
+import com.android.launcher3.logging.StartupLatencyLogger;
import com.android.launcher3.logging.StatsLogManager;
import com.android.launcher3.model.BgDataModel.Callbacks;
import com.android.launcher3.model.ItemInstallQueue;
@@ -190,6 +199,7 @@
import com.android.launcher3.util.ComponentKey;
import com.android.launcher3.util.IntArray;
import com.android.launcher3.util.IntSet;
+import com.android.launcher3.util.LockedUserState;
import com.android.launcher3.util.OnboardingPrefs;
import com.android.launcher3.util.PackageUserKey;
import com.android.launcher3.util.PendingRequestArgs;
@@ -293,6 +303,8 @@
public static final String ON_RESUME_EVT = "Launcher.onResume";
public static final String ON_NEW_INTENT_EVT = "Launcher.onNewIntent";
+ private static boolean sIsNewProcess = true;
+
private StateManager<LauncherState> mStateManager;
private static final int ON_ACTIVITY_RESULT_ANIMATION_DELAY = 500;
@@ -404,12 +416,22 @@
private StringCache mStringCache;
private BaseSearchConfig mBaseSearchConfig;
-
+ private StartupLatencyLogger mStartupLatencyLogger;
private CellPosMapper mCellPosMapper = CellPosMapper.DEFAULT;
@Override
@TargetApi(Build.VERSION_CODES.S)
protected void onCreate(Bundle savedInstanceState) {
+ mStartupLatencyLogger = createStartupLatencyLogger(
+ sIsNewProcess
+ ? LockedUserState.get(this).isUserUnlockedAtLauncherStartup()
+ ? COLD
+ : COLD_DEVICE_REBOOTING
+ : WARM);
+ sIsNewProcess = false;
+ mStartupLatencyLogger
+ .logStart(LAUNCHER_LATENCY_STARTUP_TOTAL_DURATION)
+ .logStart(LAUNCHER_LATENCY_STARTUP_ACTIVITY_ON_CREATE);
// Only use a hard-coded cookie since we only want to trace this once.
if (Utilities.ATLEAST_S) {
Trace.beginAsyncSection(
@@ -518,6 +540,7 @@
}
}
+ mStartupLatencyLogger.logWorkspaceLoadStartTime();
if (!mModel.addCallbacksAndLoad(this)) {
if (!internalStateHandled) {
// If we are not binding synchronously, pause drawing until initial bind complete,
@@ -557,6 +580,17 @@
getWindow().setSoftInputMode(LayoutParams.SOFT_INPUT_ADJUST_NOTHING);
}
setTitle(R.string.home_screen);
+ mStartupLatencyLogger.logEnd(LAUNCHER_LATENCY_STARTUP_ACTIVITY_ON_CREATE);
+ }
+
+ /**
+ * Create {@link StartupLatencyLogger} that only collects launcher startup latency metrics
+ * without sending them anywhere. Child class can override this method to create logger
+ * that overrides {@link StartupLatencyLogger#log()} to report those metrics.
+ */
+ protected StartupLatencyLogger createStartupLatencyLogger(
+ StatsLogManager.StatsLatencyLogger.LatencyType latencyType) {
+ return new StartupLatencyLogger(latencyType);
}
/**
@@ -1290,7 +1324,10 @@
* Finds all the views we need and configure them properly.
*/
protected void setupViews() {
+ mStartupLatencyLogger.logStart(LAUNCHER_LATENCY_STARTUP_VIEW_INFLATION);
inflateRootView(R.layout.launcher);
+ mStartupLatencyLogger.logEnd(LAUNCHER_LATENCY_STARTUP_VIEW_INFLATION);
+
mDragLayer = findViewById(R.id.drag_layer);
mFocusHandler = mDragLayer.getFocusIndicatorHelper();
mWorkspace = mDragLayer.findViewById(R.id.workspace);
@@ -2695,7 +2732,8 @@
@Override
@TargetApi(Build.VERSION_CODES.S)
- public void onInitialBindComplete(IntSet boundPages, RunnableList pendingTasks) {
+ public void onInitialBindComplete(IntSet boundPages, RunnableList pendingTasks,
+ int workspaceItemCount, boolean isBindSync) {
mSynchronouslyBoundPages = boundPages;
mPagesToBindSynchronously = new IntSet();
@@ -2719,6 +2757,26 @@
Trace.endAsyncSection(DISPLAY_WORKSPACE_TRACE_METHOD_NAME,
DISPLAY_WORKSPACE_TRACE_COOKIE);
}
+ mStartupLatencyLogger
+ .logCardinality(workspaceItemCount)
+ .logEnd(isBindSync
+ ? LAUNCHER_LATENCY_STARTUP_WORKSPACE_LOADER_SYNC
+ : LAUNCHER_LATENCY_STARTUP_WORKSPACE_LOADER_ASYNC);
+ // In the first rootview's onDraw after onInitialBindComplete(), log end of startup latency.
+ getRootView().getViewTreeObserver().addOnDrawListener(
+ new ViewTreeObserver.OnDrawListener() {
+
+ @Override
+ public void onDraw() {
+ mStartupLatencyLogger
+ .logEnd(LAUNCHER_LATENCY_STARTUP_TOTAL_DURATION)
+ .log()
+ .reset();
+ MAIN_EXECUTOR.getHandler().postAtFrontOfQueue(
+ () -> getRootView().getViewTreeObserver()
+ .removeOnDrawListener(this));
+ }
+ });
}
/**
diff --git a/src/com/android/launcher3/LauncherModel.java b/src/com/android/launcher3/LauncherModel.java
index 6798667d..d3e94e1 100644
--- a/src/com/android/launcher3/LauncherModel.java
+++ b/src/com/android/launcher3/LauncherModel.java
@@ -417,7 +417,7 @@
if (bindDirectly) {
// Divide the set of loaded items into those that we are binding synchronously,
// and everything else that is to be bound normally (asynchronously).
- launcherBinder.bindWorkspace(bindAllCallbacks);
+ launcherBinder.bindWorkspace(bindAllCallbacks, /* isBindSync= */ true);
// For now, continue posting the binding of AllApps as there are other
// issues that arise from that.
launcherBinder.bindAllApps();
diff --git a/src/com/android/launcher3/logging/StartupLatencyLogger.kt b/src/com/android/launcher3/logging/StartupLatencyLogger.kt
new file mode 100644
index 0000000..435f798
--- /dev/null
+++ b/src/com/android/launcher3/logging/StartupLatencyLogger.kt
@@ -0,0 +1,203 @@
+package com.android.launcher3.logging
+
+import android.os.SystemClock
+import android.util.Log
+import android.util.SparseLongArray
+import androidx.annotation.MainThread
+import androidx.annotation.VisibleForTesting
+import androidx.core.util.contains
+import androidx.core.util.isEmpty
+import com.android.launcher3.BuildConfig
+import com.android.launcher3.logging.StatsLogManager.LauncherLatencyEvent
+import com.android.launcher3.logging.StatsLogManager.StatsLatencyLogger.LatencyType
+import com.android.launcher3.util.Preconditions
+
+/** Logger for logging Launcher activity's startup latency. */
+open class StartupLatencyLogger(val latencyType: LatencyType) {
+
+ companion object {
+ const val TAG = "LauncherStartupLatencyLogger"
+ const val UNSET_INT = -1
+ const val UNSET_LONG = -1L
+ }
+
+ @VisibleForTesting val startTimeByEvent = SparseLongArray()
+ @VisibleForTesting val endTimeByEvent = SparseLongArray()
+
+ @VisibleForTesting var cardinality: Int = UNSET_INT
+ @VisibleForTesting var workspaceLoadStartTime: Long = UNSET_LONG
+
+ private var isInTest = false
+
+ /** Subclass can override this method to handle collected latency metrics. */
+ @MainThread
+ open fun log(): StartupLatencyLogger {
+ return this
+ }
+
+ @MainThread
+ fun logWorkspaceLoadStartTime() = logWorkspaceLoadStartTime(SystemClock.elapsedRealtime())
+
+ @VisibleForTesting
+ @MainThread
+ fun logWorkspaceLoadStartTime(startTimeMs: Long): StartupLatencyLogger {
+ Preconditions.assertUIThread()
+ workspaceLoadStartTime = startTimeMs
+ return this
+ }
+
+ /**
+ * Log size of workspace. Larger number of workspace items (icons, folders, widgets) means
+ * longer latency to initialize workspace.
+ */
+ @MainThread
+ fun logCardinality(cardinality: Int): StartupLatencyLogger {
+ Preconditions.assertUIThread()
+ this.cardinality = cardinality
+ return this
+ }
+
+ @MainThread
+ fun logStart(event: LauncherLatencyEvent) = logStart(event, SystemClock.elapsedRealtime())
+
+ @MainThread
+ fun logStart(event: LauncherLatencyEvent, startTimeMs: Long): StartupLatencyLogger {
+ // In unit test no looper is attached to current thread
+ Preconditions.assertUIThread()
+ if (validateLoggingEventAtStart(event)) {
+ startTimeByEvent.put(event.id, startTimeMs)
+ }
+ return this
+ }
+
+ @MainThread
+ fun logEnd(event: LauncherLatencyEvent) = logEnd(event, SystemClock.elapsedRealtime())
+
+ @MainThread
+ fun logEnd(event: LauncherLatencyEvent, endTimeMs: Long): StartupLatencyLogger {
+ // In unit test no looper is attached to current thread
+ Preconditions.assertUIThread()
+ maybeLogStartOfWorkspaceLoadTime(event)
+ if (validateLoggingEventAtEnd(event)) {
+ endTimeByEvent.put(event.id, endTimeMs)
+ }
+
+ return this
+ }
+
+ @MainThread
+ fun reset() {
+ // In unit test no looper is attached to current thread
+ Preconditions.assertUIThread()
+ startTimeByEvent.clear()
+ endTimeByEvent.clear()
+ cardinality = UNSET_INT
+ workspaceLoadStartTime = UNSET_LONG
+ }
+
+ @MainThread
+ private fun maybeLogStartOfWorkspaceLoadTime(event: LauncherLatencyEvent) {
+ if (workspaceLoadStartTime == UNSET_LONG) {
+ return
+ }
+ if (
+ event == LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_WORKSPACE_LOADER_SYNC ||
+ event == LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_WORKSPACE_LOADER_ASYNC
+ ) {
+ logStart(event, workspaceLoadStartTime)
+ workspaceLoadStartTime = UNSET_LONG
+ }
+ }
+
+ /** @return true if we can log start of [LauncherLatencyEvent] and vice versa. */
+ @MainThread
+ private fun validateLoggingEventAtStart(event: LauncherLatencyEvent): Boolean {
+ if (!BuildConfig.IS_STUDIO_BUILD && !isInTest) {
+ return true
+ }
+ if (startTimeByEvent.contains(event.id)) {
+ Log.e(TAG, String.format("Cannot restart same %s event", event.name))
+ return false
+ } else if (
+ startTimeByEvent.isEmpty() &&
+ event != LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_TOTAL_DURATION
+ ) {
+ Log.e(
+ TAG,
+ String.format(
+ "The first log start event must be %s.",
+ LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_TOTAL_DURATION.name
+ )
+ )
+ return false
+ } else if (
+ event == LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_WORKSPACE_LOADER_SYNC &&
+ startTimeByEvent.get(
+ LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_WORKSPACE_LOADER_ASYNC.id
+ ) != 0L
+ ) {
+ Log.e(
+ TAG,
+ String.format(
+ "Cannot start %s event after %s starts",
+ LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_WORKSPACE_LOADER_SYNC.name,
+ LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_WORKSPACE_LOADER_ASYNC.name
+ )
+ )
+ return false
+ } else if (
+ event == LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_WORKSPACE_LOADER_ASYNC &&
+ startTimeByEvent.get(
+ LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_WORKSPACE_LOADER_SYNC.id
+ ) != 0L
+ ) {
+ Log.e(
+ TAG,
+ String.format(
+ "Cannot start %s event after %s starts",
+ LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_WORKSPACE_LOADER_ASYNC.name,
+ LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_WORKSPACE_LOADER_SYNC.name
+ )
+ )
+ return false
+ }
+
+ return true
+ }
+
+ /** @return true if we can log end of [LauncherLatencyEvent] and vice versa. */
+ @MainThread
+ private fun validateLoggingEventAtEnd(event: LauncherLatencyEvent): Boolean {
+ if (!BuildConfig.IS_STUDIO_BUILD && !isInTest) {
+ return true
+ }
+ if (!startTimeByEvent.contains(event.id)) {
+ Log.e(TAG, String.format("Cannot end %s event before starting it", event.name))
+ return false
+ } else if (endTimeByEvent.contains(event.id)) {
+ Log.e(TAG, String.format("Cannot end same %s event again", event.name))
+ return false
+ } else if (
+ event != LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_TOTAL_DURATION &&
+ endTimeByEvent.contains(
+ LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_TOTAL_DURATION.id
+ )
+ ) {
+ Log.e(
+ TAG,
+ String.format(
+ "Cannot end %s event after %s",
+ event.name,
+ LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_TOTAL_DURATION.name
+ )
+ )
+ return false
+ }
+ return true
+ }
+
+ @VisibleForTesting
+ fun setIsInTest() {
+ isInTest = true
+ }
+}
diff --git a/src/com/android/launcher3/logging/StatsLogManager.java b/src/com/android/launcher3/logging/StatsLogManager.java
index 5b4a02b..8197b73 100644
--- a/src/com/android/launcher3/logging/StatsLogManager.java
+++ b/src/com/android/launcher3/logging/StatsLogManager.java
@@ -657,6 +657,39 @@
}
}
+ /** Launcher's latency events. */
+ public enum LauncherLatencyEvent implements EventEnum {
+ // Details of below 6 events with prefix of "LAUNCHER_LATENCY_STARTUP_" are discussed in
+ // go/launcher-startup-latency
+ @UiEvent(doc = "The total duration of launcher startup latency.")
+ LAUNCHER_LATENCY_STARTUP_TOTAL_DURATION(1362),
+
+ @UiEvent(doc = "The duration of launcher activity's onCreate().")
+ LAUNCHER_LATENCY_STARTUP_ACTIVITY_ON_CREATE(1363),
+
+ @UiEvent(doc =
+ "The duration to inflate launcher root view in launcher activity's onCreate().")
+ LAUNCHER_LATENCY_STARTUP_VIEW_INFLATION(1364),
+
+ @UiEvent(doc = "The duration of synchronous loading workspace")
+ LAUNCHER_LATENCY_STARTUP_WORKSPACE_LOADER_SYNC(1366),
+
+ @UiEvent(doc = "The duration of asynchronous loading workspace")
+ LAUNCHER_LATENCY_STARTUP_WORKSPACE_LOADER_ASYNC(1367),
+ ;
+
+ private final int mId;
+
+ LauncherLatencyEvent(int id) {
+ mId = id;
+ }
+
+ @Override
+ public int getId() {
+ return mId;
+ }
+ }
+
/**
* Launcher specific ranking related events.
*/
@@ -807,7 +840,10 @@
CONTROLLED(7),
CACHED(8),
// example: device is rebooting via power key or shell command `adb reboot`
- COLD_DEVICE_REBOOTING(9);
+ COLD_DEVICE_REBOOTING(9),
+ // Tracking warm startup latency:
+ // https://developer.android.com/topic/performance/vitals/launch-time#warm
+ WARM(10);
private final int mId;
LatencyType(int id) {
diff --git a/src/com/android/launcher3/model/BaseLauncherBinder.java b/src/com/android/launcher3/model/BaseLauncherBinder.java
index c946e2c..ba9eb20 100644
--- a/src/com/android/launcher3/model/BaseLauncherBinder.java
+++ b/src/com/android/launcher3/model/BaseLauncherBinder.java
@@ -78,14 +78,14 @@
/**
* Binds all loaded data to actual views on the main thread.
*/
- public void bindWorkspace(boolean incrementBindId) {
+ public void bindWorkspace(boolean incrementBindId, boolean isBindSync) {
if (FeatureFlags.ENABLE_WORKSPACE_LOADING_OPTIMIZATION.get()) {
DisjointWorkspaceBinder workspaceBinder =
initWorkspaceBinder(incrementBindId, mBgDataModel.collectWorkspaceScreens());
- workspaceBinder.bindCurrentWorkspacePages();
+ workspaceBinder.bindCurrentWorkspacePages(isBindSync);
workspaceBinder.bindOtherWorkspacePages();
} else {
- bindWorkspaceAllAtOnce(incrementBindId);
+ bindWorkspaceAllAtOnce(incrementBindId, isBindSync);
}
}
@@ -108,13 +108,13 @@
}
}
- private void bindWorkspaceAllAtOnce(boolean incrementBindId) {
+ private void bindWorkspaceAllAtOnce(boolean incrementBindId, boolean isBindSync) {
// Save a copy of all the bg-thread collections
ArrayList<ItemInfo> workspaceItems = new ArrayList<>();
ArrayList<LauncherAppWidgetInfo> appWidgets = new ArrayList<>();
final IntArray orderedScreenIds = new IntArray();
ArrayList<FixedContainerItems> extraItems = new ArrayList<>();
-
+ final int workspaceItemCount;
synchronized (mBgDataModel) {
workspaceItems.addAll(mBgDataModel.workspaceItems);
appWidgets.addAll(mBgDataModel.appWidgets);
@@ -124,11 +124,13 @@
mBgDataModel.lastBindId++;
}
mMyBindingId = mBgDataModel.lastBindId;
+ workspaceItemCount = mBgDataModel.itemsIdMap.size();
}
for (Callbacks cb : mCallbacksList) {
new UnifiedWorkspaceBinder(cb, mUiExecutor, mApp, mBgDataModel, mMyBindingId,
- workspaceItems, appWidgets, extraItems, orderedScreenIds).bind();
+ workspaceItems, appWidgets, extraItems, orderedScreenIds)
+ .bind(isBindSync, workspaceItemCount);
}
}
@@ -246,7 +248,7 @@
mOrderedScreenIds = orderedScreenIds;
}
- private void bind() {
+ private void bind(boolean isBindSync, int workspaceItemCount) {
final IntSet currentScreenIds =
mCallbacks.getPagesToBindSynchronously(mOrderedScreenIds);
Objects.requireNonNull(currentScreenIds, "Null screen ids provided by " + mCallbacks);
@@ -297,7 +299,8 @@
executeCallbacksTask(
c -> {
MODEL_EXECUTOR.setThreadPriority(Process.THREAD_PRIORITY_BACKGROUND);
- c.onInitialBindComplete(currentScreenIds, pendingTasks);
+ c.onInitialBindComplete(
+ currentScreenIds, pendingTasks, workspaceItemCount, isBindSync);
}, mUiExecutor);
mCallbacks.bindStringCache(mBgDataModel.stringCache.clone());
@@ -361,18 +364,19 @@
* loaded, it will bind all workspace items immediately, and bindOtherWorkspacePages() will
* not bind any items.
*/
- protected void bindCurrentWorkspacePages() {
+ protected void bindCurrentWorkspacePages(boolean isBindSync) {
// Save a copy of all the bg-thread collections
ArrayList<ItemInfo> workspaceItems;
ArrayList<LauncherAppWidgetInfo> appWidgets;
ArrayList<FixedContainerItems> fciList = new ArrayList<>();
-
+ final int workspaceItemCount;
synchronized (mBgDataModel) {
workspaceItems = new ArrayList<>(mBgDataModel.workspaceItems);
appWidgets = new ArrayList<>(mBgDataModel.appWidgets);
if (!FeatureFlags.CHANGE_MODEL_DELEGATE_LOADING_ORDER.get()) {
mBgDataModel.extraItems.forEach(fciList::add);
}
+ workspaceItemCount = mBgDataModel.itemsIdMap.size();
}
workspaceItems.forEach(it -> mBoundItemIds.add(it.id));
@@ -395,10 +399,10 @@
bindWorkspaceItems(workspaceItems);
bindAppWidgets(appWidgets);
-
executeCallbacksTask(c -> {
MODEL_EXECUTOR.setThreadPriority(Process.THREAD_PRIORITY_BACKGROUND);
- c.onInitialBindComplete(mCurrentScreenIds, new RunnableList());
+ c.onInitialBindComplete(
+ mCurrentScreenIds, new RunnableList(), workspaceItemCount, isBindSync);
}, mUiExecutor);
}
diff --git a/src/com/android/launcher3/model/BgDataModel.java b/src/com/android/launcher3/model/BgDataModel.java
index 0e3b06c..0861e9d 100644
--- a/src/com/android/launcher3/model/BgDataModel.java
+++ b/src/com/android/launcher3/model/BgDataModel.java
@@ -484,7 +484,9 @@
default void bindWorkspaceComponentsRemoved(Predicate<ItemInfo> matcher) { }
default void bindAllWidgets(List<WidgetsListBaseEntry> widgets) { }
- default void onInitialBindComplete(IntSet boundPages, RunnableList pendingTasks) {
+ /** Called when workspace has been bound. */
+ default void onInitialBindComplete(IntSet boundPages, RunnableList pendingTasks,
+ int workspaceItemCount, boolean isBindSync) {
pendingTasks.executeAllAndDestroy();
}
diff --git a/src/com/android/launcher3/model/LoaderTask.java b/src/com/android/launcher3/model/LoaderTask.java
index 481cc6e..9053d19 100644
--- a/src/com/android/launcher3/model/LoaderTask.java
+++ b/src/com/android/launcher3/model/LoaderTask.java
@@ -232,7 +232,7 @@
}
verifyNotStopped();
- mLauncherBinder.bindWorkspace(true /* incrementBindId */);
+ mLauncherBinder.bindWorkspace(true /* incrementBindId */, /* isBindSync= */ false);
logASplit(timingLogger, "bindWorkspace");
mModelDelegate.workspaceLoadComplete();
diff --git a/src/com/android/launcher3/util/LockedUserState.kt b/src/com/android/launcher3/util/LockedUserState.kt
index f5e13d2..1231604 100644
--- a/src/com/android/launcher3/util/LockedUserState.kt
+++ b/src/com/android/launcher3/util/LockedUserState.kt
@@ -7,6 +7,7 @@
import androidx.annotation.VisibleForTesting
class LockedUserState(private val mContext: Context) : SafeCloseable {
+ val isUserUnlockedAtLauncherStartup: Boolean
var isUserUnlocked: Boolean
private set
private val mUserUnlockedActions: RunnableList = RunnableList()
@@ -20,10 +21,17 @@
}
init {
+ // 1) when user reboots devices, launcher process starts at lock screen and both
+ // isUserUnlocked and isUserUnlockedAtLauncherStartup are init as false. After user unlocks
+ // screen, isUserUnlocked will be updated to true via Intent.ACTION_USER_UNLOCKED,
+ // yet isUserUnlockedAtLauncherStartup will remains as false.
+ // 2) when launcher process restarts after user has unlocked screen, both variable are
+ // init as true and will not change.
isUserUnlocked =
mContext
.getSystemService(UserManager::class.java)!!
.isUserUnlocked(Process.myUserHandle())
+ isUserUnlockedAtLauncherStartup = isUserUnlocked
if (isUserUnlocked) {
notifyUserUnlocked()
} else {
diff --git a/tests/src/com/android/launcher3/logging/StartupLatencyLoggerTest.kt b/tests/src/com/android/launcher3/logging/StartupLatencyLoggerTest.kt
new file mode 100644
index 0000000..fffa6d7
--- /dev/null
+++ b/tests/src/com/android/launcher3/logging/StartupLatencyLoggerTest.kt
@@ -0,0 +1,368 @@
+package com.android.launcher3.logging
+
+import androidx.core.util.isEmpty
+import androidx.test.annotation.UiThreadTest
+import androidx.test.ext.junit.runners.AndroidJUnit4
+import androidx.test.filters.SmallTest
+import com.google.common.truth.Truth.assertThat
+import org.junit.Before
+import org.junit.Test
+import org.junit.runner.RunWith
+
+/** Unit test for [StartupLatencyLogger]. */
+@SmallTest
+@RunWith(AndroidJUnit4::class)
+class StartupLatencyLoggerTest {
+
+ private val underTest: StartupLatencyLogger =
+ StartupLatencyLogger(StatsLogManager.StatsLatencyLogger.LatencyType.COLD)
+
+ @Before
+ fun setup() {
+ underTest.setIsInTest()
+ }
+
+ @Test
+ @UiThreadTest
+ fun logTotalDurationStart() {
+ underTest.logStart(
+ StatsLogManager.LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_TOTAL_DURATION,
+ 100
+ )
+
+ val startTime =
+ underTest.startTimeByEvent.get(
+ StatsLogManager.LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_TOTAL_DURATION.id
+ )
+ assertThat(startTime).isEqualTo(100)
+ assertThat(underTest.endTimeByEvent.isEmpty()).isTrue()
+ }
+
+ @Test
+ @UiThreadTest
+ fun logTotalDurationEnd() {
+ underTest.logStart(
+ StatsLogManager.LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_TOTAL_DURATION,
+ 100
+ )
+
+ underTest.logEnd(
+ StatsLogManager.LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_TOTAL_DURATION,
+ 100
+ )
+
+ val endTime =
+ underTest.endTimeByEvent.get(
+ StatsLogManager.LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_TOTAL_DURATION.id
+ )
+ assertThat(endTime).isEqualTo(100)
+ }
+
+ @Test
+ @UiThreadTest
+ fun logStartOfOtherEvents_withoutLogStartOfTotalDuration_noOp() {
+ underTest
+ .logStart(
+ StatsLogManager.LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_ACTIVITY_ON_CREATE,
+ 100
+ )
+ .logStart(
+ StatsLogManager.LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_VIEW_INFLATION,
+ 101
+ )
+ .logStart(
+ StatsLogManager.LauncherLatencyEvent
+ .LAUNCHER_LATENCY_STARTUP_WORKSPACE_LOADER_ASYNC,
+ 102
+ )
+
+ assertThat(underTest.startTimeByEvent.isEmpty()).isTrue()
+ }
+
+ @Test
+ @UiThreadTest
+ fun logStartOfOtherEvents_afterLogStartOfTotalDuration_logged() {
+ underTest.logStart(
+ StatsLogManager.LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_TOTAL_DURATION,
+ 100
+ )
+
+ underTest
+ .logStart(
+ StatsLogManager.LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_ACTIVITY_ON_CREATE,
+ 100
+ )
+ .logStart(
+ StatsLogManager.LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_VIEW_INFLATION,
+ 101
+ )
+ .logStart(
+ StatsLogManager.LauncherLatencyEvent
+ .LAUNCHER_LATENCY_STARTUP_WORKSPACE_LOADER_ASYNC,
+ 102
+ )
+
+ assertThat(underTest.startTimeByEvent.size()).isEqualTo(4)
+ }
+
+ @Test
+ @UiThreadTest
+ fun logDuplicatedStartEvent_2ndEvent_notLogged() {
+ underTest.logStart(
+ StatsLogManager.LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_TOTAL_DURATION,
+ 100
+ )
+
+ underTest.logStart(
+ StatsLogManager.LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_TOTAL_DURATION,
+ 101
+ )
+
+ assertThat(underTest.startTimeByEvent.size()).isEqualTo(1)
+ assertThat(
+ underTest.startTimeByEvent.get(
+ StatsLogManager.LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_TOTAL_DURATION.id
+ )
+ )
+ .isEqualTo(100)
+ }
+
+ @Test
+ @UiThreadTest
+ fun loadStartOfWorkspace_thenEndWithAsync_logAsyncStart() {
+ underTest
+ .logStart(
+ StatsLogManager.LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_TOTAL_DURATION,
+ 100
+ )
+ .logWorkspaceLoadStartTime(111)
+
+ underTest.logEnd(
+ StatsLogManager.LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_WORKSPACE_LOADER_ASYNC,
+ 120
+ )
+
+ assertThat(underTest.startTimeByEvent.size()).isEqualTo(2)
+ assertThat(
+ underTest.startTimeByEvent.get(
+ StatsLogManager.LauncherLatencyEvent
+ .LAUNCHER_LATENCY_STARTUP_WORKSPACE_LOADER_ASYNC
+ .id
+ )
+ )
+ .isEqualTo(111)
+ }
+
+ @Test
+ @UiThreadTest
+ fun loadStartOfWorkspace_thenEndWithSync_logSyncStart() {
+ underTest
+ .logStart(
+ StatsLogManager.LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_TOTAL_DURATION,
+ 100
+ )
+ .logWorkspaceLoadStartTime(111)
+
+ underTest.logEnd(
+ StatsLogManager.LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_WORKSPACE_LOADER_SYNC,
+ 120
+ )
+
+ assertThat(underTest.startTimeByEvent.size()).isEqualTo(2)
+ assertThat(
+ underTest.startTimeByEvent.get(
+ StatsLogManager.LauncherLatencyEvent
+ .LAUNCHER_LATENCY_STARTUP_WORKSPACE_LOADER_SYNC
+ .id
+ )
+ )
+ .isEqualTo(111)
+ }
+
+ @Test
+ @UiThreadTest
+ fun loadStartOfWorkspaceLoadSync_thenAsync_asyncNotLogged() {
+ underTest
+ .logStart(
+ StatsLogManager.LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_TOTAL_DURATION,
+ 100
+ )
+ .logStart(
+ StatsLogManager.LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_WORKSPACE_LOADER_SYNC,
+ 110
+ )
+
+ underTest.logStart(
+ StatsLogManager.LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_WORKSPACE_LOADER_ASYNC,
+ 111
+ )
+
+ assertThat(underTest.startTimeByEvent.size()).isEqualTo(2)
+ assertThat(
+ underTest.startTimeByEvent.get(
+ StatsLogManager.LauncherLatencyEvent
+ .LAUNCHER_LATENCY_STARTUP_WORKSPACE_LOADER_SYNC
+ .id
+ )
+ )
+ .isEqualTo(110)
+ assertThat(
+ underTest.startTimeByEvent.get(
+ StatsLogManager.LauncherLatencyEvent
+ .LAUNCHER_LATENCY_STARTUP_WORKSPACE_LOADER_ASYNC
+ .id
+ )
+ )
+ .isEqualTo(0)
+ }
+
+ @Test
+ @UiThreadTest
+ fun loadStartOfWorkspaceLoadAsync_thenSync_syncNotLogged() {
+ underTest.logStart(
+ StatsLogManager.LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_TOTAL_DURATION,
+ 100
+ )
+ underTest.logStart(
+ StatsLogManager.LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_WORKSPACE_LOADER_ASYNC,
+ 111
+ )
+
+ underTest.logStart(
+ StatsLogManager.LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_WORKSPACE_LOADER_SYNC,
+ 112
+ )
+
+ assertThat(underTest.startTimeByEvent.size()).isEqualTo(2)
+ assertThat(
+ underTest.startTimeByEvent.get(
+ StatsLogManager.LauncherLatencyEvent
+ .LAUNCHER_LATENCY_STARTUP_WORKSPACE_LOADER_ASYNC
+ .id
+ )
+ )
+ .isEqualTo(111)
+ assertThat(
+ underTest.startTimeByEvent.get(
+ StatsLogManager.LauncherLatencyEvent
+ .LAUNCHER_LATENCY_STARTUP_WORKSPACE_LOADER_SYNC
+ .id
+ )
+ )
+ .isEqualTo(0)
+ }
+
+ @Test
+ @UiThreadTest
+ fun logEndOfEvent_withoutStartEvent_notLogged() {
+ underTest.logStart(
+ StatsLogManager.LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_TOTAL_DURATION,
+ 100
+ )
+
+ underTest.logEnd(
+ StatsLogManager.LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_WORKSPACE_LOADER_SYNC,
+ 120
+ )
+
+ assertThat(underTest.endTimeByEvent.size()).isEqualTo(0)
+ assertThat(
+ underTest.endTimeByEvent.get(
+ StatsLogManager.LauncherLatencyEvent
+ .LAUNCHER_LATENCY_STARTUP_WORKSPACE_LOADER_SYNC
+ .id
+ )
+ )
+ .isEqualTo(0)
+ }
+
+ @Test
+ @UiThreadTest
+ fun logEndOfEvent_afterEndOfTotalDuration_notLogged() {
+ underTest
+ .logStart(
+ StatsLogManager.LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_TOTAL_DURATION,
+ 100
+ )
+ .logEnd(
+ StatsLogManager.LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_TOTAL_DURATION,
+ 120
+ )
+
+ underTest.logEnd(
+ StatsLogManager.LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_WORKSPACE_LOADER_SYNC,
+ 121
+ )
+
+ assertThat(underTest.endTimeByEvent.size()).isEqualTo(1)
+ assertThat(
+ underTest.endTimeByEvent.get(
+ StatsLogManager.LauncherLatencyEvent
+ .LAUNCHER_LATENCY_STARTUP_WORKSPACE_LOADER_SYNC
+ .id
+ )
+ )
+ .isEqualTo(0)
+ }
+
+ @Test
+ @UiThreadTest
+ fun logCardinality_setCardinality() {
+ underTest.logCardinality(-1)
+ underTest.logStart(
+ StatsLogManager.LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_TOTAL_DURATION,
+ 100
+ )
+
+ underTest.logCardinality(235)
+
+ assertThat(underTest.cardinality).isEqualTo(235)
+ }
+
+ @Test
+ @UiThreadTest
+ fun reset_clearState() {
+ underTest
+ .logStart(
+ StatsLogManager.LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_TOTAL_DURATION,
+ 100
+ )
+ .logStart(
+ StatsLogManager.LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_ACTIVITY_ON_CREATE,
+ 100
+ )
+ .logStart(
+ StatsLogManager.LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_VIEW_INFLATION,
+ 110
+ )
+ .logEnd(
+ StatsLogManager.LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_VIEW_INFLATION,
+ 115
+ )
+ .logWorkspaceLoadStartTime(120)
+ .logCardinality(235)
+ .logEnd(
+ StatsLogManager.LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_ACTIVITY_ON_CREATE,
+ 100
+ )
+ .logEnd(
+ StatsLogManager.LauncherLatencyEvent
+ .LAUNCHER_LATENCY_STARTUP_WORKSPACE_LOADER_ASYNC,
+ 140
+ )
+ .logEnd(
+ StatsLogManager.LauncherLatencyEvent.LAUNCHER_LATENCY_STARTUP_TOTAL_DURATION,
+ 160
+ )
+ assertThat(underTest.startTimeByEvent.size()).isEqualTo(4)
+ assertThat(underTest.endTimeByEvent.size()).isEqualTo(4)
+ assertThat(underTest.cardinality).isEqualTo(235)
+
+ underTest.reset()
+
+ assertThat(underTest.startTimeByEvent.isEmpty()).isTrue()
+ assertThat(underTest.endTimeByEvent.isEmpty()).isTrue()
+ assertThat(underTest.cardinality).isEqualTo(StartupLatencyLogger.UNSET_INT)
+ assertThat(underTest.workspaceLoadStartTime).isEqualTo(StartupLatencyLogger.UNSET_LONG)
+ }
+}
diff --git a/tests/src/com/android/launcher3/model/ModelMultiCallbacksTest.java b/tests/src/com/android/launcher3/model/ModelMultiCallbacksTest.java
index 42c9f11..b9da16a 100644
--- a/tests/src/com/android/launcher3/model/ModelMultiCallbacksTest.java
+++ b/tests/src/com/android/launcher3/model/ModelMultiCallbacksTest.java
@@ -180,7 +180,8 @@
}
@Override
- public void onInitialBindComplete(IntSet boundPages, RunnableList pendingTasks) {
+ public void onInitialBindComplete(IntSet boundPages, RunnableList pendingTasks,
+ int workspaceItemCount, boolean isBindSync) {
mPageBoundSync = boundPages;
mPendingTasks = pendingTasks;
}