1353599 - Intermittent test_about_private_browsing.py TestAboutPrivateBrowsing.testCheckAboutPrivateBrowsing | TimeoutException: Timeout loading page after 300000ms

Status: RESOLVED FIXED

(Testing :: Firefox UI Tests, defect)

Description

[Treeherder Bug Filer]

Filed by: philringnalda [at] gmail.com

https://treeherder.mozilla.org/logviewer.html#?job_id=88682813&repo=mozilla-inbound

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

Comment 1

[Henrik Skupin [:whimboo][⌚️UTC+2]]

This happens when the test tried to load `about:privatebrowsing`:

[task 2017-04-04T21:23:23.103541Z] 21:23:23     INFO - Traceback (most recent call last):
[task 2017-04-04T21:23:23.103628Z] 21:23:23     INFO -   File "/home/worker/workspace/build/venv/local/lib/python2.7/site-packages/marionette_harness/marionette_test/testcases.py", line 166, in run
[task 2017-04-04T21:23:23.103682Z] 21:23:23     INFO -     testMethod()
[task 2017-04-04T21:23:23.103763Z] 21:23:23     INFO -   File "/home/worker/workspace/build/tests/firefox-ui/tests/functional/private_browsing/test_about_private_browsing.py", line 35, in testCheckAboutPrivateBrowsing
[task 2017-04-04T21:23:23.103813Z] 21:23:23     INFO -     self.marionette.navigate('about:privatebrowsing')
[task 2017-04-04T21:23:23.103881Z] 21:23:23     INFO -   File "/home/worker/workspace/build/venv/local/lib/python2.7/site-packages/marionette_driver/marionette.py", line 1721, in navigate
[task 2017-04-04T21:23:23.103928Z] 21:23:23     INFO -     self._send_message("get", {"url": url})
[task 2017-04-04T21:23:23.103992Z] 21:23:23     INFO -   File "/home/worker/workspace/build/venv/local/lib/python2.7/site-packages/marionette_driver/decorators.py", line 23, in _
[task 2017-04-04T21:23:23.104035Z] 21:23:23     INFO -     return func(*args, **kwargs)
[task 2017-04-04T21:23:23.104671Z] 21:23:23     INFO -   File "/home/worker/workspace/build/venv/local/lib/python2.7/site-packages/marionette_driver/marionette.py", line 735, in _send_message
[task 2017-04-04T21:23:23.105472Z] 21:23:23     INFO -     self._handle_error(err)
[task 2017-04-04T21:23:23.106038Z] 21:23:23     INFO -   File "/home/worker/workspace/build/venv/local/lib/python2.7/site-packages/marionette_driver/marionette.py", line 768, in _handle_error
[task 2017-04-04T21:23:23.106451Z] 21:23:23     INFO -     raise errors.lookup(error)(message, stacktrace=stacktrace)

Actually there are the following lines right before:

[task 2017-04-04T21:23:19.396901Z] 21:23:19     INFO -  JavaScript error: chrome://marionette/content/proxy.js, line 195: NS_ERROR_ILLEGAL_VALUE: Component returned failure code: 0x80070057 (NS_ERROR_ILLEGAL_VALUE) [nsIMessageSender.sendAsyncMessage]

So this is related to bug 1353635, and we might need a fix for bug 1336137 (including the case when the framescript got reloaded).

Comment 2

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Hm, whereby there is also the following line:

> Full message: TypeError: NetworkError when attempting to fetch resource.

Not sure if that is related.

Comment 3

[Intermittent Failures Robot]

5 failures in 867 pushes (0.006 failures/push) were associated with this bug in the last 7 days.   

Repository breakdown:
* mozilla-inbound: 5

Platform breakdown:
* linux32: 5

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

Comment 4

[Intermittent Failures Robot]

5 failures in 883 pushes (0.006 failures/push) were associated with this bug in the last 7 days.   

Repository breakdown:
* autoland: 2
* try: 1
* mozilla-inbound: 1
* mozilla-central: 1

Platform breakdown:
* linux32: 3
* windows8-64: 1
* osx-10-10: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1353599&startday=2017-04-24&endday=2017-04-30&tree=all

