I am automating a Webview on Android and I am facing a problem of very slow click() actions. In my Appium Java code, I first use the driver to find an element using some locator, and then I click the returned element.
MobileElement el = driver.findElement(locator);
el.click();
The problem is that even though the findElement() command returns very quickly, the click() command takes extremely long to return (sometimes up to a minute).
Looking at the device screen, it appears that the click() is executed quickly as well. However, the Appium log tells me that the response of the click command does not arrive at the Appium server until much later (see highlighted timestamps).
2020-03-18 14:23:56:187 - e[35m[HTTP]e[39m e[90me[39m
2020-03-18 14:23:56:206 - e[35m[HTTP]e[39m e[37m–>e[39m e[37mPOSTe[39m e[37m/wd/hub/session/58497e80-0264-4f7c-8dbf-a5305edcd684/elemente[39m
2020-03-18 14:23:56:206 - e[35m[HTTP]e[39m e[90m{“using”:“css selector”,“value”:“[resource-id=‘login-page-login-button’]”}e[39m
2020-03-18 14:23:56:207 - e[35m[W3C (58497e80)]e[39m Driver proxy active, passing request on via HTTP proxy
2020-03-18 14:23:56:208 - [debug] e[35m[WD Proxy]e[39m Matched ‘/wd/hub/session/58497e80-0264-4f7c-8dbf-a5305edcd684/element’ to command name ‘findElement’
2020-03-18 14:23:56:208 - [debug] e[35m[WD Proxy]e[39m Proxying [POST /wd/hub/session/58497e80-0264-4f7c-8dbf-a5305edcd684/element] to [POST http://127.0.0.1:8000/wd/hub/session/0c3fee22af06b5ff9bdd3dfce348d443/element] with body: {“using”:“css selector”,“value”:“[resource-id=‘login-page-login-button’]”}
2020-03-18 14:23:56:936 - [debug] e[35m[WD Proxy]e[39m Got response with status 200: {“sessionId”:“0c3fee22af06b5ff9bdd3dfce348d443”,“status”:0,“value”:{“ELEMENT”:“0.0645002172884559-6”}}
2020-03-18 14:23:56:936 - e[35m[WD Proxy]e[39m Replacing sessionId 0c3fee22af06b5ff9bdd3dfce348d443 with 58497e80-0264-4f7c-8dbf-a5305edcd684
2020-03-18 14:23:56:954 - e[35m[HTTP]e[39m e[37m<-- POST /wd/hub/session/58497e80-0264-4f7c-8dbf-a5305edcd684/element e[39me[32m200e[39m e[90m731 ms - 156e[39m
2020-03-18 14:23:56:954 - e[35m[HTTP]e[39m e[90me[39m
2020-03-18 14:23:56:957 - e[35m[HTTP]e[39m e[37m–>e[39m e[37mPOSTe[39m e[37m/wd/hub/session/58497e80-0264-4f7c-8dbf-a5305edcd684/element/0.0645002172884559-6/clicke[39m
2020-03-18 14:23:56:957 - e[35m[HTTP]e[39m e[90m{“id”:“0.0645002172884559-6”}e[39m
2020-03-18 14:23:56:957 - e[35m[W3C (58497e80)]e[39m Driver proxy active, passing request on via HTTP proxy
2020-03-18 14:23:56:981 - [debug] e[35m[WD Proxy]e[39m Matched ‘/wd/hub/session/58497e80-0264-4f7c-8dbf-a5305edcd684/element/0.0645002172884559-6/click’ to command name ‘click’
2020-03-18 14:23:56:981 - [debug] e[35m[WD Proxy]e[39m Proxying [POST /wd/hub/session/58497e80-0264-4f7c-8dbf-a5305edcd684/element/0.0645002172884559-6/click] to [POST http://127.0.0.1:8000/wd/hub/session/0c3fee22af06b5ff9bdd3dfce348d443/element/0.0645002172884559-6/click] with body: {“id”:“0.0645002172884559-6”}
2020-03-18 14:24:31:287 - [debug] e[35m[WD Proxy]e[39m Got response with status 200: {“sessionId”:“0c3fee22af06b5ff9bdd3dfce348d443”,“status”:0,“value”:null}
2020-03-18 14:24:31:288 - e[35m[WD Proxy]e[39m Replacing sessionId 0c3fee22af06b5ff9bdd3dfce348d443 with 58497e80-0264-4f7c-8dbf-a5305edcd684
2020-03-18 14:24:31:292 - e[35m[HTTP]e[39m e[37m<-- POST /wd/hub/session/58497e80-0264-4f7c-8dbf-a5305edcd684/element/0.0645002172884559-6/click e[39me[32m200e[39m e[90m34331 ms - 65e[39m
I also noticed in the Logcat log that an exception related to UiAutomationService occurred. However, the exception does not always occur when I notice the delay on the click() command, so I am unsure if these two issues are really related.
(There is a mismatch between the timestamps in the Appium Log and those in the Logcat.)
03-18 10:27:03.993 17235 17235 D AndroidRuntime: >>>>>> START com.android.internal.os.RuntimeInit uid 2000 <<<<<<
03-18 10:27:04.082 17235 17235 D AndroidRuntime: Calling main entry com.android.commands.uiautomator.Launcher
03-18 10:27:04.090 17235 17235 D AndroidRuntime: Shutting down VM
--------- beginning of crash
03-18 10:27:04.091 17235 17235 E AndroidRuntime: *** FATAL EXCEPTION IN SYSTEM PROCESS: main
03-18 10:27:04.091 17235 17235 E AndroidRuntime: java.lang.IllegalStateException: UiAutomationService android.accessibilityservice.IAccessibilityServiceClient$Stub$Proxy@ad91b8ealready registered!
03-18 10:27:04.091 17235 17235 E AndroidRuntime: at android.os.Parcel.readException(Parcel.java:1951)
03-18 10:27:04.091 17235 17235 E AndroidRuntime: at android.os.Parcel.readException(Parcel.java:1889)
03-18 10:27:04.091 17235 17235 E AndroidRuntime: at android.view.accessibility.IAccessibilityManager$Stub$Proxy.registerUiTestAutomationService(IAccessibilityManager.java:402)
03-18 10:27:04.091 17235 17235 E AndroidRuntime: at android.app.UiAutomationConnection.registerUiTestAutomationServiceLocked(UiAutomationConnection.java:396)
03-18 10:27:04.091 17235 17235 E AndroidRuntime: at android.app.UiAutomationConnection.connect(UiAutomationConnection.java:96)
03-18 10:27:04.091 17235 17235 E AndroidRuntime: at android.app.UiAutomation.connect(UiAutomation.java:223)
03-18 10:27:04.091 17235 17235 E AndroidRuntime: at android.app.UiAutomation.connect(UiAutomation.java:202)
03-18 10:27:04.091 17235 17235 E AndroidRuntime: at com.android.uiautomator.core.UiAutomationShellWrapper.connect(UiAutomationShellWrapper.java:31)
03-18 10:27:04.091 17235 17235 E AndroidRuntime: at com.android.commands.uiautomator.DumpCommand.run(DumpCommand.java:74)
03-18 10:27:04.091 17235 17235 E AndroidRuntime: at com.android.commands.uiautomator.Launcher.main(Launcher.java:83)
03-18 10:27:04.091 17235 17235 E AndroidRuntime: at com.android.internal.os.RuntimeInit.nativeFinishInit(Native Method)
03-18 10:27:04.091 17235 17235 E AndroidRuntime: at com.android.internal.os.RuntimeInit.main(RuntimeInit.java:284)
What could be a reason for the click() to take so long? How could I further investigate the issue?
My setup is as follows:
- Appium Server: 1.15.1
- Appium Java Client 7.3.0
- Real device with Android 8.0.0, running on AWS Device Farm
- The app is a hybrid app built using Ionic.
Running the same tests on an emulator with Android 8.0.0 does not suffer from the problem.