Skip to content

Commit 39d2b47

Browse files
runningcoderunningcode
committed
ref(android): Measure ANR profiling thresholds on the uptime clock (JAVA-579)
Same reasoning as the watchdog: the suspicion and ANR thresholds must not count time the device spent suspended. The clock is now injected rather than read from SystemClock, so the tests drive it directly instead of going through Robolectric's shadow clock.
1 parent 61bcca3 commit 39d2b47

2 files changed

Lines changed: 37 additions & 21 deletions

File tree

‎sentry-android-core/src/main/java/io/sentry/android/core/anr/AnrProfilingIntegration.java‎

Lines changed: 24 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -4,7 +4,6 @@
44

55
import android.os.Handler;
66
import android.os.Looper;
7-
import android.os.SystemClock;
87
import io.sentry.ILogger;
98
import io.sentry.IScopes;
109
import io.sentry.ISentryLifecycleToken;
@@ -14,12 +13,16 @@
1413
import io.sentry.SentryOptions;
1514
import io.sentry.android.core.AppState;
1615
import io.sentry.android.core.SentryAndroidOptions;
16+
import io.sentry.time.JavaUptimeClock;
17+
import io.sentry.time.Stopwatch;
18+
import io.sentry.time.UptimeClock;
1719
import io.sentry.util.AutoClosableReentrantLock;
1820
import io.sentry.util.Objects;
1921
import io.sentry.util.SentryRandom;
2022
import java.io.Closeable;
2123
import java.io.File;
2224
import java.io.IOException;
25+
import java.util.concurrent.TimeUnit;
2326
import java.util.concurrent.atomic.AtomicBoolean;
2427
import java.util.concurrent.atomic.AtomicInteger;
2528
import org.jetbrains.annotations.ApiStatus;
@@ -36,12 +39,13 @@ public class AnrProfilingIntegration
3639
static final int MAX_NUM_STACKS = (int) (10_000 / POLLING_INTERVAL_MS);
3740

3841
private final AtomicBoolean enabled = new AtomicBoolean(true);
39-
private final Runnable updater = () -> lastMainThreadExecutionTime = SystemClock.uptimeMillis();
42+
private final @NotNull UptimeClock clock;
43+
private final @NotNull Runnable updater;
4044
private final @NotNull AutoClosableReentrantLock lifecycleLock = new AutoClosableReentrantLock();
4145
private final @NotNull AutoClosableReentrantLock profileManagerLock =
4246
new AutoClosableReentrantLock();
4347

44-
private volatile long lastMainThreadExecutionTime = SystemClock.uptimeMillis();
48+
private volatile long lastMainThreadExecutionNanos;
4549
final AtomicInteger numCollectedStacks = new AtomicInteger();
4650
private volatile MainThreadState mainThreadState = MainThreadState.IDLE;
4751
private volatile @Nullable AnrProfileManager profileManager;
@@ -53,6 +57,17 @@ public class AnrProfilingIntegration
5357
private volatile @Nullable Handler mainHandler;
5458
private volatile @Nullable Thread mainThread;
5559

