diff --git a/src/org/thoughtcrime/securesms/ApplicationContext.java b/src/org/thoughtcrime/securesms/ApplicationContext.java index 232714471a..2b26dff9bd 100644 --- a/src/org/thoughtcrime/securesms/ApplicationContext.java +++ b/src/org/thoughtcrime/securesms/ApplicationContext.java @@ -45,7 +45,6 @@ import org.thoughtcrime.securesms.insights.InsightsOptOut; import org.thoughtcrime.securesms.jobmanager.JobManager; import org.thoughtcrime.securesms.jobs.CreateSignedPreKeyJob; import org.thoughtcrime.securesms.jobs.FcmRefreshJob; -import org.thoughtcrime.securesms.jobs.StorageSyncJob; import org.thoughtcrime.securesms.jobs.MultiDeviceContactUpdateJob; import org.thoughtcrime.securesms.jobs.PushNotificationReceiveJob; import org.thoughtcrime.securesms.logging.AndroidLogger; @@ -69,6 +68,7 @@ import org.thoughtcrime.securesms.revealable.ViewOnceMessageManager; import org.thoughtcrime.securesms.service.RotateSenderCertificateListener; import org.thoughtcrime.securesms.service.RotateSignedPreKeyListener; import org.thoughtcrime.securesms.service.UpdateApkRefreshListener; +import org.thoughtcrime.securesms.util.FrameRateTracker; import org.thoughtcrime.securesms.util.TextSecurePreferences; import org.thoughtcrime.securesms.util.dynamiclanguage.DynamicLanguageContextWrapper; import org.webrtc.voiceengine.WebRtcAudioManager; @@ -145,6 +145,7 @@ public class ApplicationContext extends MultiDexApplication implements DefaultLi ApplicationDependencies.getRecipientCache().warmUp(); executePendingContactSync(); KeyCachingService.onAppForegrounded(this); + ApplicationDependencies.getFrameRateTracker().begin(); } @Override @@ -153,6 +154,7 @@ public class ApplicationContext extends MultiDexApplication implements DefaultLi Log.i(TAG, "App is no longer visible."); KeyCachingService.onAppBackgrounded(this); MessageNotifier.setVisibleThread(-1); + ApplicationDependencies.getFrameRateTracker().end(); } public ExpiringMessageManager getExpiringMessageManager() { diff --git a/src/org/thoughtcrime/securesms/dependencies/ApplicationDependencies.java b/src/org/thoughtcrime/securesms/dependencies/ApplicationDependencies.java index 5e79330919..a3b790ec20 100644 --- a/src/org/thoughtcrime/securesms/dependencies/ApplicationDependencies.java +++ b/src/org/thoughtcrime/securesms/dependencies/ApplicationDependencies.java @@ -12,6 +12,7 @@ import org.thoughtcrime.securesms.push.SignalServiceNetworkAccess; import org.thoughtcrime.securesms.recipients.LiveRecipientCache; import org.thoughtcrime.securesms.service.IncomingMessageObserver; import org.thoughtcrime.securesms.util.FeatureFlags; +import org.thoughtcrime.securesms.util.FrameRateTracker; import org.thoughtcrime.securesms.util.IasKeyStore; import org.thoughtcrime.securesms.util.TextSecurePreferences; import org.whispersystems.signalservice.api.KeyBackupService; @@ -39,6 +40,7 @@ public class ApplicationDependencies { private static MessageRetriever messageRetriever; private static LiveRecipientCache recipientCache; private static JobManager jobManager; + private static FrameRateTracker frameRateTracker; public static synchronized void init(@NonNull Application application, @NonNull Provider provider) { if (ApplicationDependencies.application != null || ApplicationDependencies.provider != null) { @@ -145,6 +147,16 @@ public class ApplicationDependencies { return jobManager; } + public static synchronized @NonNull FrameRateTracker getFrameRateTracker() { + assertInitialization(); + + if (frameRateTracker == null) { + frameRateTracker = provider.provideFrameRateTracker(); + } + + return frameRateTracker; + } + private static void assertInitialization() { if (application == null || provider == null) { throw new UninitializedException(); @@ -160,6 +172,7 @@ public class ApplicationDependencies { @NonNull MessageRetriever provideMessageRetriever(); @NonNull LiveRecipientCache provideRecipientCache(); @NonNull JobManager provideJobManager(); + @NonNull FrameRateTracker provideFrameRateTracker(); } private static class UninitializedException extends IllegalStateException { diff --git a/src/org/thoughtcrime/securesms/dependencies/ApplicationDependencyProvider.java b/src/org/thoughtcrime/securesms/dependencies/ApplicationDependencyProvider.java index 37027136c4..15b87b4a01 100644 --- a/src/org/thoughtcrime/securesms/dependencies/ApplicationDependencyProvider.java +++ b/src/org/thoughtcrime/securesms/dependencies/ApplicationDependencyProvider.java @@ -24,6 +24,7 @@ import org.thoughtcrime.securesms.push.SignalServiceNetworkAccess; import org.thoughtcrime.securesms.recipients.LiveRecipientCache; import org.thoughtcrime.securesms.service.IncomingMessageObserver; import org.thoughtcrime.securesms.util.AlarmSleepTimer; +import org.thoughtcrime.securesms.util.FrameRateTracker; import org.thoughtcrime.securesms.util.TextSecurePreferences; import org.whispersystems.libsignal.util.guava.Optional; import org.whispersystems.signalservice.api.SignalServiceAccountManager; @@ -113,6 +114,11 @@ public class ApplicationDependencyProvider implements ApplicationDependencies.Pr .build()); } + @Override + public @NonNull FrameRateTracker provideFrameRateTracker() { + return new FrameRateTracker(context); + } + private static class DynamicCredentialsProvider implements CredentialsProvider { private final Context context; diff --git a/src/org/thoughtcrime/securesms/logsubmit/SubmitLogFragment.java b/src/org/thoughtcrime/securesms/logsubmit/SubmitLogFragment.java index 945fd318a2..7eaa1dd130 100644 --- a/src/org/thoughtcrime/securesms/logsubmit/SubmitLogFragment.java +++ b/src/org/thoughtcrime/securesms/logsubmit/SubmitLogFragment.java @@ -61,6 +61,7 @@ import org.thoughtcrime.securesms.dependencies.ApplicationDependencies; import org.thoughtcrime.securesms.logging.Log; import org.thoughtcrime.securesms.logsubmit.util.Scrubber; import org.thoughtcrime.securesms.util.BucketInfo; +import org.thoughtcrime.securesms.util.FrameRateTracker; import org.thoughtcrime.securesms.util.TextSecurePreferences; import org.thoughtcrime.securesms.util.Util; import org.thoughtcrime.securesms.util.task.ProgressDialogAsyncTask; @@ -545,6 +546,8 @@ public class SubmitLogFragment extends Fragment { builder.append("Memory : ").append(getMemoryUsage(context)).append("\n"); builder.append("Memclass : ").append(getMemoryClass(context)).append("\n"); builder.append("OS Host : ").append(Build.HOST).append("\n"); + builder.append("Refresh Rate : ").append(String.format(Locale.ENGLISH, "%.2f", FrameRateTracker.getDisplayRefreshRate(context))).append(" hz").append("\n"); + builder.append("Average FPS : ").append(String.format(Locale.ENGLISH, "%.2f", ApplicationDependencies.getFrameRateTracker().getRunningAverageFps())).append("\n"); builder.append("First Version: ").append(TextSecurePreferences.getFirstInstallVersion(context)).append("\n"); builder.append("App : "); try { diff --git a/src/org/thoughtcrime/securesms/util/FrameRateTracker.java b/src/org/thoughtcrime/securesms/util/FrameRateTracker.java new file mode 100644 index 0000000000..ed0d8ba00a --- /dev/null +++ b/src/org/thoughtcrime/securesms/util/FrameRateTracker.java @@ -0,0 +1,192 @@ +package org.thoughtcrime.securesms.util; + +import android.content.Context; +import android.view.Choreographer; +import android.view.Display; +import androidx.annotation.NonNull; + +import org.thoughtcrime.securesms.logging.Log; + +import java.util.ArrayDeque; +import java.util.ArrayList; +import java.util.List; +import java.util.Locale; +import java.util.concurrent.TimeUnit; + +/** + * Tracks the frame rate of the app and logs when things are bad. + * + * In general, whenever alterations are made here, the author should be very cautious to do as + * little work as possible, because we don't want the tracker itself to impact the frame rate. + */ +public class FrameRateTracker { + + private static final String TAG = Log.tag(FrameRateTracker.class); + + private static final long REPORTING_INTERVAL = TimeUnit.SECONDS.toMillis(1); + + private static final int MAX_CONSECUTIVE_FRAME_LOGS = 10; + private static final int MAX_CONSECUTIVE_INTERVAL_LOGS = 10; + + private final Context context; + private final List fpsData; + private final RingBuffer runningAverageFps; + + private double refreshRate; + private long idealTimePerFrameNanos; + private long badFrameThresholdNanos; + private double badIntervalThresholdFps; + + private long lastFrameTimeNanos; + private long lastReportTimeNanos; + + private long consecutiveFrameWarnings; + private long consecutiveIntervalWarnings; + + public FrameRateTracker(@NonNull Context context) { + this.context = context; + this.fpsData = new ArrayList<>(); + this.runningAverageFps = new RingBuffer(TimeUnit.SECONDS.toMillis(10)); + + updateRefreshRate(); + } + + public void begin() { + Log.d(TAG, String.format(Locale.ENGLISH, "Beginning frame rate tracking. Screen refresh rate: %.2f hz, or %.2f ms per frame.", refreshRate, idealTimePerFrameNanos / (float) 1_000_000)); + + lastFrameTimeNanos = System.nanoTime(); + lastReportTimeNanos = System.nanoTime(); + + Choreographer.getInstance().postFrameCallback(calculator); + Choreographer.getInstance().postFrameCallbackDelayed(reporter, 1000); + } + + public void end() { + Choreographer.getInstance().removeFrameCallback(calculator); + Choreographer.getInstance().removeFrameCallback(reporter); + + fpsData.clear(); + runningAverageFps.clear(); + } + + public double getRunningAverageFps() { + return runningAverageFps.getAverage(); + } + + /** + * The natural screen refresh rate, in hertz. May not always return the same value if a display + * has a dynamic refresh rate. + */ + public static float getDisplayRefreshRate(@NonNull Context context) { + Display display = ServiceUtil.getWindowManager(context).getDefaultDisplay(); + return display.getRefreshRate(); + } + + /** + * Displays with dynamic refresh rates may change their reported refresh rate over time. + */ + private void updateRefreshRate() { + double newRefreshRate = getDisplayRefreshRate(context); + + if (this.refreshRate != newRefreshRate) { + if (this.refreshRate > 0) { + Log.d(TAG, String.format(Locale.ENGLISH, "Refresh rate changed from %.2f hz to %.2f hz", refreshRate, newRefreshRate)); + } + + this.refreshRate = getDisplayRefreshRate(context); + this.idealTimePerFrameNanos = (long) (TimeUnit.SECONDS.toNanos(1) / refreshRate); + this.badFrameThresholdNanos = idealTimePerFrameNanos * (int) (refreshRate / 4); + this.badIntervalThresholdFps = refreshRate / 2; + } + } + + private final Choreographer.FrameCallback calculator = new Choreographer.FrameCallback() { + @Override + public void doFrame(long frameTimeNanos) { + long elapsedNanos = frameTimeNanos - lastFrameTimeNanos; + double fps = TimeUnit.SECONDS.toNanos(1) / (double) elapsedNanos; + + if (elapsedNanos > badFrameThresholdNanos) { + if (consecutiveFrameWarnings < MAX_CONSECUTIVE_FRAME_LOGS) { + long droppedFrames = elapsedNanos / idealTimePerFrameNanos; + Log.w(TAG, String.format(Locale.ENGLISH, "Bad frame! Took %d ms (%d dropped frames, or %.2f FPS)", TimeUnit.NANOSECONDS.toMillis(elapsedNanos), droppedFrames, fps)); + consecutiveFrameWarnings++; + } + } else { + consecutiveFrameWarnings = 0; + } + + fpsData.add(fps); + runningAverageFps.add(fps); + + lastFrameTimeNanos = frameTimeNanos; + Choreographer.getInstance().postFrameCallback(this); + } + }; + + private final Choreographer.FrameCallback reporter = new Choreographer.FrameCallback() { + @Override + public void doFrame(long frameTimeNanos) { + double averageFps = 0; + int size = fpsData.size(); + + for (double fps : fpsData) { + averageFps += fps / size; + } + + if (averageFps < badIntervalThresholdFps) { + if (consecutiveIntervalWarnings < MAX_CONSECUTIVE_INTERVAL_LOGS) { + Log.w(TAG, String.format(Locale.ENGLISH, "Bad interval! Average of %.2f FPS over the last %d ms", averageFps, TimeUnit.NANOSECONDS.toMillis(frameTimeNanos - lastReportTimeNanos))); + consecutiveIntervalWarnings++; + } + } else { + consecutiveIntervalWarnings = 0; + } + + lastReportTimeNanos = frameTimeNanos; + updateRefreshRate(); + Choreographer.getInstance().postFrameCallbackDelayed(this, REPORTING_INTERVAL); + } + }; + + private static class RingBuffer { + private final long interval; + private final ArrayDeque timestamps; + private final ArrayDeque elements; + + RingBuffer(long interval) { + this.interval = interval; + this.timestamps = new ArrayDeque<>(); + this.elements = new ArrayDeque<>(); + } + + void add(double value) { + long currentTime = System.currentTimeMillis(); + + while (!timestamps.isEmpty() && timestamps.getFirst() < (currentTime - interval)) { + timestamps.pollFirst(); + elements.pollFirst(); + } + + timestamps.addLast(currentTime); + elements.addLast(value); + } + + double getAverage() { + List elementsCopy = new ArrayList<>(elements); + double average = 0; + int size = elementsCopy.size(); + + for (double element : elementsCopy) { + average += element / size; + } + + return average; + } + + void clear() { + timestamps.clear(); + elements.clear(); + } + } +}