ref(android): Measure ANR thresholds on the monotonic clock (JAVA-579)

The watchdog took its readings from an ICurrentDateProvider lambda over
SystemClock.uptimeMillis(). The type named no clock, so a call site could
not tell what it was measuring, and the arithmetic -- now minus the last
tick, compared against a threshold -- was spelled out inline.

MonotonicClock and Deadline replace both: the clock is a named type, and
the watchdog asks the question it actually cares about, which is whether
the main thread has missed its window.

The clock counts deep sleep, which uptimeMillis() did not, so a suspend
between posting the ticker and checking it now looks like a missed
window. It cannot fabricate an ANR: the watchdog reports only once
ActivityManager confirms the process is NOT_RESPONDING, and on resume the
main thread runs the ticker that is already queued.

Author: runningcode

sentry-android-core/src/main/java/io/sentry/android/core/ANRWatchDog.java

@@ -30,11 +30,13 @@
 import android.app.ActivityManager;
 import android.content.Context;
 import android.os.Debug;
-import android.os.SystemClock;
 import io.sentry.ILogger;
 import io.sentry.SentryLevel;
-import io.sentry.transport.ICurrentDateProvider;
+import io.sentry.android.core.internal.time.AndroidMonotonicClock;
+import io.sentry.time.Deadline;
+import io.sentry.time.MonotonicClock;
 import java.util.List;
+import java.util.concurrent.TimeUnit;
 import java.util.concurrent.atomic.AtomicBoolean;
 import org.jetbrains.annotations.NotNull;
 import org.jetbrains.annotations.TestOnly;
