Stale element problem / Understanding Webdriver-protocol

[Michael Baas]

I am struggling with a "stale element"-exception which I think is not justified (there is no page navigation going on, there is no code to mutate that element - so I claim it has not been mutated,  the element is visible in the browser and I can inspect various properties of it - but MoveToElement claims it's stale).

Finally I managed to get the driver-logs - but they dont seem help much - but of course this is my first attempt ever to read them, so I might be missing something.

Here's what I see:

1) Find Elements By CSS-Selector (there are 2 matching elements)

  [2020-06-12T08:20:25Z] [Info] [af6ffc091bbc0981313177cb4a9a9e6a] COMMAND FindElements {
   "using": "css selector",
   "value": "#links > li > a"
}


  [2020-06-12T08:20:25Z] [Info] Waiting for pending navigations...


  [2020-06-12T08:20:25Z] [Debug] DevTools WebSocket Command: Runtime.evaluate (id=85) 41B655605DA2DA2DB8FF4E2374B1F663 {
   "expression": "1"
}


  [2020-06-12T08:20:25Z] [Debug] DevTools WebSocket Response: Runtime.evaluate (id=85) 41B655605DA2DA2DB8FF4E2374B1F663 {
   "result": {
      "description": "1",
      "type": "number",
      "value": 1
   }
}


  [2020-06-12T08:20:25Z] [Info] Done waiting for pending navigations. Status: ok


  [2020-06-12T08:20:25Z] [Debug] DevTools WebSocket Command: Runtime.evaluate (id=86) 41B655605DA2DA2DB8FF4E2374B1F663 {
   "awaitPromise": true,
   "expression": "(function() { // Copyright (c) 2012 The Chromium Authors. All rights reserved.\n// Use of this source code is governed by a BSD-style license that can be\n// found in the LICENSE file.\n\n/**\n * Enum f...",
   "returnByValue": true
}


  [2020-06-12T08:20:25Z] [Debug] DevTools WebSocket Response: Runtime.evaluate (id=86) 41B655605DA2DA2DB8FF4E2374B1F663 {
   "result": {
      "type": "object",
      "value": {
         "status": 0,
         "value": [ {
            "element-6066-11e4-a52e-4f735466cecf": "6a78726d-c544-4905-85c5-eb0a9427badd"
         }, {
            "element-6066-11e4-a52e-4f735466cecf": "e2bbf8d5-0312-489f-9463-e434e7287975"
         } ]
      }
   }
}


  [2020-06-12T08:20:25Z] [Info] Waiting for pending navigations...


  [2020-06-12T08:20:25Z] [Debug] DevTools WebSocket Command: Runtime.evaluate (id=87) 41B655605DA2DA2DB8FF4E2374B1F663 {
   "expression": "1"
}


  [2020-06-12T08:20:25Z] [Debug] DevTools WebSocket Response: Runtime.evaluate (id=87) 41B655605DA2DA2DB8FF4E2374B1F663 {
   "result": {
      "description": "1",
      "type": "number",
      "value": 1
   }
}


  [2020-06-12T08:20:25Z] [Info] Done waiting for pending navigations. Status: ok


  [2020-06-12T08:20:25Z] [Info] [af6ffc091bbc0981313177cb4a9a9e6a] RESPONSE FindElements [ {
   "element-6066-11e4-a52e-4f735466cecf": "6a78726d-c544-4905-85c5-eb0a9427badd"
}, {
   "element-6066-11e4-a52e-4f735466cecf": "e2bbf8d5-0312-489f-9463-e434e7287975"
} ]

That seems to indicate that 2 elements were found. 1st question: this protocol refers to the page-elements using some IDs. Is there any way to get a dump of the DOM as seen by the driver...so that I could somehow work out the relation between these IDs and the elements on the page? Or is there any other way go get such info?

