StaleElementReferenceException not thrown until 600 seconds later

Issues/Bugs
1

I am using Appium/Selendroid. Most of the time when a StaleElementReferenceException is thrown it happens right away, but sometimes it doesn’t get thrown for 600 seconds. In the case below it is a click that is failing. It looks like the click was attempted, nothing happened for 600 seconds, at which point something timed out, and Appium (?) attempted the click again, which resulted in a StaleElementReferenceException. Where is it spinning for 600 seconds and why?

I tried adding logs, but couldn’t. I got the message, “Sorry, new users can only mention 2 users in a post.” I am not mentioning any users, so no idea what that is about. If anyone is interested, I will try adding logs.

2

Please try and add the logs, versions, etc.

3

Appium version 1.1.0. Selendroid version 0.10.0.

Appium log:

debug: Appium request initiated at /wd/hub/session/ad23d6ca-e784-dcd4-9bf7-1b4a46c6ee28/element

info: Making http request with opts: {“url”:“http://localhost:8080/wd/hub/session/ad23d6ca-e784-dcd4-9bf7-1b4a46c6ee28/element",“method”:“POST”,“json”:{“using”:“name”,“value”:"HR_Contact_Visibility_Singular--IS”}}

debug: Request received with params: {“using”:“name”,“value”:“HR_Contact_Visibility_Singular–IS”}
debug: Proxying command to localhost:8080

POST /wd/hub/session/ad23d6ca-e784-dcd4-9bf7-1b4a46c6ee28/element 200 11ms - 144b
info: Making http request with opts: {“url”:“http://localhost:8080/wd/hub/session/ad23d6ca-e784-dcd4-9bf7-1b4a46c6ee28/element/491ab09c-ae15-6873-b7d4-fb8dbbc5ea94/displayed",“method”:"GET”}

debug: Proxied response received with status 200: {“value”:{“ELEMENT”:“491ab09c-ae15-6873-b7d4-fb8dbbc5ea94”},“status”:0,“sessionId”:“ad23d6ca-e784-dcd4-9bf7-1b4a46c6ee28”}
debug: Appium request initiated at /wd/hub/session/ad23d6ca-e784-dcd4-9bf7-1b4a46c6ee28/element/491ab09c-ae15-6873-b7d4-fb8dbbc5ea94/displayed
debug: Request received with params: {}
debug: Proxying command to localhost:8080

GET /wd/hub/session/ad23d6ca-e784-dcd4-9bf7-1b4a46c6ee28/element/491ab09c-ae15-6873-b7d4-fb8dbbc5ea94/displayed 200 12ms - 76b
info: Making http request with opts: {“url”:“http://localhost:8080/wd/hub/session/ad23d6ca-e784-dcd4-9bf7-1b4a46c6ee28/element",“method”:“POST”,“json”:{“using”:“name”,“value”:"HR_Contact_Visibility_Singular--IS”}}
POST /wd/hub/session/ad23d6ca-e784-dcd4-9bf7-1b4a46c6ee28/element 200 12ms - 144b

debug: Proxied response received with status 200: “{“value”:true,“status”:0,“sessionId”:“ad23d6ca-e784-dcd4-9bf7-1b4a46c6ee28”}”
debug: Appium request initiated at /wd/hub/session/ad23d6ca-e784-dcd4-9bf7-1b4a46c6ee28/element
debug: Request received with params: {“using”:“name”,“value”:“HR_Contact_Visibility_Singular–IS”}
debug: Proxying command to localhost:8080
debug: Proxied response received with status 200: {“value”:{“ELEMENT”:“491ab09c-ae15-6873-b7d4-fb8dbbc5ea94”},“status”:0,“sessionId”:“ad23d6ca-e784-dcd4-9bf7-1b4a46c6ee28”}

info: Making http request with opts: {“url”:“http://localhost:8080/wd/hub/session/ad23d6ca-e784-dcd4-9bf7-1b4a46c6ee28/element/491ab09c-ae15-6873-b7d4-fb8dbbc5ea94/click",“method”:“POST”,“json”:{“id”:"491ab09c-ae15-6873-b7d4-fb8dbbc5ea94”}}

debug: Appium request initiated at /wd/hub/session/ad23d6ca-e784-dcd4-9bf7-1b4a46c6ee28/element/491ab09c-ae15-6873-b7d4-fb8dbbc5ea94/click
debug: Request received with params: {“id”:“491ab09c-ae15-6873-b7d4-fb8dbbc5ea94”}
debug: Proxying command to localhost:8080

debug: Proxied response received with status 200: {“value”:"",“status”:0,“sessionId”:“ad23d6ca-e784-dcd4-9bf7-1b4a46c6ee28”}

POST /wd/hub/session/ad23d6ca-e784-dcd4-9bf7-1b4a46c6ee28/element/491ab09c-ae15-6873-b7d4-fb8dbbc5ea94/click 200 655ms - 87b

debug: Appium request initiated at /wd/hub/session/ad23d6ca-e784-dcd4-9bf7-1b4a46c6ee28/element

info: Making http request with opts: {“url”:“http://localhost:8080/wd/hub/session/ad23d6ca-e784-dcd4-9bf7-1b4a46c6ee28/element",“method”:“POST”,“json”:{“using”:"link text”,“value”:“Public”}}

debug: Request received with params: {“using”:“link text”,“value”:“Public”}
debug: Proxying command to localhost:8080

POST /wd/hub/session/ad23d6ca-e784-dcd4-9bf7-1b4a46c6ee28/element 200 13ms - 144b
info: Making http request with opts: {“url”:“http://localhost:8080/wd/hub/session/ad23d6ca-e784-dcd4-9bf7-1b4a46c6ee28/element/ac8a1cbf-aefa-2fb0-2712-601a420528e6/displayed",“method”:"GET”}

debug: Proxied response received with status 200: {“value”:{“ELEMENT”:“ac8a1cbf-aefa-2fb0-2712-601a420528e6”},“status”:0,“sessionId”:“ad23d6ca-e784-dcd4-9bf7-1b4a46c6ee28”}
debug: Appium request initiated at /wd/hub/session/ad23d6ca-e784-dcd4-9bf7-1b4a46c6ee28/element/ac8a1cbf-aefa-2fb0-2712-601a420528e6/displayed
debug: Request received with params: {}
debug: Proxying command to localhost:8080

debug: Proxied response received with status 200: “{“value”:true,“status”:0,“sessionId”:“ad23d6ca-e784-dcd4-9bf7-1b4a46c6ee28”}”

GET /wd/hub/session/ad23d6ca-e784-dcd4-9bf7-1b4a46c6ee28/element/ac8a1cbf-aefa-2fb0-2712-601a420528e6/displayed 200 145ms - 76b

debug: Appium request initiated at /wd/hub/session/ad23d6ca-e784-dcd4-9bf7-1b4a46c6ee28/element

info: Making http request with opts: {“url”:“http://localhost:8080/wd/hub/session/ad23d6ca-e784-dcd4-9bf7-1b4a46c6ee28/element",“method”:“POST”,“json”:{“using”:"link text”,“value”:“Public”}}

debug: Request received with params: {“using”:“link text”,“value”:“Public”}
debug: Proxying command to localhost:8080

POST /wd/hub/session/ad23d6ca-e784-dcd4-9bf7-1b4a46c6ee28/element 200 18ms - 144b
info: Making http request with opts: {“url”:“http://localhost:8080/wd/hub/session/ad23d6ca-e784-dcd4-9bf7-1b4a46c6ee28/element/ac8a1cbf-aefa-2fb0-2712-601a420528e6/click",“method”:“POST”,“json”:{“id”:"ac8a1cbf-aefa-2fb0-2712-601a420528e6”}}

debug: Proxied response received with status 200: {“value”:{“ELEMENT”:“ac8a1cbf-aefa-2fb0-2712-601a420528e6”},“status”:0,“sessionId”:“ad23d6ca-e784-dcd4-9bf7-1b4a46c6ee28”}
debug: Appium request initiated at /wd/hub/session/ad23d6ca-e784-dcd4-9bf7-1b4a46c6ee28/element/ac8a1cbf-aefa-2fb0-2712-601a420528e6/click
debug: Request received with params: {“id”:“ac8a1cbf-aefa-2fb0-2712-601a420528e6”}
debug: Proxying command to localhost:8080

.
.
.

POST /wd/hub/session/ad23d6ca-e784-dcd4-9bf7-1b4a46c6ee28/element/ac8a1cbf-aefa-2fb0-2712-601a420528e6/click 200 600002ms

debug: Appium request initiated at /wd/hub/session/ad23d6ca-e784-dcd4-9bf7-1b4a46c6ee28/element/ac8a1cbf-aefa-2fb0-2712-601a420528e6/click

info: Making http request with opts: {“url”:“http://localhost:8080/wd/hub/session/ad23d6ca-e784-dcd4-9bf7-1b4a46c6ee28/element/ac8a1cbf-aefa-2fb0-2712-601a420528e6/click",“method”:“POST”,“json”:{“id”:"ac8a1cbf-aefa-2fb0-2712-601a420528e6”}}

debug: Request received with params: {“id”:“ac8a1cbf-aefa-2fb0-2712-601a420528e6”}
debug: Proxying command to localhost:8080

info: Responding to client with error: {“status”:10,“value”:{“message”:“An element command failed because the referenced element is no longer attached to the DOM.”,“origValue”:“The element with id ‘ac8a1cbf-aefa-2fb0-2712-601a420528e6’ was not found.\nio.selendroid.exceptions.StaleElementReferenceException: The element with id ‘ac8a1cbf-aefa-2fb0-2712-601a420528e6’ was not found.\n\tat io.selendroid.server.handler.ClickElement.handle(ClickElement.java:39)\n\tat io.selendroid.server.AndroidServlet.handleRequest(AndroidServlet.java:290)\n\tat io.selendroid.server.BaseServlet.handleHttpRequest(BaseServlet.java:70)\n\tat org.webbitserver.netty.NettyHttpControl.nextHandler(NettyHttpControl.java:78)\n\tat org.webbitserver.netty.NettyHttpControl.nextHandler(NettyHttpControl.java:62)\n\tat io.selendroid.server.inspector.InspectorServlet.handleHttpRequest(InspectorServlet.java:78)\n\tat org.webbitserver.netty.NettyHttpControl.nextHandler(NettyHttpControl.java:78)\n\tat org.webbitserver.netty.NettyHttpControl.nextHandler(NettyHttpControl.java:62)\n\tat org.webbitserver.handler.PathMatchHandler.handleHttpRequest(PathMatchHandler.java:33)\n\tat org.webbitserver.netty.NettyHttpControl.nextHandler(NettyHttpControl.java:78)\n\tat org.webbitserver.netty.NettyHttpControl.nextHandler(NettyHttpControl.java:62)\n\tat org.webbitserver.handler.DateHeaderHandler.handleHttpRequest(DateHeaderHandler.java:21)\n\tat org.webbitserver.netty.NettyHttpControl.nextHandler(NettyHttpControl.java:78)\n\tat org.webbitserver.netty.NettyHttpControl.nextHandler(NettyHttpControl.java:62)\n\tat org.webbitserver.handler.ServerHeaderHandler.handleHttpRequest(ServerHeaderHandler.java:25)\n\tat org.webbitserver.netty.NettyHttpControl.nextHandler(NettyHttpControl.java:78)\n\tat org.webbitserver.netty.NettyHttpControl.nextHandler(NettyHttpControl.java:67)\n\tat org.webbitserver.netty.NettyHttpChannelHandler$2.run(NettyHttpChannelHandler.java:72)\n\tat java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1080)\n\tat java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)\n\tat java.lang.Thread.run(Thread.java:841)\n”},“sessionId”:“ad23d6ca-e784-dcd4-9bf7-1b4a46c6ee28”}

debug: Appium request initiated at /wd/hub/session/ad23d6ca-e784-dcd4-9bf7-1b4a46c6ee28

POST /wd/hub/session/ad23d6ca-e784-dcd4-9bf7-1b4a46c6ee28/element/ac8a1cbf-aefa-2fb0-2712-601a420528e6/click 500 12ms - 2.14kb
info: Shutting down appium session…

4

It is the LogCat log that I can’t post, which is too bad since it shows the Selendroid logging. I am guessing the problem is in Selendroid. However, I am guessing the 600 second timeout and the retry are in Appium. Has anyone seen this problem?

5

I just reproduced the problem with Appium version 1.2.1. Selendroid version 0.11.0.

6

Can you use appium version 1.2.4?

7

I haven’t tried appium version 1.2.4, but I did reproduce the problem with the latest appium source.

8

Okay, can you post an issue to the github repo and link this thread? Thanks.

9

Hi All,

Is StaleElementReferenceException arise in Appium as like in Selenium?
Till now I didn’t get this Exception when it comes to Appium. Please let me know.

Thank you in advance,
Bhaskar.

10

Yes, I also think so.

In my app I opened the floating-menu, saved the expanded buttons references, closed the menu and then I tried to access the closed buttons and I got ‘NoSuchElementFoundException’ instead of ‘StateElementReferenceException.’

Second time I opened the floating-menu, saved the expanded buttons references, closed the menu and reopened it and then I tried to access the expanded buttons with old references, this time related page got opened instead of ‘StateElementReferenceException.’