diff --git a/firebase-perf/dev-app/src/main/AndroidManifest.xml b/firebase-perf/dev-app/src/main/AndroidManifest.xml index 643b50fb03e..c225f4fb472 100644 --- a/firebase-perf/dev-app/src/main/AndroidManifest.xml +++ b/firebase-perf/dev-app/src/main/AndroidManifest.xml @@ -38,6 +38,9 @@ + metadataValue = getMetadataBoolean(config); + if (metadataValue.isAvailable()) { + return metadataValue.get(); + } + + // 2. Reads value from Firebase Remote Config, saves this value in cache layer if valid. + Optional rcValue = getRemoteConfigBoolean(config); + if (rcValue.isAvailable()) { + deviceCacheManager.setValue(config.getDeviceCacheFlag(), rcValue.get()); + return rcValue.get(); + } + + // 3. Reads value from cache layer. + Optional deviceCacheValue = getDeviceCacheBoolean(config); + if (deviceCacheValue.isAvailable()) { + return deviceCacheValue.get(); + } + + // 4. Returns default value if there is no valid value from above approaches. + return config.getDefault(); + } + // endregion // Helper functions for interaction with Metadata layer. diff --git a/firebase-perf/src/main/java/com/google/firebase/perf/config/ConfigurationConstants.java b/firebase-perf/src/main/java/com/google/firebase/perf/config/ConfigurationConstants.java index f14ba7c71a0..145935db505 100644 --- a/firebase-perf/src/main/java/com/google/firebase/perf/config/ConfigurationConstants.java +++ b/firebase-perf/src/main/java/com/google/firebase/perf/config/ConfigurationConstants.java @@ -661,4 +661,39 @@ protected String getMetadataFlag() { return "fragment_sampling_percentage"; } } + + protected static final class ExperimentTTID extends ConfigurationFlag { + private static ExperimentTTID instance; + + private ExperimentTTID() { + super(); + } + + protected static synchronized ExperimentTTID getInstance() { + if (instance == null) { + instance = new ExperimentTTID(); + } + return instance; + } + + @Override + protected Boolean getDefault() { + return false; + } + + @Override + protected String getRemoteConfigFlag() { + return "fpr_experiment_app_start_ttid"; + } + + @Override + protected String getDeviceCacheFlag() { + return "com.google.firebase.perf.ExperimentTTID"; + } + + @Override + protected String getMetadataFlag() { + return "experiment_app_start_ttid"; + } + } } diff --git a/firebase-perf/src/main/java/com/google/firebase/perf/config/RemoteConfigManager.java b/firebase-perf/src/main/java/com/google/firebase/perf/config/RemoteConfigManager.java index 0986e123c16..7c27b59c3d9 100644 --- a/firebase-perf/src/main/java/com/google/firebase/perf/config/RemoteConfigManager.java +++ b/firebase-perf/src/main/java/com/google/firebase/perf/config/RemoteConfigManager.java @@ -14,6 +14,8 @@ package com.google.firebase.perf.config; +import static com.google.firebase.perf.config.ConfigurationConstants.ExperimentTTID; + import android.content.Context; import android.content.pm.PackageInfo; import android.content.pm.PackageManager.NameNotFoundException; @@ -53,6 +55,7 @@ public class RemoteConfigManager { private static final long MIN_APP_START_CONFIG_FETCH_DELAY_MS = 5000; private static final int RANDOM_APP_START_CONFIG_FETCH_DELAY_MS = 25000; + private final DeviceCacheManager cache; private final ConcurrentHashMap allRcConfigMap; private final Executor executor; private final long appStartTimeInMs; @@ -65,29 +68,25 @@ public class RemoteConfigManager { private RemoteConfigManager() { this( + DeviceCacheManager.getInstance(), new ThreadPoolExecutor( /* corePoolSize= */ 0, /* maximumPoolSize= */ 1, /* keepAliveTime= */ 0L, TimeUnit.SECONDS, new LinkedBlockingQueue()), - /* firebaseRemoteConfig= */ null // set once FirebaseRemoteConfig is initialized - ); - } - - RemoteConfigManager(Executor executor, FirebaseRemoteConfig firebaseRemoteConfig) { - this( - executor, - firebaseRemoteConfig, + /* firebaseRemoteConfig= */ null, // set once FirebaseRemoteConfig is initialized MIN_APP_START_CONFIG_FETCH_DELAY_MS + new Random().nextInt(RANDOM_APP_START_CONFIG_FETCH_DELAY_MS)); } @VisibleForTesting RemoteConfigManager( + DeviceCacheManager cache, Executor executor, FirebaseRemoteConfig firebaseRemoteConfig, long appStartConfigFetchDelayInMs) { + this.cache = cache; this.executor = executor; this.firebaseRemoteConfig = firebaseRemoteConfig; this.allRcConfigMap = @@ -315,7 +314,7 @@ private void triggerRemoteConfigFetchIfNecessary() { return; } if (allRcConfigMap.isEmpty()) { // Initial fetch. - syncConfigValues(firebaseRemoteConfig.getAll()); + allRcConfigMap.putAll(firebaseRemoteConfig.getAll()); } if (shouldFetchAndActivateRemoteConfigValues()) { triggerFirebaseRemoteConfigFetchAndActivateOnSuccessfulFetch(); @@ -342,6 +341,21 @@ protected void syncConfigValues(Map newlyFetc allRcConfigMap.remove(existingKey); } } + + // TODO: remove after experiment is over and experiment RC flag is no longer needed + // Save ExperimentTTID flag to device cache upon successful RC fetchAndActivate, because reading + // is done quite early and it is possible that RC isn't initialized yet. + ExperimentTTID flag = ExperimentTTID.getInstance(); + FirebaseRemoteConfigValue rcValue = allRcConfigMap.get(flag.getRemoteConfigFlag()); + if (rcValue != null) { + try { + cache.setValue(flag.getDeviceCacheFlag(), rcValue.asBoolean()); + } catch (Exception exception) { + logger.debug("ExperimentTTID remote config flag has invalid value, expected boolean."); + } + } else { + logger.debug("ExperimentTTID remote config flag does not exist."); + } } @VisibleForTesting diff --git a/firebase-perf/src/main/java/com/google/firebase/perf/metrics/AppStartTrace.java b/firebase-perf/src/main/java/com/google/firebase/perf/metrics/AppStartTrace.java index 3aa363e1338..2e1bb5cd8d3 100644 --- a/firebase-perf/src/main/java/com/google/firebase/perf/metrics/AppStartTrace.java +++ b/firebase-perf/src/main/java/com/google/firebase/perf/metrics/AppStartTrace.java @@ -18,11 +18,15 @@ import android.app.Application; import android.app.Application.ActivityLifecycleCallbacks; import android.content.Context; +import android.os.Build; import android.os.Bundle; +import android.os.Process; +import android.view.View; import androidx.annotation.Keep; import androidx.annotation.NonNull; import androidx.annotation.Nullable; import com.google.android.gms.common.util.VisibleForTesting; +import com.google.firebase.perf.config.ConfigResolver; import com.google.firebase.perf.logging.AndroidLogger; import com.google.firebase.perf.provider.FirebasePerfProvider; import com.google.firebase.perf.session.PerfSession; @@ -30,6 +34,7 @@ import com.google.firebase.perf.transport.TransportManager; import com.google.firebase.perf.util.Clock; import com.google.firebase.perf.util.Constants; +import com.google.firebase.perf.util.FirstDrawDoneListener; import com.google.firebase.perf.util.Timer; import com.google.firebase.perf.v1.ApplicationProcessState; import com.google.firebase.perf.v1.TraceMetric; @@ -69,6 +74,7 @@ public class AppStartTrace implements ActivityLifecycleCallbacks { private boolean isRegisteredForLifecycleCallbacks = false; private final TransportManager transportManager; private final Clock clock; + private final ConfigResolver configResolver; private Context appContext; /** * The first time onCreate() of any activity is called, the activity is saved as launchActivity. @@ -89,6 +95,7 @@ public class AppStartTrace implements ActivityLifecycleCallbacks { private Timer onCreateTime = null; private Timer onStartTime = null; private Timer onResumeTime = null; + private Timer firstDrawDone = null; private PerfSession startSession; private boolean isStartedFromBackground = false; @@ -134,12 +141,13 @@ static AppStartTrace getInstance(TransportManager transportManager, Clock clock) new AppStartTrace( transportManager, clock, + ConfigResolver.getInstance(), new ThreadPoolExecutor( CORE_POOL_SIZE, MAX_POOL_SIZE, /* keepAliveTime= */ MAX_LATENCY_BEFORE_UI_INIT + 10, TimeUnit.SECONDS, - new LinkedBlockingQueue<>(1))); + new LinkedBlockingQueue<>())); } } } @@ -149,9 +157,11 @@ static AppStartTrace getInstance(TransportManager transportManager, Clock clock) AppStartTrace( @NonNull TransportManager transportManager, @NonNull Clock clock, + @NonNull ConfigResolver configResolver, @NonNull ExecutorService executorService) { this.transportManager = transportManager; this.clock = clock; + this.configResolver = configResolver; this.executorService = executorService; } @@ -178,6 +188,33 @@ public synchronized void unregisterActivityLifecycleCallbacks() { isRegisteredForLifecycleCallbacks = false; } + /** + * Gets the timetamp that marks the beginning of app start, currently defined as the beginning of + * BIND_APPLICATION. Fallback to class-load time of {@link FirebasePerfProvider} when API < 24. + * + * @return {@link Timer} at the beginning of app start by Fireperf definition. + */ + private static Timer getStartTimer() { + if (Build.VERSION.SDK_INT >= Build.VERSION_CODES.N) { + return Timer.ofElapsedRealtime(Process.getStartElapsedRealtime()); + } + return FirebasePerfProvider.getAppStartTime(); + } + + private void recordFirstDrawDone() { + if (firstDrawDone != null) { + return; + } + this.firstDrawDone = clock.getTime(); + executorService.execute( + () -> this.logColdStart(getStartTimer(), this.firstDrawDone, this.startSession)); + + if (isRegisteredForLifecycleCallbacks) { + // After AppStart trace is queued to be logged, we can unregister this callback. + unregisterActivityLifecycleCallbacks(); + } + } + @Override public synchronized void onActivityCreated(Activity activity, Bundle savedInstanceState) { if (isStartedFromBackground || onCreateTime != null // An activity already called onCreate() @@ -206,9 +243,18 @@ public synchronized void onActivityStarted(Activity activity) { @Override public synchronized void onActivityResumed(Activity activity) { - if (isStartedFromBackground - || onResumeTime != null // An activity already called onResume() - || isTooLateToInitUI) { + if (isStartedFromBackground || isTooLateToInitUI) { + return; + } + + // Shadow-launch experiment of new app start time + final boolean isExperimentTTIDEnabled = configResolver.getIsExperimentTTIDEnabled(); + if (isExperimentTTIDEnabled) { + View rootView = activity.findViewById(android.R.id.content); + FirstDrawDoneListener.registerForNextDraw(rootView, this::recordFirstDrawDone); + } + + if (onResumeTime != null) { // An activity already called onResume() return; } @@ -228,12 +274,30 @@ public synchronized void onActivityResumed(Activity activity) { // Log the app start trace in a non-main thread. executorService.execute(this::logAppStartTrace); - if (isRegisteredForLifecycleCallbacks) { + if (!isExperimentTTIDEnabled && isRegisteredForLifecycleCallbacks) { // After AppStart trace is logged, we can unregister this callback. unregisterActivityLifecycleCallbacks(); } } + private void logColdStart(Timer start, Timer end, PerfSession session) { + TraceMetric.Builder metric = + TraceMetric.newBuilder() + .setName("_experiment_app_start_ttid") + .setClientStartTimeUs(start.getMicros()) + .setDurationUs(start.getDurationMicros(end)); + + TraceMetric.Builder subtrace = + TraceMetric.newBuilder() + .setName("_experiment_classLoadTime") + .setClientStartTimeUs(FirebasePerfProvider.getAppStartTime().getMicros()) + .setDurationUs(FirebasePerfProvider.getAppStartTime().getDurationMicros(end)); + + metric.addSubtraces(subtrace).addPerfSessions(this.startSession.build()); + + transportManager.log(metric.build(), ApplicationProcessState.FOREGROUND_BACKGROUND); + } + private void logAppStartTrace() { TraceMetric.Builder metric = TraceMetric.newBuilder() diff --git a/firebase-perf/src/test/java/com/google/firebase/perf/config/RemoteConfigManagerTest.java b/firebase-perf/src/test/java/com/google/firebase/perf/config/RemoteConfigManagerTest.java index 9855d3cfe62..af1b971d9a1 100644 --- a/firebase-perf/src/test/java/com/google/firebase/perf/config/RemoteConfigManagerTest.java +++ b/firebase-perf/src/test/java/com/google/firebase/perf/config/RemoteConfigManagerTest.java @@ -25,6 +25,7 @@ import androidx.annotation.NonNull; import com.google.android.gms.tasks.Task; import com.google.android.gms.tasks.TaskCompletionSource; +import com.google.common.util.concurrent.MoreExecutors; import com.google.firebase.inject.Provider; import com.google.firebase.perf.FirebasePerformanceTestBase; import com.google.firebase.perf.provider.FirebasePerfProvider; @@ -48,11 +49,16 @@ public final class RemoteConfigManagerTest extends FirebasePerformanceTestBase { private static final String FIREPERF_FRC_NAMESPACE_NAME = "fireperf"; + private static final FirebaseRemoteConfigValue TRUE_VALUE = + new RemoteConfigValueImplForTest("true"); + private static final FirebaseRemoteConfigValue FALSE_VALUE = + new RemoteConfigValueImplForTest("false"); @Mock private FirebaseRemoteConfig mockFirebaseRemoteConfig; @Mock private RemoteConfigComponent mockFirebaseRemoteConfigComponent; @Mock private Provider mockFirebaseRemoteConfigProvider; + private DeviceCacheManager cacheManager; private FakeScheduledExecutorService fakeExecutor; @Before @@ -60,6 +66,8 @@ public void setUp() { initMocks(this); fakeExecutor = new FakeScheduledExecutorService(); + // DeviceCacheManager initialization requires immediate blocking task execution in its executor + cacheManager = new DeviceCacheManager(MoreExecutors.newDirectExecutorService()); when(mockFirebaseRemoteConfigProvider.get()).thenReturn(mockFirebaseRemoteConfigComponent); when(mockFirebaseRemoteConfigComponent.get(FIREPERF_FRC_NAMESPACE_NAME)) @@ -230,6 +238,29 @@ public void getString_validFrcValue_updatesWithNewValue() { assertThat(testRemoteConfigManager.getString("some_key3").isAvailable()).isFalse(); } + @Test + public void syncConfigValues_savesNewlyFetchedValueToDeviceCache() { + Map configs = new HashMap<>(); + ConfigurationConstants.ExperimentTTID flag = + ConfigurationConstants.ExperimentTTID.getInstance(); + configs.put(flag.getRemoteConfigFlag(), TRUE_VALUE); + RemoteConfigManager testRemoteConfigManager = setupTestRemoteConfigManager(configs); + + assertThat(cacheManager.getBoolean(flag.getDeviceCacheFlag()).isAvailable()).isFalse(); + + configs.put(flag.getRemoteConfigFlag(), FALSE_VALUE); + testRemoteConfigManager.syncConfigValues(configs); + + assertThat(cacheManager.getBoolean(flag.getDeviceCacheFlag()).isAvailable()).isTrue(); + assertThat(cacheManager.getBoolean(flag.getDeviceCacheFlag()).get()).isFalse(); + + configs.put(flag.getRemoteConfigFlag(), TRUE_VALUE); + testRemoteConfigManager.syncConfigValues(configs); + + assertThat(cacheManager.getBoolean(flag.getDeviceCacheFlag()).isAvailable()).isTrue(); + assertThat(cacheManager.getBoolean(flag.getDeviceCacheFlag()).get()).isTrue(); + } + @Test public void getRemoteConfigValueOrDefaultLong_invalidFrcValue_returnsDefaultValue() { Map configs = createDefaultRcConfigMap(); @@ -889,10 +920,13 @@ private RemoteConfigManager setupTestRemoteConfigManager( when(mockFirebaseRemoteConfig.getAll()).thenReturn(configs); if (initializeFrc) { return new RemoteConfigManager( - fakeExecutor, mockFirebaseRemoteConfig, appStartConfigFetchDelayInMs); + cacheManager, fakeExecutor, mockFirebaseRemoteConfig, appStartConfigFetchDelayInMs); } else { return new RemoteConfigManager( - fakeExecutor, /* firebaseRemoteConfig= */ null, appStartConfigFetchDelayInMs); + cacheManager, + fakeExecutor, + /* firebaseRemoteConfig= */ null, + appStartConfigFetchDelayInMs); } } diff --git a/firebase-perf/src/test/java/com/google/firebase/perf/metrics/AppStartTraceTest.java b/firebase-perf/src/test/java/com/google/firebase/perf/metrics/AppStartTraceTest.java index c1f975754e5..e705a145aed 100644 --- a/firebase-perf/src/test/java/com/google/firebase/perf/metrics/AppStartTraceTest.java +++ b/firebase-perf/src/test/java/com/google/firebase/perf/metrics/AppStartTraceTest.java @@ -14,19 +14,27 @@ package com.google.firebase.perf.metrics; +import static com.google.common.truth.Truth.assertThat; import static com.google.firebase.perf.util.TimerTest.getElapsedRealtimeMicros; +import static org.mockito.ArgumentMatchers.isA; import static org.mockito.Mockito.doAnswer; import static org.mockito.Mockito.mock; import static org.mockito.Mockito.times; import static org.mockito.Mockito.verify; import static org.mockito.Mockito.when; import static org.mockito.MockitoAnnotations.initMocks; +import static org.robolectric.Shadows.shadowOf; import android.app.Activity; import android.content.pm.ProviderInfo; import android.os.Bundle; +import android.os.Looper; +import android.os.Process; +import android.os.SystemClock; +import android.view.View; import androidx.test.core.app.ApplicationProvider; import com.google.firebase.perf.FirebasePerformanceTestBase; +import com.google.firebase.perf.config.ConfigResolver; import com.google.firebase.perf.provider.FirebasePerfProvider; import com.google.firebase.perf.session.SessionManager; import com.google.firebase.perf.transport.TransportManager; @@ -36,6 +44,7 @@ import com.google.firebase.perf.v1.ApplicationProcessState; import com.google.firebase.perf.v1.TraceMetric; import com.google.testing.timing.FakeScheduledExecutorService; +import java.time.Duration; import java.util.concurrent.TimeUnit; import org.junit.After; import org.junit.Assert; @@ -48,13 +57,18 @@ import org.mockito.invocation.InvocationOnMock; import org.mockito.stubbing.Answer; import org.robolectric.RobolectricTestRunner; +import org.robolectric.annotation.Config; +import org.robolectric.annotation.LooperMode; +import org.robolectric.shadows.ShadowSystemClock; /** Unit tests for {@link AppStartTrace}. */ @RunWith(RobolectricTestRunner.class) +@LooperMode(LooperMode.Mode.PAUSED) public class AppStartTraceTest extends FirebasePerformanceTestBase { @Mock private Clock clock; @Mock private TransportManager transportManager; + @Mock private ConfigResolver configResolver; @Mock private Activity activity1; @Mock private Activity activity2; @Mock private Bundle bundle; @@ -94,7 +108,8 @@ public void reset() { @Test public void testLaunchActivity() { FakeScheduledExecutorService fakeExecutorService = new FakeScheduledExecutorService(); - AppStartTrace trace = new AppStartTrace(transportManager, clock, fakeExecutorService); + AppStartTrace trace = + new AppStartTrace(transportManager, clock, configResolver, fakeExecutorService); // first activity goes through onCreate()->onStart()->onResume() state change. currentTime = 1; trace.onActivityCreated(activity1, bundle); @@ -171,7 +186,8 @@ private void verifyFinalState( @Test public void testInterleavedActivity() { FakeScheduledExecutorService fakeExecutorService = new FakeScheduledExecutorService(); - AppStartTrace trace = new AppStartTrace(transportManager, clock, fakeExecutorService); + AppStartTrace trace = + new AppStartTrace(transportManager, clock, configResolver, fakeExecutorService); // first activity onCreate() currentTime = 1; trace.onActivityCreated(activity1, bundle); @@ -206,7 +222,8 @@ public void testInterleavedActivity() { @Test public void testDelayedAppStart() { FakeScheduledExecutorService fakeExecutorService = new FakeScheduledExecutorService(); - AppStartTrace trace = new AppStartTrace(transportManager, clock, fakeExecutorService); + AppStartTrace trace = + new AppStartTrace(transportManager, clock, configResolver, fakeExecutorService); // Delays activity creation after 1 minute from app start time. currentTime = appStart.getMicros() + TimeUnit.MINUTES.toMicros(1) + 1; trace.onActivityCreated(activity1, bundle); @@ -227,7 +244,8 @@ public void testDelayedAppStart() { @Test public void testStartFromBackground() { FakeScheduledExecutorService fakeExecutorService = new FakeScheduledExecutorService(); - AppStartTrace trace = new AppStartTrace(transportManager, clock, fakeExecutorService); + AppStartTrace trace = + new AppStartTrace(transportManager, clock, configResolver, fakeExecutorService); trace.setIsStartFromBackground(); trace.onActivityCreated(activity1, bundle); Assert.assertNull(trace.getOnCreateTime()); @@ -261,4 +279,43 @@ public void testFirebasePerfProviderOnAttachInfo_initializesGaugeCollection() { Assert.assertEquals(oldSessionId, SessionManager.getInstance().perfSession().sessionId()); verify(mockPerfSession, times(2)).isGaugeAndEventCollectionEnabled(); } + + @Test + @Config(sdk = 26) + public void timeToInitialDisplay_isLogged() { + // Test setup + when(clock.getTime()).thenCallRealMethod(); // Use robolectric shadows to manipulate time + View testView = new View(ApplicationProvider.getApplicationContext()); + when(activity1.findViewById(android.R.id.content)).thenReturn(testView); + when(configResolver.getIsExperimentTTIDEnabled()).thenReturn(true); + FakeScheduledExecutorService fakeExecutorService = new FakeScheduledExecutorService(); + AppStartTrace trace = + new AppStartTrace(transportManager, clock, configResolver, fakeExecutorService); + + // Simulate resume and manually stepping time forward + ShadowSystemClock.advanceBy(Duration.ofMillis(1000)); + long resumeTime = TimeUnit.NANOSECONDS.toMicros(SystemClock.elapsedRealtimeNanos()); + trace.onActivityCreated(activity1, bundle); + trace.onActivityStarted(activity1); + trace.onActivityResumed(activity1); + fakeExecutorService.runAll(); + verify(transportManager, times(1)) + .log(isA(TraceMetric.class), isA(ApplicationProcessState.class)); + + // Simulate draw and manually stepping time forward + ShadowSystemClock.advanceBy(Duration.ofMillis(1000)); + long drawTime = TimeUnit.NANOSECONDS.toMicros(SystemClock.elapsedRealtimeNanos()); + testView.getViewTreeObserver().dispatchOnDraw(); + shadowOf(Looper.getMainLooper()).idle(); + fakeExecutorService.runNext(); + verify(transportManager, times(2)) + .log(traceArgumentCaptor.capture(), isA(ApplicationProcessState.class)); + + // Verify ttid trace is being logged + TraceMetric ttid = traceArgumentCaptor.getValue(); + long appStartTime = TimeUnit.MILLISECONDS.toMicros(Process.getStartElapsedRealtime()); + assertThat(ttid.getName()).isEqualTo("_experiment_app_start_ttid"); + assertThat(ttid.getDurationUs()).isNotEqualTo(resumeTime - appStartTime); + assertThat(ttid.getDurationUs()).isEqualTo(drawTime - appStartTime); + } }