2) So then I tried to MoveTo the first element:

  [2020-06-12T08:20:45Z] [Info] [af6ffc091bbc0981313177cb4a9a9e6a] COMMAND PerformActions {
   "actions": [ {
      "actions": [ {
         "duration": 250,
         "origin": {
            "element-6066-11e4-a52e-4f735466cecf": "db248282-2ec7-40a6-9f44-3c2353901d8d"
         },
         "type": "pointerMove",
         "x": 0,
         "y": 0
      }, {
         "duration": 250,
         "origin": {
            "element-6066-11e4-a52e-4f735466cecf": "6a78726d-c544-4905-85c5-eb0a9427badd"
         },
         "type": "pointerMove",
         "x": 0,
         "y": 0
      }, {
         "duration": 250,
         "origin": {
            "element-6066-11e4-a52e-4f735466cecf": "6a78726d-c544-4905-85c5-eb0a9427badd"
         },
         "type": "pointerMove",
         "x": 0,
         "y": 0
      } ],
      "id": "default mouse",
      "parameters": {
         "pointerType": "mouse"
      },
      "type": "pointer"
   } ]
}


  [2020-06-12T08:20:45Z] [Info] Waiting for pending navigations...


  [2020-06-12T08:20:45Z] [Debug] DevTools WebSocket Command: Runtime.evaluate (id=88) 41B655605DA2DA2DB8FF4E2374B1F663 {
   "expression": "1"
}


  [2020-06-12T08:20:45Z] [Debug] DevTools WebSocket Response: Runtime.evaluate (id=88) 41B655605DA2DA2DB8FF4E2374B1F663 {
   "result": {
      "description": "1",
      "type": "number",
      "value": 1
   }
}


  [2020-06-12T08:20:45Z] [Info] Done waiting for pending navigations. Status: ok


  [2020-06-12T08:20:45Z] [Debug] DevTools WebSocket Command: Runtime.evaluate (id=89) 41B655605DA2DA2DB8FF4E2374B1F663 {
   "awaitPromise": true,
   "expression": "(function() { // Copyright (c) 2012 The Chromium Authors. All rights reserved.\n// Use of this source code is governed by a BSD-style license that can be\n// found in the LICENSE file.\n\n/**\n * Enum f...",
   "returnByValue": true
}


  [2020-06-12T08:20:45Z] [Debug] DevTools WebSocket Response: Runtime.evaluate (id=89) 41B655605DA2DA2DB8FF4E2374B1F663 {
   "result": {
      "type": "object",
      "value": {
         "status": 0,
         "value": {
            "view_height": 925,
            "view_width": 1920
         }
      }
   }
}


  [2020-06-12T08:20:45Z] [Debug] DevTools WebSocket Command: Runtime.evaluate (id=90) 41B655605DA2DA2DB8FF4E2374B1F663 {
   "awaitPromise": true,
   "expression": "(function() { // Copyright (c) 2012 The Chromium Authors. All rights reserved.\n// Use of this source code is governed by a BSD-style license that can be\n// found in the LICENSE file.\n\n/**\n * Enum f...",
   "returnByValue": true
}


  [2020-06-12T08:20:45Z] [Debug] DevTools WebSocket Response: Runtime.evaluate (id=90) 41B655605DA2DA2DB8FF4E2374B1F663 {
   "result": {
      "type": "object",
      "value": {
         "status": 10,
         "value": "element is not attached to the page document"
      }
   }
}


  [2020-06-12T08:20:45Z] [Debug] DevTools WebSocket Command: Runtime.evaluate (id=91) 41B655605DA2DA2DB8FF4E2374B1F663 {
   "expression": "1"
}


  [2020-06-12T08:20:45Z] [Debug] DevTools WebSocket Response: Runtime.evaluate (id=91) 41B655605DA2DA2DB8FF4E2374B1F663 {
   "result": {
      "description": "1",
      "type": "number",
      "value": 1
   }
}


  [2020-06-12T08:20:45Z] [Info] Waiting for pending navigations...


  [2020-06-12T08:20:45Z] [Debug] DevTools WebSocket Command: Runtime.evaluate (id=92) 41B655605DA2DA2DB8FF4E2374B1F663 {
   "expression": "1"
}


  [2020-06-12T08:20:45Z] [Debug] DevTools WebSocket Response: Runtime.evaluate (id=92) 41B655605DA2DA2DB8FF4E2374B1F663 {
   "result": {
      "description": "1",
      "type": "number",
      "value": 1
   }
}


  [2020-06-12T08:20:45Z] [Info] Done waiting for pending navigations. Status: ok


  [2020-06-12T08:20:45Z] [Info] [af6ffc091bbc0981313177cb4a9a9e6a] RESPONSE PerformActions ERROR stale element reference: element is not attached to the page document
  (Session info: chrome=83.0.4103.97)

Hmmm - I'm lost now! The data of element "Response: Runtime.evaluate (id=89)" looks rather good - but then "Response: Runtime.evaluate (id=90)" shows the error.  I fail to understand this. Besides, despite all efforts on google, I did not find a soure which would explain the level of protocol we are seeing here - any links would be appreciated.

TIA 

Michael

P.S: this log is from ChromeDriver, but I also tested Edge & Firefox and while details might be different, they also end up with stale-element...

[Michael Baas]

Actually...I just had an idea: the element that I am moving to does have an event listener for MouseOver which will add some output to the page. So when we're moving, the element exists - but because of the rebuilding of the DOM (caused by the additional output) it will get a different id - so perhaps a validation "did we arrive where we attempted to go to?" would fail. Not sure if that makes any sense, but I just saw a remark on StackOverflow about these IDs being "opaque" and only valid for the duration of a search.

But if that was true - does that mean that we can't test stuff when event-handlers modify the DOM?

[Rhicha Satam]

Hi,
Selenium -stale element reference error is thrown when the element is
no longer attached to a DOM.This Element is destroyed and then
recreated.
Therefore, its reference path is changed but old path is present in
the DOM, hence you need to refresh the path.
Solution is
wrap your . findElement call in a try-catch block and catch the
StaleElementReferenceException , then you can loop and retry as many
times as you need until it succeeds.

Regards,
Rhicha

> --
> You received this message because you are subscribed to the Google Groups "Selenium Users" group.
> To unsubscribe from this group and stop receiving emails from it, send an email to selenium-user...@googlegroups.com.
> To view this discussion on the web visit https://groups.google.com/d/msgid/selenium-users/6879f081-6e98-43ed-a7ba-9e35d9c9a416o%40googlegroups.com.

