search

appium / appium-espresso-driver

Espresso integration for Appium
Apache License 2.0
188 stars 75 forks source link

Issue with compose Idling resource timed out in Espresso #958

Open MiladVS opened 9 months ago

MiladVS commented 9 months ago

I am encountering an issue while running Espresso tests with the given capabilities: Appium: 2.2.2 Espresso-driver: 2.25.7 { "platformName": "ANDROID", "appium:app": "Our_Link", "appium:appWaitActivity": "*", "appium:automationName": "Espresso", "appium:deviceName": "Pixel_XL_API_32", "appium:espressoBuildConfig": "{\"additionalAndroidTestDependencies\":[\"androidx.lifecycle:lifecycle-viewmodel-compose:2.6.2\",\"androidx.compose.material3:material3:1.2.0-alpha09\",\"androidx.activity:activity-compose:1.8.1\",\"androidx.activity:activity-ktx:1.8.1\"],\"toolsVersions\":{\"gradle\":\"8.0.2\",\"targetCompatibility\":\"VERSION_17\",\"minSdk\":24,\"composeVersion\":\"1.5.5\",\"kotlin\":\"1.9.20\",\"jvmTarget\":\"17\",\"targetSdk\":34,\"sourceCompatibility\":\"VERSION_17\",\"compileSdk\":\"34\"}}", "appium:forceEspressoRebuild": true, "appium:newCommandTimeout": 180, "appium:showGradleLog": true, "appium:udid": "emulator-5554" }

The problem arises after successfully logging in and transitioning to the second layout implemented in Compose. The error indicates an issue with idling, and the logs are as follows:

Please note that we did update our libraries and I put on the "show surface updates" in the android developer mode to see if there is any constant updates but the layout is not flashing and it seems that there's no infinite recomposition. I also checked with the Devs and they are pretty sure that there is not infinite recomposition, they even added logs to too see the recomposition and it's only shown once when the screen is loaded. Another extra info the layout has LazyColumn

