Closed Bug 1303942 Opened 5 years ago Closed 5 years ago

[e10s] Intermittent test_navigation.py TestNavigate.test_set_location_through_execute_script | TimeoutException: Timed out after 5.0 seconds

Categories

(Testing :: Marionette, defect)

Version 3
defect
Not set
normal

Tracking

(firefox50 wontfix, firefox51 wontfix, firefox52 wontfix, firefox-esr52 wontfix, firefox53 fixed, firefox54 fixed, firefox55 fixed)

RESOLVED FIXED
mozilla55
Tracking Status
firefox50 --- wontfix
firefox51 --- wontfix
firefox52 --- wontfix
firefox-esr52 --- wontfix
firefox53 --- fixed
firefox54 --- fixed
firefox55 --- fixed

People

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

References

Details

(Keywords: intermittent-failure)

 05:05:33     INFO -   File "/builds/slave/test/build/tests/marionette/tests/testing/marionette/harness/marionette/tests/unit/test_navigation.py", line 26, in test_set_location_through_execute_script
05:05:33 INFO - Wait(self.marionette).until(lambda _: self.test_doc == self.location_href)

It fails here:

https://dxr.mozilla.org/mozilla-central/rev/d38d06f85ef59c5dbb5d4a1a8d895957a78714de/testing/marionette/harness/marionette/tests/unit/test_navigation.py#26

The new URL gets set via `execute_script("window.location.href = '%s'" % self.test_doc)`. 

Maybe it's a side-effect of bug 1145668 and manifests as a race in rare conditions.
This is strange. We exactly call execute_script once and get about:blank returned:

1479398164260	Marionette	TRACE	conn730 -> [0,6,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"test_navigation.py","script":"window.location.href = 'http://127.0.0.1:46050/test.html'","sandbox":"default","line":25}]
1479398164448	Marionette	TRACE	conn730 <- [1,6,null,{"value":null}]
1479398164775	Marionette	TRACE	conn730 -> [0,7,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"test_navigation.py","script":"return window.location.href","sandbox":"default","line":145}]
1479398169779	Marionette	TRACE	conn730 <- [1,7,null,{"value":"about:blank"}]
1479398169832	Marionette	TRACE	conn730 -> [0,8,"getContext",null]
1479398169839	Marionette	TRACE	conn730 <- [1,8,null,{"value":"content"}]
1479398170161	Marionette	TRACE	conn730 -> [0,9,"setContext",{"value":"chrome"}]
1479398170177	Marionette	TRACE	conn730 <- [1,9,null,{}]

As you can see the call to execute_script() took about 5s and it only called once because we directly run into the timeout. So something in that code caused Marionette not to return the href immediately but delayed it.
This is all about e10s, and doesn't fail if it is disabled.
Summary: Intermittent test_navigation.py TestNavigate.test_set_location_through_execute_script | TimeoutException: Timed out after 5.0 seconds → [e10s] Intermittent test_navigation.py TestNavigate.test_set_location_through_execute_script | TimeoutException: Timed out after 5.0 seconds
Too late for firefox 52, mass-wontfix.
This should be fixed with my patch on bug 1354310.
Assignee: nobody → hskupin
Status: NEW → ASSIGNED
Depends on: 1354310
Status: ASSIGNED → RESOLVED
Closed: 5 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla55
The patch on bug 1354310 will not be uplifted to esr52.
You need to log in before you can comment on or make changes to this bug.