Flaky Espresso tests: Test fails with a timeout after launching an activity

Question

After launching an activity, my espresso test fails with a timeout after 45 seconds.

To launch the activity, I use InstrumentationRegistry.getInstrumentation().startActivitySync(intent). Although the activity launches correctly, the test runs into a timeout failure after 45 seconds. This only happens occasionally.

Note that my app fetches some stuff via OkHTTP right after launching the activity. I am also using libraries like Firebase Event Logging. However, I can confirm that all the OkHTTP requests are done within 2-3 seconds.

What are possible reasons that block Espresso from finishing the test? How can I debug this issue?

Here are the stacktraces when the timeout occurs:

  Thread[Jit thread pool worker thread 0,5,main]

  Thread[arch_disk_io_3,5,main]
    sun.misc.Unsafe.park(Native Method)
    java.util.concurrent.locks.LockSupport.park(LockSupport.java:190)
    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2067)
    java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
    java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1092)
    java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1152)
    java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
    java.lang.Thread.run(Thread.java:919)

  Thread[AsyncTask #1,5,main]
    sun.misc.Unsafe.park(Native Method)
    java.util.concurrent.locks.LockSupport.park(LockSupport.java:190)
    java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:459)
    java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
    java.util.concurrent.SynchronousQueue.take(SynchronousQueue.java:920)
    java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1092)
    java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1152)
    java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
    java.lang.Thread.run(Thread.java:919)

  Thread[Okio Watchdog,5,main]
    java.lang.Object.wait(Native Method)
    okio.AsyncTimeout.awaitTimeout(AsyncTimeout.java:361)
    okio.AsyncTimeout$Watchdog.run(AsyncTimeout.java:312)

  Thread[Timer-1,5,main]
    java.lang.Object.wait(Native Method)
    java.lang.Object.wait(Object.java:442)
    java.util.TimerThread.mainLoop(Timer.java:559)
    java.util.TimerThread.run(Timer.java:512)

  Thread[OkHttp ConnectionPool,5,main]
    java.lang.Object.wait(Native Method)
    com.android.okhttp.ConnectionPool$1.run(ConnectionPool.java:106)
    java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
    java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
    java.lang.Thread.run(Thread.java:919)

  Thread[RenderThread,7,main]

  Thread[HeapTaskDaemon,5,system]

  Thread[queued-work-looper,5,main]
    android.os.MessageQueue.nativePollOnce(Native Method)
    android.os.MessageQueue.next(MessageQueue.java:336)
    android.os.Looper.loop(Looper.java:174)
    android.os.HandlerThread.run(HandlerThread.java:67)

  Thread[hwuiTask1,6,main]

  Thread[ReferenceQueueDaemon,5,system]
    java.lang.Object.wait(Native Method)
    java.lang.Object.wait(Object.java:442)
    java.lang.Object.wait(Object.java:568)
    java.lang.Daemons$ReferenceQueueDaemon.runInternal(Daemons.java:215)
    java.lang.Daemons$Daemon.run(Daemons.java:137)
    java.lang.Thread.run(Thread.java:919)

  Thread[pool-1-thread-1,5,main]
    sun.misc.Unsafe.park(Native Method)
    java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:230)
    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2109)
    java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1132)
    java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:849)
    java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1092)
    java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1152)
    java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
    java.lang.Thread.run(Thread.java:919)

  Thread[OkHttp ConnectionPool,5,main]
    java.lang.Object.wait(Native Method)
    okhttp3.ConnectionPool$1.run(ConnectionPool.java:67)
    java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
    java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
    java.lang.Thread.run(Thread.java:919)

  Thread[pool-5-thread-2,5,main]
    sun.misc.Unsafe.park(Native Met

E/TestRunner: failed: registerWithoutUI(com.myapp.RegistrationTests) ----- begin exception ----- E/TestRunner: java.lang.RuntimeException: Could not launch intent Intent { act=android.intent.action.MAIN flg=0x14000000 cmp=com.myapp/com.myapp.navigation.StartupActivity } within 45000 seconds. Perhaps the main thread has not gone idle within a reasonable amount of time? There could be an animation or something constantly repainting the screen. Or the activity is doing network calls on creation? See the threaddump logs. For your reference the last time the event queue was idle before your activity launch request was 1571388177991 and now the last time the queue went idle was: 1571388191468. If these numbers are the same your activity might be hogging the event queue. at androidx.test.runner.MonitoringInstrumentation.startActivitySync(MonitoringInstrumentation.java:483) at com.myapp.TestUtilKt.launchActivity(TestUtil.kt:25) at com.myapp.RobotKitKt.launchStartupActivity(RobotKit.kt:18) at com.myappe.RobotKitKt.precondition_new_registration(RobotKit.kt:163) at com.myapp.RegistrationTests.registerWithoutUI(RegistrationTests.kt:48) at java.lang.reflect.Method.invoke(Native Method) at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50) at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47) at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17) at androidx.test.internal.runner.junit4.statement.RunBefores.evaluate(RunBefores.java:80) at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57) at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290) at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71) at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288) at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58) at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268) at org.junit.runners.ParentRunner.run(ParentRunner.java:363) at androidx.test.ext.junit.runners.AndroidJUnit4.run(AndroidJUnit4.java:104) at org.junit.runners.Suite.runChild(Suite.java:128) at org.junit.runners.Suite.runChild(Suite.java:27) at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290) at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71) at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288) at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58) at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268) at org.junit.runners.ParentRunner.run(ParentRunner.java:363) at org.junit.runner.JUnitCore.run(JUnitCore.java:137) at org.junit.runner.JUnitCore.run(JUnitCore.java:115) at androidx.test.internal.runner.TestExecutor.execute(TestExecutor.java:56) at androidx.test.runner.AndroidJUnitRunner.onStart(AndroidJUnitRunner.java:392) at android.app.Instrumentation$InstrumentationThread.run(Instrumentation.java:2189) ----- end exception -----

Do you use IdlingResrouces? The OkHttpis supported by IdlingResources now adays. Lookup for that, if that could handle the call correct way and would not die due timetout. — ponkape
In my understanding, IdlingResources is a mean to tell Espresso to wait for a particular resource. The rationale is to avoid the need for Thread.sleep(). However, failing to wait for a resource is not the issue. This is the opposite issue: Espresso seems to wait for a resource that does not idle. — Mike76
Very true. And it cannot be about animations, maybe possible to try other server instance? Is it only this specific activity? — ponkape
There are no animations. I will now start to disable certain functionality step by step. However, I would really like to extract debugging information from Espresso without rolling my own Espresso version. — Mike76

Mike76 Mike76 · Accepted Answer · 2019-10-21T07:23:07

I was now able to workaround the issue by inserting Thread.sleep() at a few places in my precondition code (before launching the activity under test).

I wish that I had the time to dig deep into Espresso to help fix all of this mess.

Flaky Espresso tests: Test fails with a timeout after launching an activity

1 Answers