[Michael Baas]

Thanks Rhicha - but that doesn't work. No matter how often I repeat this Find/MoveTo-Sequence - it always goes wrong!

Meanwhile...I did more research and tried to build a small minimal repro - and that repro doesn't fail! 

Now...I also looked at the log of the working repro and I see one major difference:

working repro:

  [2020-06-12T09:55:30Z] [Info] [71c6b586c43f77be190d9ceba92d930e] RESPONSE FindElements [ {
   "element-6066-11e4-a52e-4f735466cecf": "49c2ce53-3ae1-4ae6-9a58-711219181e9d"
}, {
   "element-6066-11e4-a52e-4f735466cecf": "1ddc540a-879b-44aa-b855-6c6ca6472abb"
} ]


  [2020-06-12T09:55:30Z] [Info] [71c6b586c43f77be190d9ceba92d930e] COMMAND PerformActions {

   "actions": [ {
      "actions": [ {
         "duration": 250,
         "origin": {

            "element-6066-11e4-a52e-4f735466cecf": "49c2ce53-3ae1-4ae6-9a58-711219181e9d"
         },
         "type": "pointerMove",

Failing repro:

  [2020-06-12T08:20:25Z] [Info] [af6ffc091bbc0981313177cb4a9a9e6a] RESPONSE FindElements [ {
   "element-6066-11e4-a52e-4f735466cecf": "6a78726d-c544-4905-85c5-eb0a9427badd"
}, {
   "element-6066-11e4-a52e-4f735466cecf": "e2bbf8d5-0312-489f-9463-e434e7287975"
} ]

  [2020-06-12T08:20:45Z] [Info] [af6ffc091bbc0981313177cb4a9a9e6a] COMMAND PerformActions {

   "actions": [ {
      "actions": [ {
         "duration": 250,
         "origin": {
            "element-6066-11e4-a52e-4f735466cecf": "db248282-2ec7-40a6-9f44-3c2353901d8d"
         },
         "type": "pointerMove",

So the failing repro seems to not address the element that was found before - like the first repro shows.

What's interesting is that both repros were run against the same URL - so the HTML/JS (and the behaviour of event listeners) should be the same. But the "minimal repro" (which succeeds) succeeds consistently always - and the failing repro fails always as well! Yet...I don't see that I am doing something differently - my interpretation is that WebDriver behaves differently and "looses" the element - but I have no idea why and how. :((

> To unsubscribe from this group and stop receiving emails from it, send an email to seleniu...@googlegroups.com.

[Michael Baas]

I have now found the the explanation for the problem - but I don't fully understand it yet! Hopefully one of you has an idea...

Due to a very stupid bug on my end, the test (open URL, FindElements, MoveTo elements[0]) was ran twice. The first run was succesful, the 2nd failed .Because I only logged failures, I never noticed that first run.

Somehow Selenium's ids got mixed up in the 2nd run!

Here's a bit from the 1st run:

 [2020-06-15T10:25:03Z] [Info] [d7975788469801850f97e95e6406dd17] RESPONSE FindElements [ {
   "element-6066-11e4-a52e-4f735466cecf": "b45bb086-5d29-4c7a-be06-b50c0fa74c92"
}, {
   "element-6066-11e4-a52e-4f735466cecf": "d8d5715a-59f3-4bb4-905e-d2717daf3398"
} ]
  [2020-06-15T10:25:05Z] [Info] [d7975788469801850f97e95e6406dd17] COMMAND PerformActions {

   "actions": [ {
      "actions": [ {
         "duration": 250,
         "origin": {

            "element-6066-11e4-a52e-4f735466cecf": "b45bb086-5d29-4c7a-be06-b50c0fa74c92"
         },

And in the 2nd run, the Find/MoveTo-Segment is:

  [2020-06-15T10:28:39Z] [Info] [d7975788469801850f97e95e6406dd17] RESPONSE FindElements [ {
   "element-6066-11e4-a52e-4f735466cecf": "42d48cea-f446-4064-88cd-a886fe9e9749"
}, {
   "element-6066-11e4-a52e-4f735466cecf": "df218d10-81f9-46e8-a2e4-fec5eb437ad9"
} ]
  [2020-06-15T10:28:39Z] [Info] [d7975788469801850f97e95e6406dd17] COMMAND PerformActions {

   "actions": [ {
      "actions": [ {
         "duration": 250,
         "origin": {

            "element-6066-11e4-a52e-4f735466cecf": "b45bb086-5d29-4c7a-be06-b50c0fa74c92"

         },
         "type": "pointerMove",
         "x": 0,
         "y": 0
      },

For some reason the ids of the previous run are used here! On my end of the code, I am referring to a variable which holds the result of FindElementsByCssSelector - so MoveToElement then receiving an old result seems to be on a lower level then I can control.

Or could there be a race condition somehow by running the two tests consecutively - or do I need to do some sort of "resetting" in between? (I' re-using the Driver-instance, but variables  for Find-results are reset between runs - do I perhaps have initiate such a reset for other levels of the protocol?)