1369023 - Intermittent test_navigation.py TestRefresh.test_timeout_error | TimeoutException: Timed out after 7.7 seconds with message: No new tab has been opened

Status: VERIFIED INCOMPLETE

(Testing :: Marionette Client and Harness, defect)

Description

[Treeherder Bug Filer]

Filed by: cbook [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=103323801&repo=autoland

https://queue.taskcluster.net/v1/task/ePCaKDX9SAe8JOlqfEqKjw/runs/0/artifacts/public/logs/live_backing.log

Comment 1

[Henrik Skupin [:whimboo][⌚️UTC+2] (away 10/03 - 10/13)]

[task 2017-05-31T08:16:50.369145Z] 08:16:50     INFO - TEST-START | test_navigation.py TestRefresh.test_timeout_error
[task 2017-05-31T08:17:01.648584Z] 08:17:01     INFO - TEST-UNEXPECTED-ERROR | test_navigation.py TestRefresh.test_timeout_error | TimeoutException: Timed out after 7.7 seconds with message: No new tab has been opened
[task 2017-05-31T08:17:01.648674Z] 08:17:01     INFO - Traceback (most recent call last):
[task 2017-05-31T08:17:01.648750Z] 08:17:01     INFO -   File "/home/worker/workspace/build/venv/local/lib/python2.7/site-packages/marionette_harness/marionette_test/testcases.py", line 147, in run
[task 2017-05-31T08:17:01.648791Z] 08:17:01     INFO -     self.setUp()
[task 2017-05-31T08:17:01.648865Z] 08:17:01     INFO -   File "/home/worker/workspace/build/tests/marionette/tests/testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py", line 46, in setUp
[task 2017-05-31T08:17:01.648917Z] 08:17:01     INFO -     self.new_tab = self.open_tab(open_with_link)
[task 2017-05-31T08:17:01.648998Z] 08:17:01     INFO -   File "/home/worker/workspace/build/venv/local/lib/python2.7/site-packages/marionette_harness/runner/mixins/window_manager.py", line 88, in open_tab
[task 2017-05-31T08:17:01.649077Z] 08:17:01     INFO -     message="No new tab has been opened"
[task 2017-05-31T08:17:01.649146Z] 08:17:01     INFO -   File "/home/worker/workspace/build/venv/local/lib/python2.7/site-packages/marionette_driver/wait.py", line 150, in until
[task 2017-05-31T08:17:01.649186Z] 08:17:01     INFO -     cause=last_exc)

Here an excerpt from the gecko log:

1496218612469	Marionette	TRACE	1051 -> [0,14,"clickElement",{"id":"c8356f2b-ffa3-4227-a68d-9c578e6d4c7c"}]
1496218612753	Marionette	TRACE	1051 <- [1,14,null,{}]
1496218612758	Marionette	TRACE	1051 -> [0,15,"getWindowHandles",{}]
1496218612764	Marionette	TRACE	1051 <- [1,15,null,["10737418677"]]
++DOCSHELL 0xd646b400 == 27 [pid = 1143] [id = {3755dee8-d5a4-4112-924e-2521f3f6c6fd}]
++DOMWINDOW == 79 (0xd646d000) [pid = 1143] [serial = 539] [outer = (nil)]
[Parent 947] WARNING: [nsFrameLoader] ReallyStartLoadingInternal tried but couldn't show remote browser.
: file /home/worker/workspace/build/src/dom/base/nsFrameLoader.cpp, line 785
++DOMWINDOW == 80 (0xd6470c00) [pid = 1143] [serial = 540] [outer = 0xd646d000]
1496218620289	Marionette	DEBUG	loaded listener.js
1496218620393	Marionette	TRACE	1051 -> [0,16,"getWindowHandles",{}]
1496218620403	Marionette	TRACE	1051 <- [1,16,null,["10737418677"]]

There is a 7s gap between the both calls to getWindowHandles. So this is similar to bug 1368227.

Comment 2

[Intermittent Failures Robot]

3 failures in 814 pushes (0.004 failures/push) were associated with this bug in the last 7 days.   

Repository breakdown:
* autoland: 2
* try: 1

Platform breakdown:
* linux32: 3

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1369023&startday=2017-06-12&endday=2017-06-18&tree=all

Comment 3

[Intermittent Failures Robot]

1 failures in 656 pushes (0.002 failures/push) were associated with this bug in the last 7 days.   

Repository breakdown:
* mozilla-inbound: 1

Platform breakdown:
* linux32: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1369023&startday=2017-07-03&endday=2017-07-09&tree=all

Comment 4

[BMO Automation]

Moving bug to Testing::Marionette Client and Harness component per bug 1815831.