1384875 - Intermittent test_tabbar_session_restore_button.py TestTabbarSessionRestoreButton.test_window_resizing | AssertionError: u'visible' != 'hidden'

Reporter

Description

•

7 years ago

treeherder

Filed by: cbook [at] mozilla.com

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

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

Comment hidden (Intermittent Failures Robot)

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

Repository breakdown:
* autoland: 9
* mozilla-central: 6
* mozilla-inbound: 5
* try: 1

Platform breakdown:
* linux64: 14
* linux32: 7

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

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

Comment 2

•

7 years ago

This started July 27th. Erica, do you know if something has been changed for the button at this time? It's visible when it should be hidden. Maybe it's related to the window size?

[task 2017-07-27T09:35:49.103230Z] 09:35:49     INFO - TEST-UNEXPECTED-FAIL | test_tabbar_session_restore_button.py TestTabbarSessionRestoreButton.test_window_resizing | AssertionError: u'visible' != 'hidden'
[task 2017-07-27T09:35:49.104485Z] 09:35:49     INFO - Traceback (most recent call last):
[task 2017-07-27T09:35:49.108787Z] 09:35:49     INFO -   File "/home/worker/workspace/build/venv/local/lib/python2.7/site-packages/marionette_harness/marionette_test/testcases.py", line 156, in run
[task 2017-07-27T09:35:49.108847Z] 09:35:49     INFO -     testMethod()
[task 2017-07-27T09:35:49.109270Z] 09:35:49     INFO -   File "/home/worker/workspace/build/tests/firefox-ui/tests/functional/sessionstore/test_tabbar_session_restore_button.py", line 77, in test_window_resizing
[task 2017-07-27T09:35:49.109346Z] 09:35:49     INFO -     self.assertEqual(wrapper.value_of_css_property('visibility'), 'hidden')

Flags: needinfo?(ewright)

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

Comment 3

•

7 years ago

Attached image screenshot.png — Details

Erica Wright [:ewright]

Comment 4

•

7 years ago

Nothing has been changed for the button. It could be window size, if the window does not successfully resize small then the button will show.

Flags: needinfo?(ewright)

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

Comment 5

•

7 years ago

Hm, so the failing lines are:

>        self.marionette.set_window_size(335, 335)
>        self.assertEqual(wrapper.value_of_css_property('visibility'), 'hidden')

Given the screenshot for this failure the window is of size 1200 x 1200 and not 335 x 335.

Andreas, is that another instance of a race condition when we return to early from set window size? Will it be fixed by one of your patches?

Flags: needinfo?(ato)

Andreas Tolfsen ❲:ato❳

Comment 6

•

7 years ago