An unknown server-side error occurred while processing the command. Original error: androidx.compose.ui.test.junit4.android.ComposeNotIdleException: Idling resource timed out: possibly due to compose being busy. IdlingResourceRegistry has the following idling resources registered: - [busy] ComposeIdlingResource is busy due to pending recompositions. - Note: Timeout on pending recomposition means that there are most likely infinite re-compositions happening in the tested code. - Debug: hadRecomposerChanges = true, hadSnapshotChanges = false, hadAwaitersOnMainClock = false All registered idling resources: Compose-Espresso link Build info: version: '4.11.0', revision: '040bc5406b' System info: os.name: 'Mac OS X', os.arch: 'x86_64', os.version: '14.1.1', java.version: '11.0.14.1' Driver info: io.appium.java_client.android.AndroidDriver Command: [f902c6d9-12fb-4a27-ba28-43e60bd7e92b, findElement {using=xpath, value=//Image[@content-desc="btnSearch"]}] Capabilities {appium:app: appium:appWaitActivity: , appium:automationName: Espresso, appium:deviceName: Pixel_XL_API_32, appium:espressoBuildConfig: {"additionalAndroidTestDepe..., appium:forceEspressoRebuild: true, appium:newCommandTimeout: 180, appium:showGradleLog: true, appium:udid: emulator-5554, platformName: ANDROID} Session ID: f902c6d9-12fb-4a27-ba28-43e60bd7e92b

adb logcat: Matched route handler: class io.appium.espressoserver.lib.handlers.FindElement 12-05 10:17:52.663 6087 6336 D appium : Got raw post data: {"using":"xpath","value":"//Image[@content-desc=\"btnSearch\"]"} 12-05 10:17:52.666 6087 6336 I appium : Executing FindElement handler 12-05 10:17:53.311 6087 6098 W System : A resource failed to call end. 12-05 10:17:53.311 6087 6098 W System : A resource failed to call end. 12-05 10:17:53.312 6087 6098 W System : A resource failed to call end. 12-05 10:17:53.312 6087 6098 W System : A resource failed to call end. 12-05 10:17:54.378 6087 6087 W UiControllerImpl: Waiting for: DYNAMIC_TASKS_HAVE_IDLED for 200 iterations. 12-05 10:17:57.706 6087 6087 W IdlingPolicy: These resources are not idle: [Compose-Espresso link] 12-05 10:17:59.868 6087 6087 W UiControllerImpl: Waiting for: DYNAMIC_TASKS_HAVE_IDLED for 900 iterations. 12-05 10:18:00.003 560 3515 W ActivityManager: Unable to start service Intent { act=android.service.smartspace.SmartspaceService cmp=com.google.android.as/com.google.android.apps.miphone.aiai.app.AiAiSmartspaceService } U=0: not found 12-05 10:18:00.003 560 3515 W RemoteSmartspaceService: could not bind to Intent { act=android.service.smartspace.SmartspaceService cmp=com.google.android.as/com.google.android.apps.miphone.aiai.app.AiAiSmartspaceService } using flags 67112961 12-05 10:18:00.003 560 560 W ActivityManager: Unbind failed: could not find connection for android.app.LoadedApk$ServiceDispatcher$InnerConnection@2c359d4 12-05 10:18:00.036 766 1048 D EGL_emulation: app_time_stats: avg=25194.49ms min=25194.49ms max=25194.49ms count=1 12-05 10:18:02.162 6087 6087 W UiControllerImpl: Waiting for: DYNAMIC_TASKS_HAVE_IDLED for 1200 iterations. 12-05 10:18:02.707 6087 6087 W IdlingPolicy: These resources are not idle: [Compose-Espresso link] 12-05 10:18:03.674 6087 6087 W UiControllerImpl: Waiting for: DYNAMIC_TASKS_HAVE_IDLED for 1400 iterations. 12-05 10:18:04.087 6087 6096 I steuerPhoneBet: Background concurrent copying GC freed 134631(5004KB) AllocSpace objects, 0(0B) LOS objects, 21% free, 86MB/110MB, paused 16us,15us total 100.028ms 12-05 10:18:04.413 6087 6087 W UiControllerImpl: Waiting for: DYNAMIC_TASKS_HAVE_IDLED for 1500 iterations. 12-05 10:18:07.781 6087 6087 W IdlingPolicy: These resources are not idle: [Compose-Espresso link] 12-05 10:18:08.241 6087 6096 I steuerPhoneBet: Background concurrent copying GC freed 164997(6193KB) AllocSpace objects, 1(164KB) LOS objects, 18% free, 107MB/131MB, paused 29us,197us total 179.595ms 12-05 10:18:08.500 6087 6087 W UiControllerImpl: Waiting for: DYNAMIC_TASKS_HAVE_IDLED for 2000 iterations. 12-05 10:18:11.616 6087 6087 W UiControllerImpl: Waiting for: DYNAMIC_TASKS_HAVE_IDLED for 2400 iterations. 12-05 10:18:12.685 6087 6096 I steuerPhoneBet: Background concurrent copying GC freed 128561(4940KB) AllocSpace objects, 0(0B) LOS objects, 15% free, 129MB/153MB, paused 102us,17us total 165.020ms 12-05 10:18:12.782 6087 6087 W IdlingPolicy: These resources are not idle: [Compose-Espresso link]

12-05 10:18:17.784 6087 6087 W IdlingPolicy: These resources are not idle: [Compose-Espresso link] 12-05 10:18:18.711 6087 6336 I appium : Responding to server with error: {error=unknown error, message=androidx.compose.ui.test.junit4.android.ComposeNotIdleException: Idling resource timed out: possibly due to compose being busy. 12-05 10:18:18.711 6087 6336 I appium : IdlingResourceRegistry has the following idling resources registered: 12-05 10:18:18.711 6087 6336 I appium : - [busy] ComposeIdlingResource is busy due to pending recompositions. 12-05 10:18:18.711 6087 6336 I appium : - Note: Timeout on pending recomposition means that there are most likely infinite re-compositions happening in the tested code. 12-05 10:18:18.711 6087 6336 I appium : - Debug: hadRecomposerChanges = true, hadSnapshotChanges = false, hadAwaitersOnMainClock = false 12-05 10:18:18.711 6087 6336 I appium : All registered idling resources: Compose-Espresso link, stacktrace=androidx.compose.ui.test.junit4.android.ComposeNotIdleException: Idling resource timed out: possibly due to compose being busy. 12-05 10:18:18.711 6087 6336 I appium : IdlingResourceRegistry has the following idling resources registered: 12-05 10:18:18.711 6087 6336 I appium : - [busy] ComposeIdlingResource is busy due to pending recompositions. 12-05 10:18:18.711 6087 6336 I appium : - Note: Timeout on pending recomposition means that there are most likely infinite re-compositions happening in the tested code. 12-05 10:18:18.711 6087 6336 I appium : - Debug: hadRecomposerChanges = true, hadSnapshotChanges = false, hadAwaitersOnMainClock = false 12-05 10:18:18.711 6087 6336 I appium : All registered idling resources: Compose-Espresso link 12-05 10:18:18.711 6087 6336 I appium : at androidx.compose.ui.test.junit4.EspressoLink_androidKt.rethrowWithMoreInfo(EspressoLink.android.kt:136) 12-05 10:18:18.711 6087 6336 I appium : at androidx.compose.ui.test.junit4.EspressoLink_androidKt.runEspressoOnIdle(EspressoLink.android.kt:110) 12-05 10:18:18.711 6087 6336 I appium : at androidx.compose.ui.test.junit4.EspressoLink.runUntilIdle(EspressoLink.android.kt:79) 12-05 10:18:18.711 6087 6336 I appium : at androidx.compose.ui.test.AndroidComposeUiTestEnvironment.waitForIdle(ComposeUiTest.android.kt:336) 12-05 10:18:18.711 6087 6336 I appium : at androidx.compose.ui.test.AndroidComposeUiTestEnvironment.access$waitForIdle(ComposeUiTest.android.kt:228) 12-05 10:18:18.711 6087 6336 I appium : at androidx.compose.ui.test.AndroidComposeUiTestEnvironment$AndroidTestOwner.getRoots(ComposeUiTest.android.kt:529) 12-05 10:18:18.711 6087 6336 I appium : at androidx.compose.ui.test.TestContext.getAllSemanticsNodes$ui_test_release(TestOwner.kt:85) 12-05 10:18:18.711 6087 6336 I appium : at androidx.compose.ui.test.SemanticsNodeInteraction.fetchSemanticsNodes$ui_test_release(SemanticsNodeInteraction.kt:62) 12-05 10:18:18.711 6087 6336 I appium : at androidx.compose.ui.test.SemanticsNodeInteraction.fetchOneOrDie(SemanticsNodeInteraction.kt:128) 12-05 10:18:18.711 6087 6336 I appium : at androidx.compose.ui.test.SemanticsNodeInteraction.fetchSemanticsNode(SemanticsNodeInteraction.kt:79) 12-05 10:18:18.711 6087 6336 I appium : at androidx.compose.ui.test.SemanticsNodeInteraction.fetchSemanticsNode$default(SemanticsNodeInteraction.kt:78) 12-05 10:18:18.711 6087 6336 I appium : at io.appium.espressoserver.lib.model.SourceDocument.rootSemanticNodes(SourceDocument.kt:335) 12-05 10:18:18.711 6087 6336 I appium : at io.appium.espressoserver.lib.model.SourceDocument.toStream(SourceDocument.kt:289) 12-05 10:18:18.711 6087 6336 I appium : at io.appium.espressoserver.lib.model.SourceDocument.access$toStream(SourceDocument.kt:90) 12-05 10:18:18.711 6087 6336 I appium : at io.appium.espressoserver.lib.model.SourceDocument$findMatchingNodeIds$1.invoke(SourceDocument.kt:373) 12-05 10:18:18.711 6087 6336 I appium : at io.appium.espressoserver.lib.model.SourceDocument$findMatchingNodeIds$1.invoke(SourceDocument.kt:372) 12-05 10:18:18.711 6087 6336 I appium : at io.appium.espressoserver.lib.helpers.extensions.SemaphoreKt.withPermit(Semaphore.kt:17) 12-05 10:18:18.711 6087 6336 I appium : at io.appium.espressoserver.lib.model.SourceDocument.findMatchingNodeIds(SourceDocument.kt:372) 12-05 10:18:18.711 6087 6336 I appium : at io.appium.espressoserver.lib.helpers.ComposeNodeFinderKt.hasXpath(ComposeNodeFinder.kt:72) 12-05 10:18:18.711 6087 6336 I appium : at io.appium.espressoserver.lib.helpers.ComposeNodeFinderKt.semanticsMatcherForLocator(ComposeNodeFinder.kt:58) 12-05 10:18:18.711 6087 6336 I appium : at io.appium.espressoserver.lib.helpers.ComposeNodeFinderKt.toNodeInteractionsCollection(ComposeNodeFinder.kt:45) 12-05 10:18:18.711 6087 6336 I appium : at io.appium.espressoserver.lib.handlers.FindElement.handleCompose(FindElement.kt:51) 12-05 10:18:18.711 6087 6336 I appium : at io.appium.espressoserver.lib.handlers.FindElement.handleCompose(FindElement.kt:27) 12-05 10:18:18.711 6087 6336 I appium : at io.appium.espressoserver.lib.handlers.RequestHandler$DefaultImpls.invokeStrategy(RequestHandler.kt:34) 12-05 10:18:18.711 6087 6336 I appium : at io.appium.espressoserver.lib.handlers.FindElement.invokeStrategy(FindElement.kt:27) 12-05 10:18:18.711 6087 6336 I appium : at io.appium.espressoserver.lib.handlers.FindElement.invokeStrategy(FindElement.kt:27) 12-05 10:18:18.711 6087 6336 I appium : at io.appium.espressoserver.lib.handlers.RequestHandler$DefaultImpls.handleInternal(RequestHandler.kt:29) 12-05 10:18:18.711 6087 6336 I appium : at io.appium.espressoserver.lib.handlers.FindElement.handleInternal(FindElement.kt:27) 12-05 10:18:18.711 6087 6336 I appium : at io.appium.espressoserver.lib.handlers.FindElement.handleInternal(FindElement.kt:27) 12-05 10:18:18.711 6087 6336 I appium : at io.appium.espressoserver.lib.handlers.RequestHandler$DefaultImpls.handle(RequestHandler.kt:57) 12-05 10:18:18.711 6087 6336 I appium : at io.appium.espressoserver.lib.handlers.FindElement.handle(FindElement.kt:27) 12-05 10:18:18.711 6087 6336 I appium : at io.appium.espressoserver.lib.handlers.FindElement.handle(FindElement.kt:27) 12-05 10:18:18.711 6087 6336 I appium : at io.appium.espressoserver.lib.http.Router.route(Router.kt:231) 12-05 10:18:18.711 6087 6336 I appium : at io.appium.espressoserver.lib.http.Server.serve(Server.kt:54) 12-05 10:18:18.711 6087 6336 I appium : at fi.iki.elonen.NanoHTTPD$HTTPSession.execute(NanoHTTPD.java:945) 12-05 10:18:18.711 6087 6336 I appium : at fi.iki.elonen.NanoHTTPD$ClientHandler.run(NanoHTTPD.java:192) 12-05 10:18:18.711 6087 6336 I appium : at java.lang.Thread.run(Thread.java:920) 12-05 10:18:18.711 6087 6336 I appium : Caused by: androidx.test.espresso.IdlingResourceTimeoutException: Wait for [Compose-Espresso link] to become idle timed out 12-05 10:18:18.711 6087 6336 I appium : at androidx.test.espresso.IdlingPolicy.handleTimeout(IdlingPolicy.java:4) 12-05 10:18:18.711 6087 6336 I appium : at androidx.test.espresso.base.UiControllerImpl$5.resourcesHaveTimedOut(UiControllerImpl.java:1) 12-05 10:18:18.711 6087 6336 I appium : at androidx.test.espresso.base.IdlingResourceRegistry$Dispatcher.handleTimeout(IdlingResourceRegistry.java:4) 12-05 10:18:18.711 6087 6336 I appium : at androidx.test.espresso.base.IdlingResourceRegistry$Dispatcher.handleMessage(IdlingResourceRegistry.java:6) 12-05 10:18:18.711 6087 6336 I appium : at android.os.Handler.dispatchMessage(Handler.java:102) 12-05 10:18:18.711 6087 6336 I appium : at androidx.test.espresso.base.Interrogator.loopAndInterrogate(Interrogator.java:14) 12-05 10:18:18.711 6087 6336 I appium : at androidx.test.espresso.base.UiControllerImpl.loopUntil(UiControllerImpl.java:8) 12-05 10:18:18.711 6087 6336 I appium : at androidx.test.espresso.base.UiControllerImpl.loopMainThreadUntilIdle(UiControllerImpl.java:16) 12-05 10:18:18.711 6087 6336 I appium : at androidx.test.espresso.Espresso$1.run(Espresso.java:1) 12-05 10:18:18.711 6087 6336 I appium : at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:462) 12-05 10:18:18.711 6087 6336 I appium : at java.util.concurrent.FutureTask.run(FutureTask.java:266) 12-05 10:18:18.711 6087 6336 I appium : at android.os.Handler.handleCallback(Handler.java:938) 12-05 10:18:18.711 6087 6336 I appium : at android.os.Handler.dispatchMessage(Handler.java:99) 12-05 10:18:18.711 6087 6336 I appium : at android.os.Looper.loopOnce(Looper.java:201) 12-05 10:18:18.711 6087 6336 I appium : at android.os.Looper.loop(Looper.java:288) 12-05 10:18:18.711 6087 6336 I appium : at android.app.ActivityThread.main(ActivityThread.java:7842) 12-05 10:18:18.711 6087 6336 I appium : at java.lang.reflect.Method.invoke(Native Method) 12-05 10:18:18.711 6087 6336 I appium : at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:548) 12-05 10:18:18.711 6087 6336 I appium : at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1003) 12-05 10:18:18.711 6087 6336 I appium : } 12-05 10:18:18.900 6087 6336 D appium : Started processing GET request for '/session/a5b12763-2095-406d-9ceb-eccc6c1bba44/screenshot' 12-05 10:18:18.901 6087 6336 D appium : Matched route definition: class io.appium.espressoserver.lib.http.RouteDefinition 12-05 10:18:18.901 6087 6336 D appium : Matched route handler: class io.appium.espressoserver.lib.handlers.ScreenshotHandler 12-05 10:18:18.903 6087 6336 I appium : Executing ScreenshotHandler handler

sravanmedarapu commented 6 months ago

@MiladVS Could you try using mobile: waitForUIThread just before finding the element and see if it makes any difference.

MiladVS commented 6 months ago

So The "policy = neverEqualsPolicy()" was making the Idling Resource time out in Compose (https://developer.android.com/reference/kotlin/androidx/compose/runtime/package-summary) So after Changing it to <FilingButtonError?>(null) it worked

Line of Code:

var errorState by remember { mutableStateOf<FilingButtonError?>(null, policy = neverEqualPolicy()) }

-->

var errorState by remember { mutableStateOf<FilingButtonError?>(null) }