@@ -46,15 +48,17 @@ final class ANRWatchDog extends Thread {
   private final boolean reportInDebug;
   private final ANRListener anrListener;
   private final MainLooperHandler uiHandler;
-  private final ICurrentDateProvider timeProvider;
+  private final MonotonicClock clock;
 
   /** the interval in which we check if there's an ANR, in ms */
   private long pollingIntervalMs;
 
   private final long timeoutIntervalMillis;
   private final @NotNull ILogger logger;
 
-  private volatile long lastKnownActiveUiTimestampMs = 0;
+  /** How long the main thread has left to run the ticker before we call it an ANR. */
+  private volatile @NotNull Deadline uiResponsiveUntil;
+
   private final AtomicBoolean reported = new AtomicBoolean(false);
 
   private final @NotNull Context context;
@@ -68,10 +72,8 @@ final class ANRWatchDog extends Thread {
       @NotNull ANRListener listener,
       @NotNull ILogger logger,
       final @NotNull Context context) {
-    // avoid method refs on Android due to some issues with older AGP setups
-    // noinspection Convert2MethodRef
     this(
-        () -> SystemClock.uptimeMillis(),
+        AndroidMonotonicClock.getInstance(),
         timeoutIntervalMillis,
         500,
         reportInDebug,
@@ -83,7 +85,7 @@ final class ANRWatchDog extends Thread {
 
   @TestOnly
   ANRWatchDog(
-      @NotNull final ICurrentDateProvider timeProvider,
+      @NotNull final MonotonicClock clock,
       long timeoutIntervalMillis,
       long pollingIntervalMillis,
       boolean reportInDebug,
@@ -94,17 +96,18 @@ final class ANRWatchDog extends Thread {
 
     super("|ANR-WatchDog|");
 
-    this.timeProvider = timeProvider;
+    this.clock = clock;
     this.timeoutIntervalMillis = timeoutIntervalMillis;
     this.pollingIntervalMs = pollingIntervalMillis;
     this.reportInDebug = reportInDebug;
     this.anrListener = listener;
     this.logger = logger;
     this.uiHandler = uiHandler;
     this.context = context;
+    this.uiResponsiveUntil = Deadline.after(clock, timeoutIntervalMillis, TimeUnit.MILLISECONDS);
     this.ticker =
         () -> {
-          lastKnownActiveUiTimestampMs = timeProvider.getCurrentTimeMillis();
+          uiResponsiveUntil = Deadline.after(clock, timeoutIntervalMillis, TimeUnit.MILLISECONDS);
           reported.set(false);
         };
 
@@ -140,11 +143,8 @@ public void run() {
         return;
       }
 
-      final long unresponsiveDurationMs =
-          timeProvider.getCurrentTimeMillis() - lastKnownActiveUiTimestampMs;
-
       // If the main thread has not handled ticker, it is blocked. ANR.
-      if (unresponsiveDurationMs > timeoutIntervalMillis) {
+      if (uiResponsiveUntil.hasPassed()) {
         if (!reportInDebug && (Debug.isDebuggerConnected() || Debug.waitingForDebugger())) {
           logger.log(
               SentryLevel.DEBUG,

sentry-android-core/src/test/java/io/sentry/android/core/ANRWatchDogTest.kt

@@ -4,10 +4,11 @@ import android.app.ActivityManager
 import android.app.ActivityManager.ProcessErrorStateInfo.NOT_RESPONDING
 import android.app.ActivityManager.ProcessErrorStateInfo.NO_ERROR
 import android.content.Context
-import io.sentry.transport.ICurrentDateProvider
+import io.sentry.time.TestMonotonicClock
 import java.util.concurrent.CountDownLatch
 import java.util.concurrent.Executors
 import java.util.concurrent.TimeUnit
+import java.util.concurrent.TimeUnit.MILLISECONDS
 import kotlin.test.Test
 import kotlin.test.assertEquals
 import kotlin.test.assertNotNull
@@ -20,12 +21,12 @@ import org.mockito.kotlin.mock
 import org.mockito.kotlin.whenever
 
 class ANRWatchDogTest {
-  private var currentTimeMs = 0L
-  private val timeProvider = ICurrentDateProvider { currentTimeMs }
+  private lateinit var clock: TestMonotonicClock
 
   @Before
   fun `setup`() {
-    currentTimeMs = 12341234
+    // an arbitrary, non-zero origin: no caller may assume a tick counts from zero
+    clock = TestMonotonicClock(MILLISECONDS.toNanos(12341234))
   }
 
   @Test
@@ -42,8 +43,7 @@ class ANRWatchDogTest {
     whenever(handler.thread).thenReturn(thread)
     val interval = 10L
 
-    val sut =
-      ANRWatchDog(timeProvider, interval, 1L, true, { a -> anr = a }, mock(), handler, mock())
+    val sut = ANRWatchDog(clock, interval, 1L, true, { a -> anr = a }, mock(), handler, mock())
     val es = Executors.newSingleThreadExecutor()
     try {
       es.submit { sut.run() }
@@ -53,7 +53,7 @@ class ANRWatchDogTest {
       ) // Wait until worker posts the job for the "UI thread"
       var waitCount = 0
       do {
-        currentTimeMs += 100L
+        clock.advance(100, MILLISECONDS)
         Thread.sleep(100) // Let worker realize this is ANR
       } while (anr == null && waitCount++ < 100)
 
@@ -79,15 +79,14 @@ class ANRWatchDogTest {
     whenever(handler.thread).thenReturn(thread)
     val interval = 10L
 
-    val sut =
-      ANRWatchDog(timeProvider, interval, 1L, true, { a -> anr = a }, mock(), handler, mock())
+    val sut = ANRWatchDog(clock, interval, 1L, true, { a -> anr = a }, mock(), handler, mock())
     val es = Executors.newSingleThreadExecutor()
     try {
       es.submit { sut.run() }
 
       var waitCount = 0
       do {
-        currentTimeMs += 100L
+        clock.advance(100, MILLISECONDS)
         Thread.sleep(100) // Let worker realize his runner always runs
       } while (!invoked && waitCount++ < 100)
 
@@ -121,8 +120,7 @@ class ANRWatchDogTest {
     val anrs = listOf(stateInfo)
     whenever(am.processesInErrorState).thenReturn(anrs)
 
-    val sut =
-      ANRWatchDog(timeProvider, interval, 1L, true, { a -> anr = a }, mock(), handler, context)
+    val sut = ANRWatchDog(clock, interval, 1L, true, { a -> anr = a }, mock(), handler, context)
     val es = Executors.newSingleThreadExecutor()
     try {
       es.submit { sut.run() }
@@ -132,7 +130,7 @@ class ANRWatchDogTest {
       ) // Wait until worker posts the job for the "UI thread"
       var waitCount = 0
       do {
-        currentTimeMs += 100L
+        clock.advance(100, MILLISECONDS)
         Thread.sleep(100) // Let worker realize this is ANR
       } while (anr == null && waitCount++ < 100)
 
@@ -167,8 +165,7 @@ class ANRWatchDogTest {
     val anrs = listOf(stateInfo)
     whenever(am.processesInErrorState).thenReturn(anrs)
 
-    val sut =
-      ANRWatchDog(timeProvider, interval, 1L, true, { a -> anr = a }, mock(), handler, context)
+    val sut = ANRWatchDog(clock, interval, 1L, true, { a -> anr = a }, mock(), handler, context)
     val es = Executors.newSingleThreadExecutor()
     try {
       es.submit { sut.run() }
@@ -178,7 +175,7 @@ class ANRWatchDogTest {
       ) // Wait until worker posts the job for the "UI thread"
       var waitCount = 0
       do {
-        currentTimeMs += 100L
+        clock.advance(100, MILLISECONDS)
         Thread.sleep(100L) // Let worker realize this is ANR
       } while (anr == null && waitCount++ < 100)
       assertNull(anr) // callback never ran
@@ -187,4 +184,31 @@ class ANRWatchDogTest {
       es.shutdown()
     }
   }
+
+  @Test
+  fun `a device suspend does not trip the ANR threshold`() {
+    // The uptime clock stands still while the device is suspended, so a suspend cannot be mistaken
+    // for a blocked main thread. On an elapsed-real-time clock the suspended interval would count
+    // against the main thread and fabricate an ANR.
+    var anr: ApplicationNotResponding? = null
+    val handler = mock<MainLooperHandler>()
+    val latch = CountDownLatch(1)
+    whenever(handler.post(any())).then { latch.countDown() }
+    whenever(handler.thread).thenReturn(mock<Thread>())
+
+    // context is a mock, so ActivityManager is absent and any passed deadline reports an ANR
+    val sut = ANRWatchDog(clock, 10L, 1L, true, { a -> anr = a }, mock(), handler, mock())
+    val es = Executors.newSingleThreadExecutor()
+    try {
+      es.submit { sut.run() }
+
+      assertTrue(latch.await(10L, TimeUnit.SECONDS)) // wait until the watchdog is polling
+      Thread.sleep(200) // hundreds of polls of wall time, none of it uptime
+
+      assertNull(anr)
+    } finally {
+      sut.interrupt()
+      es.shutdown()
+    }
+  }
 }