60+
public AnrProfilingIntegration() {
61+
this(JavaUptimeClock.getInstance());
62+
}
63+
64+
@TestOnly
65+
AnrProfilingIntegration(final @NotNull UptimeClock clock) {
66+
this.clock = clock;
67+
this.lastMainThreadExecutionNanos = clock.tickNanos();
68+
this.updater = () -> lastMainThreadExecutionNanos = clock.tickNanos();
69+
}
70+
5671
@Override
5772
public void register(final @NotNull IScopes scopes, final @NotNull SentryOptions options) {
5873
this.options =
@@ -204,8 +219,8 @@ public void run() {
204219

205220
@ApiStatus.Internal
206221
protected void checkMainThread(final @NotNull Thread mainThread) throws IOException {
207-
final long now = SystemClock.uptimeMillis();
208-
final long diff = now - lastMainThreadExecutionTime;
222+
final long diff =
223+
TimeUnit.NANOSECONDS.toMillis(clock.tickNanos() - lastMainThreadExecutionNanos);
209224

210225
if (diff < THRESHOLD_SUSPICION_MS) {
211226
mainThreadState = MainThreadState.IDLE;
@@ -234,14 +249,15 @@ protected void checkMainThread(final @NotNull Thread mainThread) throws IOExcept
234249
&& (mainThreadState == MainThreadState.SUSPICIOUS
235250
|| mainThreadState == MainThreadState.ANR_DETECTED)) {
236251
if (numCollectedStacks.get() < MAX_NUM_STACKS) {
237-
final long start = SystemClock.uptimeMillis();
252+
final @NotNull Stopwatch stopwatch = Stopwatch.started(clock);
238253
final @NotNull AnrStackTrace trace =
239254
new AnrStackTrace(System.currentTimeMillis(), mainThread.getStackTrace());
240-
final long duration = SystemClock.uptimeMillis() - start;
241255
if (logger.isEnabled(SentryLevel.DEBUG)) {
242256
logger.log(
243257
SentryLevel.DEBUG,
244-
"AnrWatchdog: capturing main thread stacktrace took " + duration + "ms");
258+
"AnrWatchdog: capturing main thread stacktrace took "
259+
+ stopwatch.elapsed(TimeUnit.MILLISECONDS)
260+
+ "ms");
245261
}
246262
addStackTrace(trace);
247263
} else {

‎sentry-android-core/src/test/java/io/sentry/android/core/anr/AnrProfilingIntegrationTest.kt‎

Lines changed: 13 additions & 13 deletions
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,5 @@
11
package io.sentry.android.core.anr
22

3-
import android.os.SystemClock
43
import androidx.test.ext.junit.runners.AndroidJUnit4
54
import io.sentry.ILogger
65
import io.sentry.IScopes
@@ -9,6 +8,8 @@ import io.sentry.SentryOptions
98
import io.sentry.android.core.AppState
109
import io.sentry.android.core.SentryAndroidOptions
1110
import io.sentry.test.getProperty
11+
import io.sentry.time.TestTicker
12+
import java.util.concurrent.TimeUnit.MILLISECONDS
1213
import kotlin.test.AfterTest
1314
import kotlin.test.BeforeTest
1415
import kotlin.test.Test
@@ -30,9 +31,11 @@ class AnrProfilingIntegrationTest {
3031
private lateinit var mockScopes: IScopes
3132
private lateinit var mockLogger: ILogger
3233
private lateinit var options: SentryAndroidOptions
34+
private lateinit var clock: TestTicker
3335

3436
@BeforeTest
3537
fun setup() {
38+
clock = TestTicker()
3639
mockScopes = mock()
3740
mockLogger = mock()
3841
options =
@@ -163,7 +166,6 @@ class AnrProfilingIntegrationTest {
163166
@Test
164167
fun `properly walks through state transitions and collects stack traces`() {
165168
val mainThread = Thread.currentThread()
166-
SystemClock.setCurrentTimeMillis(1_00)
167169

168170
val androidOptions =
169171
SentryAndroidOptions().apply {
@@ -172,20 +174,20 @@ class AnrProfilingIntegrationTest {
172174
anrProfilingSampleRate = 1.0
173175
}
174176

175-
val integration = AnrProfilingIntegration()
177+
val integration = AnrProfilingIntegration(clock)
176178
integration.register(mockScopes, androidOptions)
177179
// Drive the state machine synchronously to avoid racing the background polling thread.
178180

179-
SystemClock.setCurrentTimeMillis(1_000)
181+
clock.advance(900, MILLISECONDS)
180182
integration.checkMainThread(mainThread)
181183
assertEquals(AnrProfilingIntegration.MainThreadState.IDLE, integration.state)
182184
assertTrue(integration.profileManager.load().stacks.isEmpty())
183185

184-
SystemClock.setCurrentTimeMillis(3_000)
186+
clock.advance(2_000, MILLISECONDS)
185187
integration.checkMainThread(mainThread)
186188
assertEquals(AnrProfilingIntegration.MainThreadState.SUSPICIOUS, integration.state)
187189

188-
SystemClock.setCurrentTimeMillis(6_000)
190+
clock.advance(3_000, MILLISECONDS)
189191
integration.checkMainThread(mainThread)
190192
assertEquals(AnrProfilingIntegration.MainThreadState.ANR_DETECTED, integration.state)
191193
assertEquals(2, integration.profileManager.load().stacks.size)
@@ -199,7 +201,6 @@ class AnrProfilingIntegrationTest {
199201
@Test
200202
fun `background foreground transitions don't trigger an ANR`() {
201203
val mainThread = Thread.currentThread()
202-
SystemClock.setCurrentTimeMillis(1_000)
203204

204205
val androidOptions =
205206
SentryAndroidOptions().apply {
@@ -208,11 +209,11 @@ class AnrProfilingIntegrationTest {
208209
anrProfilingSampleRate = 1.0
209210
}
210211

211-
val integration = AnrProfilingIntegration()
212+
val integration = AnrProfilingIntegration(clock)
212213
integration.register(mockScopes, androidOptions)
213214
integration.onBackground()
214215

215-
SystemClock.setCurrentTimeMillis(20_000)
216+
clock.advance(19_000, MILLISECONDS)
216217
integration.onForeground()
217218

218219
Thread.sleep(100)
@@ -266,7 +267,6 @@ class AnrProfilingIntegrationTest {
266267
@Test
267268
fun `does not collect stacks when sample rate is zero`() {
268269
val mainThread = Thread.currentThread()
269-
SystemClock.setCurrentTimeMillis(1_00)
270270

271271
val androidOptions =
272272
SentryAndroidOptions().apply {
@@ -275,17 +275,17 @@ class AnrProfilingIntegrationTest {
275275
anrProfilingSampleRate = 0.0
276276
}
277277

278-
val integration = AnrProfilingIntegration()
278+
val integration = AnrProfilingIntegration(clock)
279279
integration.register(mockScopes, androidOptions)
280280
integration.onForeground()
281281

282282
// Transition to suspicious
283-
SystemClock.setCurrentTimeMillis(3_000)
283+
clock.advance(2_900, MILLISECONDS)
284284
integration.checkMainThread(mainThread)
285285
assertEquals(AnrProfilingIntegration.MainThreadState.SUSPICIOUS, integration.state)
286286

287287
// Transition to ANR
288-
SystemClock.setCurrentTimeMillis(6_000)
288+
clock.advance(3_000, MILLISECONDS)
289289
integration.checkMainThread(mainThread)
290290
assertEquals(AnrProfilingIntegration.MainThreadState.ANR_DETECTED, integration.state)
291291

0 commit comments

Comments
 (0)