Comment 5

[Intermittent Failures Robot]

5 failures in 891 pushes (0.006 failures/push) were associated with this bug in the last 7 days.   

Repository breakdown:
* mozilla-inbound: 3
* try: 1
* autoland: 1

Platform breakdown:
* linux64: 3
* linux32: 2

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1353599&startday=2017-05-22&endday=2017-05-28&tree=all

Comment 6

[Henrik Skupin [:whimboo][⌚️UTC+2]]

[task 2017-05-28T11:22:27.752101Z] 11:22:27     INFO -  1495970547749	Marionette	TRACE	81 -> [0,84,"get",{"url":"about:privatebrowsing"}]
[task 2017-05-28T11:22:27.759752Z] 11:22:27     INFO -  1495970547756	Marionette	DEBUG	Received DOM event "beforeunload" for "about:"
[task 2017-05-28T11:22:27.795444Z] 11:22:27     INFO -  1495970547793	Marionette	DEBUG	Received DOM event "pagehide" for "about:"
[task 2017-05-28T11:22:27.796770Z] 11:22:27     INFO -  1495970547793	Marionette	DEBUG	Received DOM event "unload" for "about:"
[task 2017-05-28T11:22:27.798974Z] 11:22:27     INFO -  ++DOCSHELL 0x7fb3e7493800 == 1 [pid = 1903] [id = {c3a06a58-8e0c-4dc4-991f-6ebb9cdd347b}]
[task 2017-05-28T11:22:27.875699Z] 11:22:27     INFO -  1495970547866	Marionette	DEBUG	Received observer notification "outer-window-destroyed" for "293"
[task 2017-05-28T11:22:27.875833Z] 11:22:27     INFO -  ++DOMWINDOW == 1 (0x7fb3e74a5000) [pid = 1903] [serial = 1] [outer = (nil)]
[task 2017-05-28T11:22:28.098488Z] 11:22:28     INFO -  ++DOMWINDOW == 2 (0x7fb3dac68800) [pid = 1903] [serial = 2] [outer = 0x7fb3e74a5000]
[task 2017-05-28T11:22:28.134121Z] 11:22:28     INFO -  1495970548127	Marionette	DEBUG	loaded listener.js
[..]
[task 2017-05-28T11:27:29.510079Z] 11:27:29     INFO -  1495970849507	Marionette	TRACE	81 <- [1,84,{"error":"timeout","message":"Timeout loading page after 300000ms","stacktrace":"WebDriverError@chrome://marionette/content/error.js:222:5\nTimeoutError@chrome://marionette/content/error.js:472:5\nnotify@chrome://marionette/content/listener.js:297:17\n"},null]

There is no further DOM event for the page load being received after the frame script got reloaded. Maybe it's a race between reloading the frame script, and registering the DOM events.

Comment 7

[Intermittent Failures Robot]

14 failures in 864 pushes (0.016 failures/push) were associated with this bug in the last 7 days.   

Repository breakdown:
* mozilla-inbound: 9
* autoland: 4
* mozilla-central: 1

Platform breakdown:
* linux32: 10
* windows10-64-vm: 3
* linux64: 1

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

Comment 8

[Intermittent Failures Robot]

16 failures in 142 pushes (0.113 failures/push) were associated with this bug yesterday.   

Repository breakdown:
* autoland: 9
* mozilla-inbound: 5
* mozilla-central: 2

Platform breakdown:
* linux32: 7
* windows7-32-vm: 5
* windows10-64-vm: 4

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

Comment 9

[Intermittent Failures Robot]

18 failures in 168 pushes (0.107 failures/push) were associated with this bug yesterday.   

Repository breakdown:
* autoland: 10
* mozilla-inbound: 6
* try: 2

Platform breakdown:
* linux32: 9
* windows10-64-vm: 5
* linux64: 4

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

Comment 10

[Intermittent Failures Robot]

15 failures in 131 pushes (0.115 failures/push) were associated with this bug yesterday.   

Repository breakdown:
* autoland: 7
* try: 4
* mozilla-inbound: 3
* mozilla-beta: 1

