1456400 - Intermittent TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/close_window/user_prompts.py | expected OK

Status: RESOLVED FIXED

(Remote Protocol :: Marionette, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: shindli [at] mozilla.com

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

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

06:00:20     INFO -  Buffered messages logged at 05:55:21
06:00:20     INFO -  57 INFO got stalled event
06:00:20     INFO -  Buffered messages finished
06:00:20    ERROR -  58 INFO TEST-UNEXPECTED-FAIL | dom/media/mediasource/test/test_FrameSelection_mp4.html | Test timed out.
06:00:20     INFO -      reportError@SimpleTest/TestRunner.js:121:7
06:00:20     INFO -      TestRunner._checkForHangs@SimpleTest/TestRunner.js:142:7

Comment 1

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

The reference in comment 0 is wrong. So here an update which shows that the failure is actually again a shutdown hang of Firefox:

[task 2018-04-24T07:00:31.762Z] 07:00:31     INFO - PID 1194 | 1524553231753   
Marionette    TRACE    0 -> [0,12,"Marionette:Quit",{"flags":["eForceQuit"]}]
[task 2018-04-24T07:00:31.763Z] 07:00:31     INFO - PID 1194 | 1524553231754   
Marionette    TRACE    0 <- [1,12,{"error":"invalid session
id","message":"","stacktrace":"WebDriverError@chrome://marionette/content/error.js:178:5\nInv
...
et@chrome://marionette/content/server.js:245:8\n_onJSONObjectReady/<@chrome://marionette/content/transport.js:500:9\n"},null]
[task 2018-04-24T07:00:31.764Z] 07:00:31     INFO - PID 1194 | 1524553231754   
geckodriver::marionette    TRACE    <- [1,12,{"error":"invalid session
id","message":"","stacktrace":"WebDriverError@chrome://marionette/content/error.js:178:5\nInvalidSessionIDError@chrome://marionette/content/error.js:347:5\nassert.that/<@chrome://marionette/content/assert.js:405:13\nassert.session@chrome://marionette/content/assert.js:79:3\ndespatch@chrome://marionette/content/server.js:294:7\nasync*execute@chrome://marionette/content/server.js:271:11\nasync*onPacket/<@chrome://marionette/content/server.js:246:15\nasync*onPacket@chrome://marionette/content/server.js:245:8\n_onJSONObjectReady/<@chrome://marionette/content/transport.js:500:9\n"},null]
[task 2018-04-24T07:00:31.782Z] 07:00:31     INFO - PID 1194 | 1524553231771   
Marionette    DEBUG    Closed connection 0
[task 2018-04-24T07:00:57.853Z] 07:00:57     INFO - TEST-UNEXPECTED-TIMEOUT |
/webdriver/tests/close_window/user_prompts.py | expected OK

So nothing we can do here right now. If it fails only intermittently we can
land, otherwise we might have to temporarily mark it as disabled.

Comment 2

[Intermittent Failures Robot]

35 failures in 183 pushes (0.191 failures/push) were associated with this bug yesterday.    

Repository breakdown:
* autoland: 26
* mozilla-central: 4
* mozilla-inbound: 3
* try: 2

Platform breakdown:
* linux32: 22
* linux64: 13

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1456400&startday=2018-04-24&endday=2018-04-24&tree=trunk

Comment 3

[Tiberius Oros[:tiberius_oros]]

Started to retrigger jobs for this failure: 
https://treeherder.mozilla.org/#/jobs?repo=autoland&revision=295fd2df534f6a5f59f9d620be955a3e70ade74b&filter-searchStr=linux32%20opt-web-platform-tests-wdspec-e10s

on this interval: 
https://treeherder.mozilla.org/#/jobs?repo=autoland&filter-searchStr=linux32%20opt-web-platform-tests-wdspec-e10s&tochange=295fd2df534f6a5f59f9d620be955a3e70ade74b&fromchange=4cc04fbbd1d7d6a4af9dbb0cbea52905cff3fef7&selectedJob=175271063

and end up with this push being the culprit:
https://treeherder.mozilla.org/#/jobs?repo=autoland&revision=295fd2df534f6a5f59f9d620be955a3e70ade74b&filter-searchStr=linux32%20opt-web-platform-tests-wdspec-e10s

It failed 4 out 6 times and on the retriggered jobs it failed 0 times.

Comment 4

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

This is a new test as added by that push, right. Given that it fails that much, and we do not see a crash report due to the shutdown hang of Firefox, a good idea would be to increase the timeout of the test. At least then we might have a chance to see a crash as caused by the hang reporter.

Comment 5

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

Given that it continuous to have a high failure rate I will come up with a patch later today which requests a longer timeout for this test.

Comment 6

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

https://treeherder.mozilla.org/#/jobs?repo=try&revision=d9f6cac65cb23c80c77ec4dda280d04eafe03918

Comment 7

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

I missed to update the manifest. Here another try:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=cda6069e1715042cb74254f04292a8deb51bcec4

Comment 8

[Intermittent Failures Robot]

23 failures in 132 pushes (0.174 failures/push) were associated with this bug yesterday.    

Repository breakdown:
* autoland: 14
* mozilla-central: 4
* mozilla-inbound: 3
* try: 2

Platform breakdown:
* linux32: 15
* linux64: 8

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1456400&startday=2018-04-25&endday=2018-04-25&tree=trunk

Comment 9

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

Attachment: Bug 1456400 - [wdspec] Increase timeout for close_window/user_prompts.py test.

Review commit: https://reviewboard.mozilla.org/r/240300/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/240300/

Comment 10

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

The try build looks fine and I'm going to increase the timeout now.

Comment 11

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

Comment on attachment 8971547 [details]
Bug 1456400 - [wdspec] Increase timeout for close_window/user_prompts.py test.

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/240300/diff/1-2/

Comment 12

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

Comment on attachment 8971547 [details]
Bug 1456400 - [wdspec] Increase timeout for close_window/user_prompts.py test.

https://reviewboard.mozilla.org/r/240300/#review246098

Comment 13

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

We have to leave this bug open until bug 1449538 has been fixed.

Comment 14

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/b27cb10f8110
[wdspec] Increase timeout for close_window/user_prompts.py test. r=whimboo

Comment 15

[Andreea Pavel [:apavel]]

https://hg.mozilla.org/mozilla-central/rev/b27cb10f8110

Comment 16

[Intermittent Failures Robot]

60 failures in 780 pushes (0.077 failures/push) were associated with this bug in the last 7 days. 

This is the #18 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: 39
* mozilla-central: 10
* mozilla-inbound: 6
* try: 5

Platform breakdown:
* linux32: 38
* linux64: 21
* linux64-nightly: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1456400&startday=2018-04-23&endday=2018-04-29&tree=trunk

Comment 17

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

Fixed by bug 1449538. I will keep the longer timeout present for now.

Comment 18

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

It was actually Jan who fixed the underlying shutdown hang in QuotaManager.

Comment 19

[Web Platform Test Sync Bot [:wpt-sync] (Matrix: #interop:mozilla.org)]

Created web-platform-tests PR https://github.com/w3c/web-platform-tests/pull/10941 for changes under testing/web-platform/tests

Comment 20

[Web Platform Test Sync Bot [:wpt-sync] (Matrix: #interop:mozilla.org)]

Upstream PR merged

Comment 21

[BMO Automation]

Moving bug to Remote Protocol::Marionette component per bug 1815831.