(In reply to Henrik Skupin (:whimboo) from comment #5)

> Hm, so the failing lines are:
> 
> >        self.marionette.set_window_size(335, 335)
> >        self.assertEqual(wrapper.value_of_css_property('visibility'), 'hidden')
> 
> Given the screenshot for this failure the window is of size 1200 x
> 1200 and not 335 x 335.
> 
> Andreas, is that another instance of a race condition when we
> return to early from set window size? Will it be fixed by one of
> your patches?

I think that’s a reasonable assumption considering it only fails
on Linux, where we now window resizing happens asynchronously.

Despite all the changes I have made to increase the determinism
of WebDriver:SetWindowRect, the core of the problem here is that
we can’t rely on window.{outerWidth,outerHeight} when polling
for the window’s size to have changed.  These two DOM properties
are populated with the new size before the resize transition has
completed.

As you can tell from
https://searchfox.org/mozilla-central/rev/f0e4ae5f8c40ba742214e89aba3f554da0b89a33/testing/marionette/driver.js#1345-1457,
we have put into place a large number of guards to prevent this:
it first waits for the "resize" DOM event to fire, then throttles
the event by requesting an animation frame after the main thread is
idle.  Then as a last safeguard it poll-waits for the window’s
size to have changed from its original dimensions.

Unfortunately, I don’t have any more good ideas for how to make
this more reliable.  I should add that this is also an unsolved
problem in GTK and internally in mochitests for window.resizeTo.

Flags: needinfo?(ato)

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

Comment 7

•

7 years ago

So it means none of the latest patches as landed in the last days which covered window resizing fixed that yet?

Flags: needinfo?(ato)

Andreas Tolfsen ❲:ato❳

Comment 8

•

7 years ago

(In reply to Henrik Skupin (:whimboo) from comment #7)
> So it means none of the latest patches as landed in the last days which
> covered window resizing fixed that yet?

Apparently not.

I would like to see how this intermittent evolves over the next week or so.

Flags: needinfo?(ato)

Firefox Bug Husbandry Bot

Updated

•

7 years ago

Status: NEW → RESOLVED

Closed: 7 years ago

Keywords: bulk-close-intermittents

Resolution: --- → INCOMPLETE

Comment hidden (Intermittent Failures Robot)

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

Repository breakdown:
* mozilla-beta: 4

Platform breakdown:
* linux32-nightly: 3
* linux64-nightly: 1

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

Comment hidden (Intermittent Failures Robot)

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

Repository breakdown:
* mozilla-beta: 1

Platform breakdown:
* linux32-nightly: 1

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

Phil Ringnalda (:philor)

Updated

•

7 years ago

Status: RESOLVED → REOPENED

Resolution: INCOMPLETE → ---

Comment hidden (Intermittent Failures Robot)

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

Repository breakdown:
* mozilla-central: 1

Platform breakdown:
* linux64: 1

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

Comment hidden (Intermittent Failures Robot)

21 failures in 116 pushes (0.181 failures/push) were associated with this bug yesterday.    

Repository breakdown:
* autoland: 21

Platform breakdown:
* linux64: 9
* linux32: 5
* windows7-32: 4
* windows10-64: 3

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

Dorel Luca [:dluca]

Comment 13

•

7 years ago

This bug failed 35 times in the last 7 days. Most than half of the fails are happening on Linux, the rest on Windows. The build types are asan, debug, opt and pgo.

Here is a recent log:
https://treeherder.mozilla.org/logviewer.html#?repo=autoland&job_id=142005695&lineNumber=44659

And here is a part of the log:

[task 2017-11-03T17:41:30.266Z] 17:41:30     INFO -  1509730890258	Marionette	TRACE	1 <- [1,47,null,{}]
[task 2017-11-03T17:41:30.267Z] 17:41:30     INFO -  1509730890260	Marionette	TRACE	1 -> [0,48,"takeScreenshot",{"highlights":null,"full":true,"hash":false,"id":null,"scroll":true}]
[task 2017-11-03T17:41:30.326Z] 17:41:30     INFO -  1509730890319	Marionette	TRACE	1 <- [1,48,null,{"value":"iVBORw0KGgoAAAANSUhEUgAABLAAAASwCAYAAADrIbPPAAAgAElEQVR4nOzdy29c54HmYS8b6P8jQBpo9M6zmAF600tvG7PshSEu1bMJtHSAWXmX7hkDI/fCgAQYi ... AAABgTWABAAAAsCawAAAAAFgTWAAAAACsCSwAAAAA1gQWAAAAAGsCCwAAAIA1gQUAAADAmsACAAAAYE1gAQAAALAmsAAAAABYC3l3cyVvUe7QAAAAAElFTkSuQmCC"}]
[task 2017-11-03T17:41:30.342Z] 17:41:30     INFO -  1509730890331	Marionette	TRACE	1 -> [0,49,"setContext",{"value":"chrome"}]
[task 2017-11-03T17:41:30.343Z] 17:41:30     INFO -  1509730890332	Marionette	TRACE	1 <- [1,49,null,{}]
[task 2017-11-03T17:41:30.344Z] 17:41:30     INFO -  1509730890333	Marionette	TRACE	1 -> [0,50,"getContext",{}]
[task 2017-11-03T17:41:30.344Z] 17:41:30     INFO -  1509730890333	Marionette	TRACE	1 <- [1,50,null,{"value":"chrome"}]
[task 2017-11-03T17:41:30.345Z] 17:41:30     INFO -  1509730890334	Marionette	TRACE	1 -> [0,51,"setContext",{"value":"content"}]
[task 2017-11-03T17:41:30.346Z] 17:41:30     INFO -  1509730890334	Marionette	TRACE	1 <- [1,51,null,{}]
[task 2017-11-03T17:41:30.347Z] 17:41:30     INFO -  1509730890335	Marionette	TRACE	1 -> [0,52,"getPageSource",{}]
[task 2017-11-03T17:41:30.357Z] 17:41:30     INFO - TEST-UNEXPECTED-FAIL | test_tabbar_session_restore_button.py TestTabbarSessionRestoreButton.test_window_resizing | AssertionError: u'hidden' != 'visible'
[task 2017-11-03T17:41:30.357Z] 17:41:30     INFO - Traceback (most recent call last):
[task 2017-11-03T17:41:30.358Z] 17:41:30     INFO -   File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_harness/marionette_test/testcases.py", line 156, in run
[task 2017-11-03T17:41:30.358Z] 17:41:30     INFO -     testMethod()
[task 2017-11-03T17:41:30.358Z] 17:41:30     INFO -   File "/builds/worker/workspace/build/tests/firefox-ui/tests/functional/sessionstore/test_tabbar_session_restore_button.py", line 73, in test_window_resizing
[task 2017-11-03T17:41:30.358Z] 17:41:30     INFO -     self.assertEqual(wrapper.value_of_css_property('visibility'), 'visible')
[task 2017-11-03T17:41:30.358Z] 17:41:30     INFO - TEST-INFO took 9142ms
[task 2017-11-03T17:41:30.358Z] 17:41:30     INFO -  1509730890339	Marionette	TRACE	1 <- [1,52,null,{"value":"<html><head></head><body></body></html>"}]
[task 2017-11-03T17:41:30.359Z] 17:41:30     INFO -  1509730890339	Marionette	TRACE	1 -> [0,53,"setContext",{"value":"chrome"}]
[task 2017-11-03T17:41:30.359Z] 17:41:30     INFO -  1509730890340	Marionette	TRACE	1 <- [1,53,null,{}]
[task 2017-11-03T17:41:30.360Z] 17:41:30     INFO -  1509730890348	Marionette	TRACE	1 -> [0,54,"getContext",{}]
[task 2017-11-03T17:41:30.361Z] 17:41:30     INFO -  1509730890348	Marionette	TRACE	1 <- [1,54,null,{"value":"chrome"}]
[task 2017-11-03T17:41:30.361Z] 17:41:30     INFO -  1509730890350	Marionette	TRACE	1 -> [0,55,"deleteSession",{}]
[task 2017-11-03T17:41:30.362Z] 17:41:30     INFO -  1509730890353	Marionette	TRACE	1 <- [1,55,null,{}]

:gbrown: Hi, can you please take a look at this bug?

Flags: needinfo?(gbrown)

Whiteboard: [stockwell needswork]

Geoff Brown [:gbrown] (pto Apr 11-18)

Comment 14

•

7 years ago

It looks like this sudden spike started with the change from bug 1414252. 

https://treeherder.mozilla.org/#/jobs?repo=autoland&filter-searchStr=firefox-ui&tochange=bedc52fb5267646d5689e4450a455daf66e8e2ac&fromchange=4635df9d3bb6919a7480cdd41cb8c4af5e2d4e71

That change was backed out and the test is no longer failing.

Flags: needinfo?(gbrown)

Updated

•

7 years ago

Whiteboard: [stockwell needswork] → [stockwell fixed:backout]

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

Comment 16

•

7 years ago

There was a single failure about 25 days ago. Since then it didn't happen anymore beside the issue and backout mentioned above. Lets close as WFM.

Status: REOPENED → RESOLVED

Closed: 7 years ago → 7 years ago

Resolution: --- → WORKSFORME

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

Updated

•

7 years ago

Status: RESOLVED → VERIFIED

Andreea Pavel [:apavel]

Comment 17

•

6 years ago

Recent failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=157630039&repo=autoland&lineNumber=44102

[task 2018-01-21T16:09:37.028Z] 16:09:37     INFO -  1516550977025	Marionette	TRACE	1 <- [1,40,null,{}]
[task 2018-01-21T16:09:37.030Z] 16:09:37     INFO -  1516550977026	Marionette	TRACE	1 -> [0,41,"findElement",{"using":"css selector","value":":root"}]
[task 2018-01-21T16:09:37.032Z] 16:09:37     INFO -  1516550977029	Marionette	TRACE	1 <- [1,41,null,{"value":{"chromeelement-9fc5-4b51-a3c8-01716eedeb04":"a1f2616a-a592-413f-ab7e-ab8967a4b34b","ELEMENT":"a1f2616a-a592-413f-ab7e-ab8967a4b34b"}}]
[task 2018-01-21T16:09:37.033Z] 16:09:37     INFO -  1516550977031	Marionette	TRACE	1 -> [0,42,"findElement",{"using":"id","value":"tabbrowser-tabs","element":"a1f2616a-a592-413f-ab7e-ab8967a4b34b"}]
[task 2018-01-21T16:09:37.041Z] 16:09:37     INFO -  1516550977036	Marionette	TRACE	1 <- [1,42,null,{"value":{"chromeelement-9fc5-4b51-a3c8-01716eedeb04":"75ced88e-242c-4ef6-836b-ca4a4014c008","ELEMENT":"75ced88e-242c-4ef6-836b-ca4a4014c008"}}]
[task 2018-01-21T16:09:37.042Z] 16:09:37     INFO -  1516550977037	Marionette	TRACE	1 -> [0,43,"findElement",{"using":"anon attribute","value":{"anonid":"restore-tabs-button-wrapper"},"element":"75ced88e-242c-4ef6-836b-ca4a4014c008"}]
[task 2018-01-21T16:09:37.043Z] 16:09:37     INFO -  1516550977039	Marionette	TRACE	1 <- [1,43,null,{"value":{"chromeelement-9fc5-4b51-a3c8-01716eedeb04":"ab11f65d-2442-41ac-8d92-c25ffa6aa421","ELEMENT":"ab11f65d-2442-41ac-8d92-c25ffa6aa421"}}]
[task 2018-01-21T16:09:37.043Z] 16:09:37     INFO -  1516550977040	Marionette	TRACE	1 -> [0,44,"setWindowSize",{"width":1200,"height":1200}]
[task 2018-01-21T16:09:37.083Z] 16:09:37     INFO -  1516550977077	Marionette	TRACE	1 <- [1,44,null,{"x":0,"y":0,"width":1200,"height":1200,"state":"normal"}]
[task 2018-01-21T16:09:37.083Z] 16:09:37     INFO -  1516550977080	Marionette	TRACE	1 -> [0,45,"getElementValueOfCssProperty",{"propertyName":"visibility","id":"ab11f65d-2442-41ac-8d92-c25ffa6aa421"}]
[task 2018-01-21T16:09:37.091Z] 16:09:37     INFO -  1516550977085	Marionette	TRACE	1 <- [1,45,null,{"value":"visible"}]
[task 2018-01-21T16:09:37.092Z] 16:09:37     INFO -  1516550977086	Marionette	TRACE	1 -> [0,46,"setWindowSize",{"width":335,"height":335}]
[task 2018-01-21T16:09:37.198Z] 16:09:37     INFO -  1516550977194	Marionette	TRACE	1 <- [1,46,null,{"x":0,"y":0,"width":335,"height":335,"state":"normal"}]
[task 2018-01-21T16:09:37.200Z] 16:09:37     INFO -  1516550977196	Marionette	TRACE	1 -> [0,47,"getElementValueOfCssProperty",{"propertyName":"visibility","id":"ab11f65d-2442-41ac-8d92-c25ffa6aa421"}]
[task 2018-01-21T16:09:37.202Z] 16:09:37     INFO -  1516550977197	Marionette	TRACE	1 <- [1,47,null,{"value":"visible"}]
[task 2018-01-21T16:09:37.217Z] 16:09:37     INFO -  1516550977207	Marionette	TRACE	1 -> [0,48,"getContext",{}]
[task 2018-01-21T16:09:37.218Z] 16:09:37     INFO -  1516550977207	Marionette	TRACE	1 <- [1,48,null,{"value":"chrome"}]
[task 2018-01-21T16:09:37.219Z] 16:09:37     INFO -  1516550977212	Marionette	TRACE	1 -> [0,49,"setContext",{"value":"chrome"}]
[task 2018-01-21T16:09:37.219Z] 16:09:37     INFO -  1516550977212	Marionette	TRACE	1 <- [1,49,null,{}]
[task 2018-01-21T16:09:37.220Z] 16:09:37     INFO -  1516550977213	Marionette	TRACE	1 -> [0,50,"takeScreenshot",{"highlights":null,"full":true,"hash":false,"id":null,"scroll":true}]
[task 2018-01-21T16:09:37.237Z] 16:09:37     INFO -  1516550977230	Marionette	TRACE	1 <- [1,50,null,{"value":"iVBORw0KGgoAAAANSUhEUgAAAU8AAAFPCAYAAADNzUzyAAAPoUlEQVR4nO3dvW8c953AYZUB8n8YcIAgna64A9KkdBtcmUKw/gPXMnBN ... dAgHgCBIgnQIB4AgSIJ0CAeAIEiCdAgHgCBIgnQIB4AgSIJ0CAeAIEiCdAgHgCBIgnQIB4AgSIJ0CAeAIEiCdAgHgCBPw/L3L3rkQ1rXAAAAAASUVORK5CYII="}]
[task 2018-01-21T16:09:37.238Z] 16:09:37     INFO -  1516550977232	Marionette	TRACE	1 -> [0,51,"setContext",{"value":"chrome"}]
[task 2018-01-21T16:09:37.238Z] 16:09:37     INFO -  1516550977232	Marionette	TRACE	1 <- [1,51,null,{}]
[task 2018-01-21T16:09:37.239Z] 16:09:37     INFO -  1516550977233	Marionette	TRACE	1 -> [0,52,"getContext",{}]
[task 2018-01-21T16:09:37.240Z] 16:09:37     INFO -  1516550977233	Marionette	TRACE	1 <- [1,52,null,{"value":"chrome"}]
[task 2018-01-21T16:09:37.241Z] 16:09:37     INFO -  1516550977234	Marionette	TRACE	1 -> [0,53,"setContext",{"value":"content"}]
[task 2018-01-21T16:09:37.241Z] 16:09:37     INFO -  1516550977235	Marionette	TRACE	1 <- [1,53,null,{}]
[task 2018-01-21T16:09:37.242Z] 16:09:37     INFO -  1516550977235	Marionette	TRACE	1 -> [0,54,"getPageSource",{}]
[task 2018-01-21T16:09:37.259Z] 16:09:37     INFO - TEST-UNEXPECTED-FAIL | testing/firefox-ui/tests/functional/sessionstore/test_tabbar_session_restore_button.py TestTabbarSessionRestoreButton.test_window_resizing | AssertionError: u'visible' != 'hidden'
[task 2018-01-21T16:09:37.260Z] 16:09:37     INFO - Traceback (most recent call last):
[task 2018-01-21T16:09:37.261Z] 16:09:37     INFO -   File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_harness/marionette_test/testcases.py", line 159, in run
[task 2018-01-21T16:09:37.262Z] 16:09:37     INFO -     testMethod()
[task 2018-01-21T16:09:37.262Z] 16:09:37     INFO -   File "/builds/worker/workspace/build/tests/firefox-ui/tests/testing/firefox-ui/tests/functional/sessionstore/test_tabbar_session_restore_button.py", line 77, in test_window_resizing
[task 2018-01-21T16:09:37.263Z] 16:09:37     INFO -     self.assertEqual(wrapper.value_of_css_property('visibility'), 'hidden')
[task 2018-01-21T16:09:37.263Z] 16:09:37     INFO - TEST-INFO took 9921ms
[task 2018-01-21T16:09:37.264Z] 16:09:37     INFO -  1516550977245	Marionette	TRACE	1 <- [1,54,null,{"value":"<html><head></head><body></body></html>"}]
[task 2018-01-21T16:09:37.264Z] 16:09:37     INFO -  1516550977246	Marionette	TRACE	1 -> [0,55,"setContext",{"value":"chrome"}]
[task 2018-01-21T16:09:37.265Z] 16:09:37     INFO -  1516550977247	Marionette	TRACE	1 <- [1,55,null,{}]
[task 2018-01-21T16:09:37.266Z] 16:09:37     INFO -  1516550977250	Marionette	TRACE	1 -> [0,56,"getContext",{}]
[task 2018-01-21T16:09:37.267Z] 16:09:37     INFO -  1516550977251	Marionette	TRACE	1 <- [1,56,null,{"value":"chrome"}]
[task 2018-01-21T16:09:37.267Z] 16:09:37     INFO -  1516550977253	Marionette	TRACE	1 -> [0,57,"deleteSession",{}]
[task 2018-01-21T16:09:37.268Z] 16:09:37     INFO -  1516550977254	Marionette	TRACE	1 <- [1,57,null,{}]

Status: VERIFIED → REOPENED

Resolution: WORKSFORME → ---

Comment hidden (Intermittent Failures Robot)

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

Repository breakdown:
* autoland: 1

Platform breakdown:
* linux64: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1384875&startday=2018-01-15&endday=2018-01-21&tree=all

Comment hidden (Intermittent Failures Robot)

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

Repository breakdown:
* autoland: 1

Platform breakdown:
* linux64: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1384875&startday=2018-01-29&endday=2018-02-04&tree=all

Firefox Bug Husbandry Bot

Comment 20

•

6 years ago

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup

Status: REOPENED → RESOLVED

Closed: 7 years ago → 6 years ago

Resolution: --- → INCOMPLETE

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

Comment 21

•

5 years ago

(In reply to Geoff Brown [:gbrown] from comment #14)

It looks like this sudden spike started with the change from bug 1414252.

https://treeherder.mozilla.org/#/jobs?repo=autoland&filter-searchStr=firefox-
ui&tochange=bedc52fb5267646d5689e4450a455daf66e8e2ac&fromchange=4635df9d3bb69
19a7480cdd41cb8c4af5e2d4e71

That change was backed out and the test is no longer failing.

We should have closed this bug as fixed then. Doing it now.

Assignee: nobody → dao+bmo

Resolution: INCOMPLETE → FIXED