Platform breakdown:
* linux64: 7
* linux32: 5
* windows7-32-vm: 2
* windows10-64-vm: 1

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

Comment 11

[Joel Maher ( :jmaher ) (UTC -8)]

this bug is failing @ 15failures/day+, I would like to see this fixed or disable next week.  I see it depends on bug 1368434 which has no action for almost 3 weeks.

:whimboo- can you get this resolved next week?

Comment 12

[Intermittent Failures Robot]

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

This is the #31 most frequent failure this week.  

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. ** 

Repository breakdown:
* autoland: 32
* mozilla-inbound: 21
* try: 8
* mozilla-central: 2
* mozilla-beta: 1

Platform breakdown:
* linux32: 33
* linux64: 12
* windows10-64-vm: 11
* windows7-32-vm: 8

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

Comment 13

[Joel Maher ( :jmaher ) (UTC -8)]

:whimboo any updates here?

Comment 14

[Henrik Skupin [:whimboo][⌚️UTC+2]]

(In reply to Joel Maher ( :jmaher) from comment #13)
> :whimboo any updates here?

It has the same underlying issue as bug 1360446 (TestLegacyClick.test_click). Not sure when I will have this fixed.

Comment 15

[Henrik Skupin [:whimboo][⌚️UTC+2]]

The test actually started to fail on April 4th but with a low intermittent failure rate. So it looks like a regression from bug 1291320.

But what I wonder is what actually caused such a high spike of failures between June 9th and 11th:

https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1353599&startday=2017-04-03&endday=2017-06-21&tree=all

Comment 16

[Joel Maher ( :jmaher ) (UTC -8)]

this is still failing often, about 40 failures since Monday- I assume the same rate as last week- is there a potential fix upcoming for this bug?

Comment 17

[Henrik Skupin [:whimboo][⌚️UTC+2]]

This still depends on a fix for bug 1368434 most likely.

Comment 18

[Joel Maher ( :jmaher ) (UTC -8)]

given there is no action in bug 1368434 for 11 days, I have little confidence this will get fixed soon- Given the failure rate is high for coming on 2 weeks in a row, I would like to disable this test.

Comment 19

[Joel Maher ( :jmaher ) (UTC -8)]

Attachment: temporarily disable test

Comment 20

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/755b2bdfc2ad
Intermittent test_about_private_browsing.py TestAboutPrivateBrowsing.testCheckAboutPrivateBrowsing. temporarily disable. r=gbrown

Comment 21

[Intermittent Failures Robot]

41 failures in 892 pushes (0.046 failures/push) were associated with this bug in the last 7 days. 

This is the #50 most frequent failure this week.  

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. ** 

Repository breakdown:
* autoland: 17
* mozilla-inbound: 16
* mozilla-central: 5
* try: 2
* mozilla-beta: 1

Platform breakdown:
* linux32: 17
* osx-10-10: 11
* linux64: 5
* windows10-64-vm: 4
* windows7-32-vm: 2
* linux64-ccov: 2

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

Comment 22

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/755b2bdfc2ad

Comment 23

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Not fixed, but the test got disabled.

Comment 24

[Intermittent Failures Robot]

2 failures in 718 pushes (0.003 failures/push) were associated with this bug in the last 7 days.   

Repository breakdown:
* mozilla-beta: 1
* autoland: 1

Platform breakdown:
* osx-10-10: 1
* linux64: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1353599&startday=2017-06-26&endday=2017-07-02&tree=all

Comment 25

[Intermittent Failures Robot]

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

Repository breakdown:
* mozilla-beta: 1

Platform breakdown:
* linux64: 1

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

Comment 26

[Intermittent Failures Robot]

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

Repository breakdown:
* mozilla-beta: 1

Platform breakdown:
* windows10-64-vm: 1

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

Comment 27

[Henrik Skupin [:whimboo][⌚️UTC+2]]

This failure was actually fixed by my patch on bug 1368434.

Comment 28

[Intermittent Failures Robot]

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

Repository breakdown:
* mozilla-release: 1

Platform breakdown:
* windows10-64-vm: 1

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