From bbc346bd7a09abed0da55111aacfd98eac75608e Mon Sep 17 00:00:00 2001 From: Greyson Parrelli Date: Wed, 6 Jan 2021 15:31:33 -0500 Subject: [PATCH] Create a system for scheduling work post-initial-render. --- .../securesms/ApplicationContext.java | 73 ++++----- .../thoughtcrime/securesms/BaseActivity.java | 3 + .../thoughtcrime/securesms/MainActivity.java | 2 + .../securesms/PassphraseRequiredActivity.java | 3 + .../ConversationListFragment.java | 18 +++ .../securesms/util/AppStartup.java | 141 ++++++++++++++++-- 6 files changed, 192 insertions(+), 48 deletions(-) diff --git a/app/src/main/java/org/thoughtcrime/securesms/ApplicationContext.java b/app/src/main/java/org/thoughtcrime/securesms/ApplicationContext.java index b5804463f..deab6fd58 100644 --- a/app/src/main/java/org/thoughtcrime/securesms/ApplicationContext.java +++ b/app/src/main/java/org/thoughtcrime/securesms/ApplicationContext.java @@ -114,6 +114,7 @@ public class ApplicationContext extends MultiDexApplication implements DefaultLi @Override public void onCreate() { Tracer.getInstance().start("Application#onCreate()"); + AppStartup.getInstance().onApplicationCreate(); long startTime = System.currentTimeMillis(); @@ -123,42 +124,42 @@ public class ApplicationContext extends MultiDexApplication implements DefaultLi super.onCreate(); - new AppStartup().addBlocking("security-provider", this::initializeSecurityProvider) - .addBlocking("logging", () -> { - initializeLogging(); - Log.i(TAG, "onCreate()"); - }) - .addBlocking("crash-handling", this::initializeCrashHandling) - .addBlocking("eat-db", () -> DatabaseFactory.getInstance(this)) - .addBlocking("app-dependencies", this::initializeAppDependencies) - .addBlocking("first-launch", this::initializeFirstEverAppLaunch) - .addBlocking("app-migrations", this::initializeApplicationMigrations) - .addBlocking("ring-rtc", this::initializeRingRtc) - .addBlocking("mark-registration", () -> RegistrationUtil.maybeMarkRegistrationComplete(this)) - .addBlocking("lifecycle-observer", () -> ProcessLifecycleOwner.get().getLifecycle().addObserver(this)) - .addBlocking("dynamic-theme", () -> DynamicTheme.setDefaultDayNightMode(this)) - .addBlocking("vector-compat", () -> { - if (Build.VERSION.SDK_INT < 21) { - AppCompatDelegate.setCompatVectorFromResourcesEnabled(true); - } - }) - .addDeferred(this::initializeMessageRetrieval) - .addDeferred(this::initializeExpiringMessageManager) - .addDeferred(this::initializeRevealableMessageManager) - .addDeferred(this::initializeGcmCheck) - .addDeferred(this::initializeSignedPreKeyCheck) - .addDeferred(this::initializePeriodicTasks) - .addDeferred(this::initializeCircumvention) - .addDeferred(this::initializePendingMessages) - .addDeferred(this::initializeBlobProvider) - .addDeferred(this::initializeCleanup) - .addDeferred(this::initializeGlideCodecs) - .addDeferred(FeatureFlags::init) - .addDeferred(() -> NotificationChannels.create(this)) - .addDeferred(RefreshPreKeysJob::scheduleIfNecessary) - .addDeferred(StorageSyncHelper::scheduleRoutineSync) - .addDeferred(() -> ApplicationDependencies.getJobManager().beginJobLoop()) - .execute(); + AppStartup.getInstance().addBlocking("security-provider", this::initializeSecurityProvider) + .addBlocking("logging", () -> { + initializeLogging(); + Log.i(TAG, "onCreate()"); + }) + .addBlocking("crash-handling", this::initializeCrashHandling) + .addBlocking("eat-db", () -> DatabaseFactory.getInstance(this)) + .addBlocking("app-dependencies", this::initializeAppDependencies) + .addBlocking("first-launch", this::initializeFirstEverAppLaunch) + .addBlocking("app-migrations", this::initializeApplicationMigrations) + .addBlocking("ring-rtc", this::initializeRingRtc) + .addBlocking("mark-registration", () -> RegistrationUtil.maybeMarkRegistrationComplete(this)) + .addBlocking("lifecycle-observer", () -> ProcessLifecycleOwner.get().getLifecycle().addObserver(this)) + .addBlocking("dynamic-theme", () -> DynamicTheme.setDefaultDayNightMode(this)) + .addBlocking("vector-compat", () -> { + if (Build.VERSION.SDK_INT < 21) { + AppCompatDelegate.setCompatVectorFromResourcesEnabled(true); + } + }) + .addNonBlocking(this::initializeMessageRetrieval) + .addNonBlocking(this::initializeRevealableMessageManager) + .addNonBlocking(this::initializeGcmCheck) + .addNonBlocking(this::initializeSignedPreKeyCheck) + .addNonBlocking(this::initializePeriodicTasks) + .addNonBlocking(this::initializeCircumvention) + .addNonBlocking(this::initializePendingMessages) + .addNonBlocking(this::initializeCleanup) + .addNonBlocking(this::initializeGlideCodecs) + .addNonBlocking(FeatureFlags::init) + .addNonBlocking(RefreshPreKeysJob::scheduleIfNecessary) + .addNonBlocking(StorageSyncHelper::scheduleRoutineSync) + .addNonBlocking(() -> ApplicationDependencies.getJobManager().beginJobLoop()) + .addPostRender(this::initializeExpiringMessageManager) + .addPostRender(this::initializeBlobProvider) + .addPostRender(() -> NotificationChannels.create(this)) + .execute(); Log.d(TAG, "onCreate() took " + (System.currentTimeMillis() - startTime) + " ms"); Tracer.getInstance().end("Application#onCreate()"); diff --git a/app/src/main/java/org/thoughtcrime/securesms/BaseActivity.java b/app/src/main/java/org/thoughtcrime/securesms/BaseActivity.java index 4227e19e5..de9dc2534 100644 --- a/app/src/main/java/org/thoughtcrime/securesms/BaseActivity.java +++ b/app/src/main/java/org/thoughtcrime/securesms/BaseActivity.java @@ -16,6 +16,7 @@ import androidx.core.app.ActivityOptionsCompat; import org.signal.core.util.logging.Log; import org.thoughtcrime.securesms.dependencies.ApplicationDependencies; +import org.thoughtcrime.securesms.util.AppStartup; import org.thoughtcrime.securesms.util.ConfigurationUtil; import org.thoughtcrime.securesms.util.TextSecurePreferences; import org.thoughtcrime.securesms.util.dynamiclanguage.DynamicLanguageContextWrapper; @@ -32,8 +33,10 @@ public abstract class BaseActivity extends AppCompatActivity { @Override protected void onCreate(Bundle savedInstanceState) { + AppStartup.getInstance().onCriticalRenderEventStart(); logEvent("onCreate()"); super.onCreate(savedInstanceState); + AppStartup.getInstance().onCriticalRenderEventEnd(); } @Override diff --git a/app/src/main/java/org/thoughtcrime/securesms/MainActivity.java b/app/src/main/java/org/thoughtcrime/securesms/MainActivity.java index 2dcf7549e..311ddb641 100644 --- a/app/src/main/java/org/thoughtcrime/securesms/MainActivity.java +++ b/app/src/main/java/org/thoughtcrime/securesms/MainActivity.java @@ -9,6 +9,7 @@ import android.os.Bundle; import androidx.annotation.NonNull; import androidx.annotation.Nullable; +import org.thoughtcrime.securesms.util.AppStartup; import org.thoughtcrime.securesms.util.CachedInflater; import org.thoughtcrime.securesms.util.CommunicationActions; import org.thoughtcrime.securesms.util.DynamicNoActionBarTheme; @@ -33,6 +34,7 @@ public class MainActivity extends PassphraseRequiredActivity { @Override protected void onCreate(Bundle savedInstanceState, boolean ready) { + AppStartup.getInstance().onCriticalRenderEventStart(); super.onCreate(savedInstanceState, ready); setContentView(R.layout.main_activity); diff --git a/app/src/main/java/org/thoughtcrime/securesms/PassphraseRequiredActivity.java b/app/src/main/java/org/thoughtcrime/securesms/PassphraseRequiredActivity.java index 0e9dd8cfe..8b0fa7c6d 100644 --- a/app/src/main/java/org/thoughtcrime/securesms/PassphraseRequiredActivity.java +++ b/app/src/main/java/org/thoughtcrime/securesms/PassphraseRequiredActivity.java @@ -26,6 +26,7 @@ import org.thoughtcrime.securesms.push.SignalServiceNetworkAccess; import org.thoughtcrime.securesms.recipients.Recipient; import org.thoughtcrime.securesms.registration.RegistrationNavigationActivity; import org.thoughtcrime.securesms.service.KeyCachingService; +import org.thoughtcrime.securesms.util.AppStartup; import org.thoughtcrime.securesms.util.TextSecurePreferences; import java.util.Locale; @@ -51,6 +52,7 @@ public abstract class PassphraseRequiredActivity extends BaseActivity implements @Override protected final void onCreate(Bundle savedInstanceState) { Tracer.getInstance().start(Log.tag(getClass()) + "#onCreate()"); + AppStartup.getInstance().onCriticalRenderEventStart(); this.networkAccess = new SignalServiceNetworkAccess(this); onPreCreate(); @@ -64,6 +66,7 @@ public abstract class PassphraseRequiredActivity extends BaseActivity implements onCreate(savedInstanceState, true); } + AppStartup.getInstance().onCriticalRenderEventEnd(); Tracer.getInstance().end(Log.tag(getClass()) + "#onCreate()"); } diff --git a/app/src/main/java/org/thoughtcrime/securesms/conversationlist/ConversationListFragment.java b/app/src/main/java/org/thoughtcrime/securesms/conversationlist/ConversationListFragment.java index 7d458588c..44c8f9b00 100644 --- a/app/src/main/java/org/thoughtcrime/securesms/conversationlist/ConversationListFragment.java +++ b/app/src/main/java/org/thoughtcrime/securesms/conversationlist/ConversationListFragment.java @@ -116,11 +116,13 @@ import org.thoughtcrime.securesms.recipients.Recipient; import org.thoughtcrime.securesms.service.KeyCachingService; import org.thoughtcrime.securesms.sms.MessageSender; import org.thoughtcrime.securesms.storage.StorageSyncHelper; +import org.thoughtcrime.securesms.util.AppStartup; import org.thoughtcrime.securesms.util.AvatarUtil; import org.thoughtcrime.securesms.util.PlayStoreUtil; import org.thoughtcrime.securesms.util.ServiceUtil; import org.thoughtcrime.securesms.util.SnapToTopDataObserver; import org.thoughtcrime.securesms.util.StickyHeaderDecoration; +import org.thoughtcrime.securesms.util.Stopwatch; import org.thoughtcrime.securesms.util.TextSecurePreferences; import org.thoughtcrime.securesms.util.Util; import org.thoughtcrime.securesms.util.ViewUtil; @@ -180,6 +182,8 @@ public class ConversationListFragment extends MainFragment implements ActionMode private Drawable archiveDrawable; private LifecycleObserver visibilityLifecycleObserver; + private Stopwatch startupStopwatch; + public static ConversationListFragment newInstance() { return new ConversationListFragment(); } @@ -188,6 +192,7 @@ public class ConversationListFragment extends MainFragment implements ActionMode public void onCreate(Bundle icicle) { super.onCreate(icicle); setHasOptionsMenu(true); + startupStopwatch = new Stopwatch("startup"); } @Override @@ -488,6 +493,19 @@ public class ConversationListFragment extends MainFragment implements ActionMode searchAdapterDecoration = new StickyHeaderDecoration(searchAdapter, false, false); setAdapter(defaultAdapter); + + defaultAdapter.registerAdapterDataObserver(new RecyclerView.AdapterDataObserver() { + @Override + public void onItemRangeInserted(int positionStart, int itemCount) { + startupStopwatch.split("data-set"); + defaultAdapter.unregisterAdapterDataObserver(this); + list.post(() -> { + AppStartup.getInstance().onCriticalRenderEventEnd(); + startupStopwatch.split("first-render"); + startupStopwatch.stop(TAG); + }); + } + }); } @SuppressWarnings("rawtypes") diff --git a/app/src/main/java/org/thoughtcrime/securesms/util/AppStartup.java b/app/src/main/java/org/thoughtcrime/securesms/util/AppStartup.java index 1d5ac649b..55c12d123 100644 --- a/app/src/main/java/org/thoughtcrime/securesms/util/AppStartup.java +++ b/app/src/main/java/org/thoughtcrime/securesms/util/AppStartup.java @@ -1,5 +1,10 @@ package org.thoughtcrime.securesms.util; +import android.app.Application; +import android.os.Handler; +import android.os.Looper; + +import androidx.annotation.MainThread; import androidx.annotation.NonNull; import org.signal.core.util.concurrent.SignalExecutors; @@ -8,30 +13,128 @@ import org.signal.core.util.logging.Log; import java.util.LinkedList; import java.util.List; +/** + * Manages our app startup flow. + */ public final class AppStartup { + /** The time to wait after Application#onCreate() to see if any UI rendering starts */ + private final long UI_WAIT_TIME = 500; + + /** The maximum amount of time we'll wait for critical rendering events to finish. */ + private final long FAILSAFE_RENDER_TIME = 2500; + private static final String TAG = Log.tag(AppStartup.class); - private final List blocking; - private final List deferred; + private static final AppStartup INSTANCE = new AppStartup(); - public AppStartup() { - this.blocking = new LinkedList<>(); - this.deferred = new LinkedList<>(); + private final List blocking; + private final List nonBlocking; + private final List postRender; + private final Handler postRenderHandler; + + private int outstandingCriticalRenderEvents; + + private long applicationStartTime; + private long renderStartTime; + private long renderEndTime; + + public static @NonNull AppStartup getInstance() { + return INSTANCE; } - public @NonNull - AppStartup addBlocking(@NonNull String name, @NonNull Runnable task) { + private AppStartup() { + this.blocking = new LinkedList<>(); + this.nonBlocking = new LinkedList<>(); + this.postRender = new LinkedList<>(); + this.postRenderHandler = new Handler(Looper.getMainLooper()); + } + + public void onApplicationCreate() { + this.applicationStartTime = System.currentTimeMillis(); + } + + /** + * Schedules a task that must happen during app startup in a blocking fashion. + */ + @MainThread + public @NonNull AppStartup addBlocking(@NonNull String name, @NonNull Runnable task) { blocking.add(new Task(name, task)); return this; } - public @NonNull - AppStartup addDeferred(@NonNull Runnable task) { - deferred.add(new Task("", task)); + /** + * Schedules a task that should not block app startup, but should still happen as quickly as + * possible. + */ + @MainThread + public @NonNull AppStartup addNonBlocking(@NonNull Runnable task) { + nonBlocking.add(new Task("", task)); return this; } + /** + * Schedules a task that should only be executed after all critical UI has been rendered. If no + * UI will be shown (i.e. the Application was created in the background), this will simply happen + * a short delay after {@link Application#onCreate()}. + * @param task + * @return + */ + @MainThread + public @NonNull AppStartup addPostRender(@NonNull Runnable task) { + postRender.add(new Task("", task)); + return this; + } + + /** + * Indicates a UI event critical to initial rendering has started. This will delay tasks that were + * scheduled via {@link #addPostRender(Runnable)}. You MUST call + * {@link #onCriticalRenderEventEnd()} for each invocation of this method. + */ + @MainThread + public void onCriticalRenderEventStart() { + if (outstandingCriticalRenderEvents == 0 && postRender.size() > 0) { + Log.i(TAG, "Received first critical render event."); + renderStartTime = System.currentTimeMillis(); + + postRenderHandler.removeCallbacksAndMessages(null); + postRenderHandler.postDelayed(() -> { + Log.w(TAG, "Reached the failsafe event for post-render! Either someone forgot to call #onRenderEnd(), the activity was started while the phone was locked, or app start is taking a very long time."); + executePostRender(); + }, FAILSAFE_RENDER_TIME); + } + + outstandingCriticalRenderEvents++; + } + + /** + * Indicates a UI event critical to initial rendering has ended. Should only be paired with + * {@link #onCriticalRenderEventStart()}. + */ + @MainThread + public void onCriticalRenderEventEnd() { + if (outstandingCriticalRenderEvents <= 0) { + Log.w(TAG, "Too many end events! onCriticalRenderEventStart/End was mismanaged."); + } + + outstandingCriticalRenderEvents = Math.max(outstandingCriticalRenderEvents - 1, 0); + + if (outstandingCriticalRenderEvents == 0 && postRender.size() > 0) { + renderEndTime = System.currentTimeMillis(); + + Log.i(TAG, "First render has finished. " + + "Cold Start: " + (renderEndTime - applicationStartTime) + " ms, " + + "Render Time: " + (renderEndTime - renderStartTime) + " ms"); + + postRenderHandler.removeCallbacksAndMessages(null); + executePostRender(); + } + } + + /** + * Begins all pending task execution. + */ + @MainThread public void execute() { Stopwatch stopwatch = new Stopwatch("init"); @@ -39,13 +142,27 @@ public final class AppStartup { task.getRunnable().run(); stopwatch.split(task.getName()); } + blocking.clear(); - for (Task task : deferred) { + for (Task task : nonBlocking) { SignalExecutors.BOUNDED.execute(task.getRunnable()); } + nonBlocking.clear(); - stopwatch.split("schedule-deferred"); + stopwatch.split("schedule-non-blocking"); stopwatch.stop(TAG); + + postRenderHandler.postDelayed(() -> { + Log.i(TAG, "Assuming the application has started in the background. Running post-render tasks."); + executePostRender(); + }, UI_WAIT_TIME); + } + + private void executePostRender() { + for (Task task : postRender) { + SignalExecutors.BOUNDED.execute(task.getRunnable()); + } + postRender.clear(); } private class Task {