Espresso.onIdle() crashing in base.UiControllerImpl$MainThreadInterrogation.execCount

[meavydev]

We get this random crash from an IdlingResource called from a Kotlin Instrumented Test:

java.lang.RuntimeException: java.util.concurrent.ExecutionException: java.lang.NullPointerException: Attempt to read from field 'int androidx.test.espresso.base.UiControllerImpl$MainThreadInterrogation.execCount' on a null object reference
at androidx.test.espresso.Espresso.onIdle(Espresso.java:342)

I'm afraid there is no easy repro, as it's happening at random when running our instrumented test suite on an LG G6 (LG-H870 - 8.0.0) running Android 8.0 from Jenkins.

We are building with: androidTestImplementation "androidx.test.espresso:espresso-core:3.2.0" androidTestImplementation "androidx.test.espresso:espresso-contrib:3.2.0"

[adazh]

Would appreciate if you could provide some way to repro (it's fine if it's a flake).

Otherwise, we might have to take this as a lower priority until we are able to repro in some way.

[badrinrs]

I too see it almost every day, It is indeed flaky. I see it when signing in on Roku Mobile App and Checking for Sign Out text to appear using IdlingResources. I have seen it happen on Pixel 2 XL - Android 11

[vpuonti]

I'm facing this error on almost all of my UI test runs in Azure Pipelines:

java.lang.NullPointerException: Attempt to read from field 'int androidx.test.espresso.base.UiControllerImpl$MainThreadInterrogation.execCount' on a null object reference
	at androidx.test.espresso.base.UiControllerImpl$MainThreadInterrogation.-$$Nest$fgetexecCount(Unknown Source:0)

Espresso version: 3.5.1.

[vpuonti]

I overrode Espresso's default failure handler to maybe get more in-depth insight into what was happening

    @Before
    fun setIdlingPolicies() {
        IdlingPolicies.setMasterPolicyTimeout(2, TimeUnit.MINUTES)
        IdlingPolicies.setIdlingResourceTimeout(2, TimeUnit.MINUTES)
        Espresso.setFailureHandler { t, matcher ->
            Timber.tag("FailureHandler").e(t, "Error with matcher: $matcher")
        }
    }

and this is what I found in the logs:

02-07 16:22:44.914  2184  2184 D ViewVisibleIdlingResource: View for view.getId() is <2131362265/com.my.application:id/dialog_text> is visible after 15575 ms.
...
02-07 16:23:09.132  2184  2184 W UiControllerImpl: Waiting for: DYNAMIC_TASKS_HAVE_IDLED for 600 iterations.
...
02-07 16:23:59.757  2184  2184 W UiControllerImpl: Waiting for: DYNAMIC_TASKS_HAVE_IDLED for 700 iterations.
02-07 16:24:30.149  2184  2258 E FailureHandler: Error with matcher: view.getId() is <2131362265/com.my.application:id/dialog_text>
02-07 16:24:30.149  2184  2258 E FailureHandler: java.lang.NullPointerException: Attempt to read from field 'int androidx.test.espresso.base.UiControllerImpl$MainThreadInterrogation.execCount' on a null object reference
02-07 16:24:30.149  2184  2258 E FailureHandler: 	at androidx.test.espresso.base.UiControllerImpl$MainThreadInterrogation.-$$Nest$fgetexecCount(Unknown Source:0)
02-07 16:24:30.149  2184  2258 E FailureHandler: 	at androidx.test.espresso.base.UiControllerImpl.loopUntil(UiControllerImpl.java:50)
02-07 16:24:30.149  2184  2258 E FailureHandler: 	at androidx.test.espresso.base.UiControllerImpl.loopMainThreadUntilIdle(UiControllerImpl.java:16)
02-07 16:24:30.149  2184  2258 E FailureHandler: 	at androidx.test.espresso.ViewInteraction$2.call(ViewInteraction.java:6)
02-07 16:24:30.149  2184  2258 E FailureHandler: 	at androidx.test.espresso.ViewInteraction$2.call(ViewInteraction.java:1)
02-07 16:24:30.149  2184  2258 E FailureHandler: 	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
02-07 16:24:30.149  2184  2258 E FailureHandler: 	at android.os.Handler.handleCallback(Handler.java:938)
02-07 16:24:30.149  2184  2258 E FailureHandler: 	at android.os.Handler.dispatchMessage(Handler.java:99)
02-07 16:24:30.149  2184  2258 E FailureHandler: 	at android.os.Looper.loop(Looper.java:223)
02-07 16:24:30.149  2184  2258 E FailureHandler: 	at android.app.ActivityThread.main(ActivityThread.java:7656)
02-07 16:24:30.149  2184  2258 E FailureHandler: 	at java.lang.reflect.Method.invoke(Native Method)
02-07 16:24:30.149  2184  2258 E FailureHandler: 	at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:592)
02-07 16:24:30.149  2184  2258 E FailureHandler: 	at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:947)
02-07 16:24:30.149  2184  2258 D IdlingRegistry: Unregistering idling resources: [com.my.application.testutil.ViewVisibleIdlingResource@c3fe26d]

For context: the test is using a ViewVisibleIdlingResource which checks in IdlingResource.isIdleNow() if a View with given ID is visible. Looks to me like this error is happening after the View has become visible and the IdlingResource is unregistering 🧐 .

[vpuonti]

I seem to have the following log for every test which fails with this error:

02-08 13:39:59.850  4342  4342 D ViewVisibleIdlingResource: View for view.getId() is <2131362265/com.my.app:id/dialog_text> is visible after 18297 ms.
02-08 13:39:59.852  4342  4342 W UiControllerImpl: ignoring signal of: DYNAMIC_TASKS_HAVE_IDLED from previous generation: 79 current generation: 80

[vpuonti]

To add some info: seems like the issues I'm facing are due to bad CPU performance in Azure Pipelines runner. Before I had no success reproing this error locally, but after installing cpulimit and finding a nice low enough CPU limit I got the same error locally.

[TWiStErRob]

Can you please write down the exact steps to reproduce the issue (hopefully with a trivial example project), without it, there's a very low chance of fix.

[dimskom]

We have the same issue using the Azure pipeline using 3.5.1 version. It fails randomly. @vpuonti Did you find any solution?

java.lang.NullPointerException: Attempt to read from field 'int androidx.test.espresso.base.UiControllerImpl$MainThreadInterrogation.execCount' on a null object reference at androidx.test.espresso.base.UiControllerImpl$MainThreadInterrogation.-$$Nest$fgetexecCount(UiControllerImpl.java:0) at androidx.test.espresso.base.UiControllerImpl.loopUntil(UiControllerImpl.java:50) at androidx.test.espresso.base.UiControllerImpl.loopMainThreadUntilIdle(UiControllerImpl.java:16) at androidx.test.espresso.ViewInteraction$2.call(ViewInteraction.java:6) at androidx.test.espresso.ViewInteraction$2.call(ViewInteraction.java:1) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at android.os.Handler.handleCallback(Handler.java:873) at android.os.Handler.dispatchMessage(Handler.java:99) at android.os.Looper.loop(Looper.java:214) at android.app.ActivityThread.main(ActivityThread.java:7032) at java.lang.reflect.Method.invoke(Native Method) at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:494) at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:965)

[george-georgy]

I'm also experiencing this issue ... any update @dimskom @TWiStErRob @badrinrs @meavydev @vpuonti ?