Intermittent TEST-UNEXPECTED-TIMEOUT | /wasm/wasm_local_iframe_test.html | send wasm module to iframe - Test timed out

RESOLVED FIXED in Firefox 58

Status

defect
P5
normal
RESOLVED FIXED
2 years ago
2 years ago

People

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

Tracking

({intermittent-failure})

Version 3
mozilla59
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(firefox58 fixed, firefox59 fixed)

Details

(Whiteboard: [stockwell fixed:race])

Attachments

(1 attachment)

For the past week, 31 total failures were recorded in Orange factor.
Little spikes in test failures are seen on 18th and 23th of November but overall test fail rate is consistent.
The failures happen mostly on Linux and Linuxx64 platforms. Here is a recent log: https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=147268817&lineNumber=4703

[task 2017-11-24T00:49:04.663Z] 00:49:04     INFO - TEST-START | /wasm/wasm_local_iframe_test.html
[task 2017-11-24T00:49:14.831Z] 00:49:14     INFO - 
[task 2017-11-24T00:49:14.831Z] 00:49:14     INFO - TEST-UNEXPECTED-TIMEOUT | /wasm/wasm_local_iframe_test.html | send wasm module to iframe - Test timed out
[task 2017-11-24T00:49:14.832Z] 00:49:14     INFO - TEST-UNEXPECTED-TIMEOUT | /wasm/wasm_local_iframe_test.html | expected OK
[task 2017-11-24T00:49:14.832Z] 00:49:14     INFO - TEST-INFO took 10169ms
[task 2017-11-24T00:49:15.010Z] 00:49:15     INFO - PID 11987 | *** UTM:SVC TimerManager:registerTimer called after profile-before-change notification. Ignoring timer registration for id: telemetry_modules_ping
[task 2017-11-24T00:49:20.100Z] 00:49:20     INFO - Browser exited with return code 0
Flags: needinfo?(james)
Whiteboard: [stockwell needswork]
Flags: needinfo?(james) → needinfo?(luke)
Ah, this looks like a wpt the Googlers wrote that showed up in our repo via two-way sync.  I'll look into this.
Assignee: nobody → luke
Flags: needinfo?(luke)
Ah hah, I think I see a race condition in the wpt assuming the <iframe>'s <script> is run (adding a listener for 'message') before the iframe.postMessage() happens.
Posted patch fix-testSplinter Review
Is this the "right" way to only run some parent-window script after the iframe has finished loading?
Attachment #8932587 - Flags: review?(bzbarsky)
Would registering the handler before issuing postMessage also handle it?
I *think* (without being a DOM expert) that isn't a problem since there is no return to the event loop between the postMessage() and addEventListener().  Rather, the problem I think I identified is that frame.html's <script> might not have run by the time the postMessage() executes in the parent window causing frame.html's message event listener to never get called.
Ah! Makes sense.
Comment on attachment 8932587 [details] [diff] [review]
fix-test

r=me, though in an ideal world we'd instantiate the promise_test ASAP but not resolve the promise until the iframe finishes loading.... this should be good enough, though.
Attachment #8932587 - Flags: review?(bzbarsky) → review+
Using onloaded=runTests() in the only simple way I could find (with my limited DOM knowledge) to reliably wait for an <iframe> to be loaded because addEventListener("load") (which would be easier to do from within the promise_test()) has the converse race if the iframe has already been loaded.  Is there a more canonical way to do this when writing wpts?  Happy to change to that.
That part is just fine and the only really good way.  The issue is whether the promise_test call is inside runTests or up front.  I wouldn't worry about it.
Pushed by lwagner@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/e219b2b152d7
Fix race in wpt /wasm/wasm_local_iframe_test.html (r=bz)
https://hg.mozilla.org/mozilla-central/rev/e219b2b152d7
Status: NEW → RESOLVED
Closed: 2 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla59
Whiteboard: [stockwell needswork] → [stockwell fixed:race]
From the graph in comment 32, looks like the patch worked.
You need to log in before you can comment on or make changes to this bug.