We are encountering a problem with sendKeys for android, occurring on a native page. We are running appium/selendroid. The problem only occurs when running at Sauce Labs. The problem doesn’t occur with appium 1.1.0. The problem occurs starting with appium 1.2.0. I am currently testing with appium 1.3.1 and seeing the problem. Here is a portion of the appium log:
12932014-11-07 00:55:01:831 - info: e[37m–>e[39m e[37mPOSTe[39m e[37m/wd/hub/session/00876295-fb80-809b-b567-0661e4bb7c21/elemente[39m e[90m{“using”:“id”,“value”:“edit”}e[39m
12942014-11-07 00:55:01:831 - info: [debug] Proxying command to localhost:4725
12952014-11-07 00:55:01:831 - info: [debug] Making http request with opts: {“url”:“http://localhost:4725/wd/hub/session/00876295-fb80-809b-b567-0661e4bb7c21/element",“method”:“POST”,“json”:{“using”:“id”,“value”:"edit”}}
12962014-11-07 00:55:01:849 - info: [debug] Proxied response received with status 200: {“value”:{“ELEMENT”:“66286ae5-0016-6476-d19e-0f5b868b13a1”},“status”:0,“sessionId”:“00876295-fb80-809b-b567-0661e4bb7c21”}
12972014-11-07 00:55:01:850 - info: e[37m<-- POST /wd/hub/session/00876295-fb80-809b-b567-0661e4bb7c21/element e[39me[32m200e[39me[90m 19.406 ms - 122e[39m e[90me[39m
12982014-11-07 00:55:01:874 - info: e[37m–>e[39m e[37mGETe[39m e[37m/wd/hub/session/00876295-fb80-809b-b567-0661e4bb7c21/element/66286ae5-0016-6476-d19e-0f5b868b13a1/displayede[39m e[90m{}e[39m
12992014-11-07 00:55:01:875 - info: [debug] Proxying command to localhost:4725
13002014-11-07 00:55:01:875 - info: [debug] Making http request with opts: {“url”:“http://localhost:4725/wd/hub/session/00876295-fb80-809b-b567-0661e4bb7c21/element/66286ae5-0016-6476-d19e-0f5b868b13a1/displayed",“method”:"GET”}
13012014-11-07 00:55:01:881 - info: [debug] Proxied response received with status 200: “{“value”:true,“status”:0,“sessionId”:“00876295-fb80-809b-b567-0661e4bb7c21”}”
13022014-11-07 00:55:01:882 - info: e[37m<-- GET /wd/hub/session/00876295-fb80-809b-b567-0661e4bb7c21/element/66286ae5-0016-6476-d19e-0f5b868b13a1/displayed e[39me[32m200e[39me[90m 7.586 ms - 76e[39m e[90me[39m
13032014-11-07 00:55:01:901 - info: e[37m–>e[39m e[37mPOSTe[39m e[37m/wd/hub/session/00876295-fb80-809b-b567-0661e4bb7c21/elemente[39m e[90m{“using”:“id”,“value”:“edit”}e[39m
13042014-11-07 00:55:01:901 - info: [debug] Proxying command to localhost:4725
13052014-11-07 00:55:01:902 - info: [debug] Making http request with opts: {“url”:“http://localhost:4725/wd/hub/session/00876295-fb80-809b-b567-0661e4bb7c21/element",“method”:“POST”,“json”:{“using”:“id”,“value”:"edit”}}
13062014-11-07 00:55:01:912 - info: [debug] Proxied response received with status 200: {“value”:{“ELEMENT”:“66286ae5-0016-6476-d19e-0f5b868b13a1”},“status”:0,“sessionId”:“00876295-fb80-809b-b567-0661e4bb7c21”}
13072014-11-07 00:55:01:912 - info: e[37m<-- POST /wd/hub/session/00876295-fb80-809b-b567-0661e4bb7c21/element e[39me[32m200e[39me[90m 11.046 ms - 122e[39m e[90me[39m
13082014-11-07 00:55:01:931 - info: e[37m–>e[39m e[37mPOSTe[39m e[37m/wd/hub/session/00876295-fb80-809b-b567-0661e4bb7c21/element/66286ae5-0016-6476-d19e-0f5b868b13a1/cleare[39m e[90m{“id”:“66286ae5-0016-6476-d19e-0f5b868b13a1”}e[39m
13092014-11-07 00:55:01:931 - info: [debug] Proxying command to localhost:4725
13102014-11-07 00:55:01:931 - info: [debug] Making http request with opts: {“url”:“http://localhost:4725/wd/hub/session/00876295-fb80-809b-b567-0661e4bb7c21/element/66286ae5-0016-6476-d19e-0f5b868b13a1/clear",“method”:“POST”,“json”:{“id”:"66286ae5-0016-6476-d19e-0f5b868b13a1”}}
13112014-11-07 00:55:01:961 - info: [debug] Proxied response received with status 200: {“value”:"",“status”:0,“sessionId”:“00876295-fb80-809b-b567-0661e4bb7c21”}
13122014-11-07 00:55:01:962 - info: e[37m<-- POST /wd/hub/session/00876295-fb80-809b-b567-0661e4bb7c21/element/66286ae5-0016-6476-d19e-0f5b868b13a1/clear e[39me[32m200e[39me[90m 31.259 ms - 74e[39m e[90me[39m
13132014-11-07 00:55:02:986 - info: e[37m–>e[39m e[37mPOSTe[39m e[37m/wd/hub/session/00876295-fb80-809b-b567-0661e4bb7c21/elemente[39m e[90m{“using”:“id”,“value”:“edit”}e[39m
13142014-11-07 00:55:02:986 - info: [debug] Proxying command to localhost:4725
13152014-11-07 00:55:02:986 - info: [debug] Making http request with opts: {“url”:“http://localhost:4725/wd/hub/session/00876295-fb80-809b-b567-0661e4bb7c21/element",“method”:“POST”,“json”:{“using”:“id”,“value”:"edit”}}
13162014-11-07 00:55:02:997 - info: [debug] Proxied response received with status 200: {“value”:{“ELEMENT”:“66286ae5-0016-6476-d19e-0f5b868b13a1”},“status”:0,“sessionId”:“00876295-fb80-809b-b567-0661e4bb7c21”}
13172014-11-07 00:55:02:997 - info: e[37m<-- POST /wd/hub/session/00876295-fb80-809b-b567-0661e4bb7c21/element e[39me[32m200e[39me[90m 11.654 ms - 122e[39m e[90me[39m
13182014-11-07 00:55:03:024 - info: e[37m–>e[39m e[37mPOSTe[39m e[37m/wd/hub/session/00876295-fb80-809b-b567-0661e4bb7c21/element/66286ae5-0016-6476-d19e-0f5b868b13a1/valuee[39m e[90m{“id”:“66286ae5-0016-6476-d19e-0f5b868b13a1”,“value”:[“super”]}e[39m
13192014-11-07 00:55:03:026 - info: e[37m<-- POST /wd/hub/session/00876295-fb80-809b-b567-0661e4bb7c21/element/66286ae5-0016-6476-d19e-0f5b868b13a1/value e[39me[33m404e[39me[90m 2.493 ms - 40e[39m e[90me[39m
13202014-11-07 01:01:03:080 - info: [debug] Didn’t get a new command in 360 secs, shutting down…
This is what the Java code looks like that corresponds with the appium log:
public void enterTextBox(String text) {
waitUntil(getTextBox(), is(displayed()));
HtmlElement textBox = getTextBox();
textBox.clear();
textBox.sendKeys(text);
getOkButton().click();
}
Notice that (Selendroid?) returned a 404 error code in response to the sendKeys. My guess is that appium didn’t recognize the 404 error code and so continued to wait for a new command until the new command timeout in 360 secs.
The error doesn’t always happen, but happens enough that we are unable to move forward from appium 1.1.0. We execute this code at the start of every test and the value is always “super.”
We have other sendKeys calls in our tests that do not have the problem. I do not know why the problem is happening with this particular code, however it might be worth noting that this sendKeys is the first one in the session. Also, the textBox is in a popup (alert) box. I have tried a static delay of up to 10 seconds prior to the sendKeys, but that did not help.