Closed Bug 1353447 Opened 4 years ago Closed 4 years ago

Intermittent TestBackForwardNavigation.test_timeout_error | NoSuchElementException: Unable to locate element: delay


(Testing :: Marionette, defect)

Version 3
Not set


(firefox-esr52 fix-optional, firefox54 fixed, firefox55 fixed)

Tracking Status
firefox-esr52 --- fix-optional
firefox54 --- fixed
firefox55 --- fixed


(Reporter: intermittent-bug-filer, Assigned: whimboo)



(Keywords: intermittent-failure, Whiteboard: [stockwell fixed])


(1 file)

08:05:07     INFO -  Traceback (most recent call last):
08:05:07     INFO -    File "c:\slave\test\build\venv\lib\site-packages\marionette_harness\marionette_test\", line 166, in run
08:05:07     INFO -      testMethod()
08:05:07     INFO -    File "c:\slave\test\build\tests\marionette\tests\testing\marionette\harness\marionette_harness\tests\unit\", line 464, in test_timeout_error
08:05:07     INFO -      self.assertEqual(self.marionette.find_element(By.ID, "delay").text, "4")
08:05:07     INFO -    File "c:\slave\test\build\venv\lib\site-packages\marionette_driver\", line 1938, in find_element
08:05:07     INFO -      return self._send_message("findElement", body, key="value")
08:05:07     INFO -    File "c:\slave\test\build\venv\lib\site-packages\marionette_driver\", line 23, in _
08:05:07     INFO -      return func(*args, **kwargs)
08:05:07     INFO -    File "c:\slave\test\build\venv\lib\site-packages\marionette_driver\", line 735, in _send_message
08:05:07     INFO -      self._handle_error(err)
08:05:07     INFO -    File "c:\slave\test\build\venv\lib\site-packages\marionette_driver\", line 768, in _handle_error
08:05:07     INFO -      raise errors.lookup(error)(message, stacktrace=stacktrace)

Interesting here is that this is happening now after a forward navigation. So it means we somehow return too early from it, and the element 'delay' is not present yet. This might have been caused by the patches on bug 1291320. It looks like a low intermittent failure.
I ran into this in my data from activedata about failures in real time.
Whiteboard: [stockwell needswork]
:whimboo, can you put this in your queue to debug or help find the right person to look at this?  The failure rate is steady and I see us needing to address this in the coming weeks.
Flags: needinfo?(hskupin)
Here the exact failing code:

This is all after the last call to `goBack()`. Given that a timeout error was raised, the command returns before the expected page has been fully loaded. So we have this extra call to `getCurrentUrl`. 

Now the interesting fact is that this command doesn't care about the page load status. And as such returns the new URL once it appears in the location bar. The test now tries to find the element `delay` which might not be present yet.

To fix that we should move the `find_element()` call into `Wait().until()`.

I will try to have a fix by today.
Assignee: nobody → hskupin
Flags: needinfo?(hskupin)
Comment on attachment 8860897 [details]
Bug 1353447 - Fix race condition in TestBackForwardNavigation.test_timeout_error.
Attachment #8860897 - Flags: review?(ato) → review+
Pushed by
Fix race condition in TestBackForwardNavigation.test_timeout_error. r=ato
Closed: 4 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla55
Whiteboard: [stockwell needswork] → [stockwell fixed]
If you want this to land on esr52 too, it'll need a rebased patch.
Flags: needinfo?(hskupin)
So far there are no crashes on mozilla-esr52, so I don't think it's useful to spend the time on a backport patch. If it starts failing there, we can re-evaluate.
Flags: needinfo?(hskupin)
You need to log in before you can comment on or make changes to this bug.