Closed Bug 1031137 Opened 10 years ago Closed 10 years ago

Intermittent 1028458.html | load failed: timed out waiting for reftest-wait to be removed

Categories

(Core :: WebRTC: Audio/Video, defect)

Product:
Core
Component:
WebRTC: Audio/Video
Platform:
x86_64
Linux
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

()

Status:
RESOLVED FIXED
Milestone:
mozilla33
Tracking Flags:
Tracking Status
firefox31 --- unaffected
firefox32 --- fixed
firefox33 --- fixed
firefox-esr24 --- unaffected
firefox-esr31 --- unaffected
b2g-v2.0 --- fixed
b2g-v2.1 --- fixed

People

(Reporter: nigelb, Assigned: padenot)

References

(
URL
)

Details

(Keywords: intermittent-failure)

Attachments

(2 files, 1 obsolete file)

Backout investigation code added in 3904c720efa4
1.68 KB, patch
Details | Diff | Splinter Review
Make content/media/test/crashtests/1028458.html pass if audio input hardware is unavailable.
978 bytes, patch
jesup
: review+
Details | Diff | Splinter Review 
Windows 7 32-bit mozilla-central opt test crashtest on 2014-06-26 18:41:25 PDT for push 092005229ae6

slave: t-w732-ix-126

https://tbpl.mozilla.org/php/getParsedLog.php?id=42581534&tree=Mozilla-Central

18:45:26     INFO -  REFTEST INFO | Loading a blank page
18:45:26     INFO -  REFTEST TEST-END | file:///C:/slave/test/build/tests/reftest/tests/content/media/test/crashtests/offline-buffer-source-ended-1.html
18:45:26     INFO -  REFTEST TEST-START | file:///C:/slave/test/build/tests/reftest/tests/content/media/test/crashtests/media-element-source-seek-1.html
18:45:26     INFO -  REFTEST TEST-LOAD | http://localhost:49658/1403833479626/4/media-element-source-seek-1.html | 446 / 2667 (16%)
18:45:26     INFO -  REFTEST TEST-PASS | file:///C:/slave/test/build/tests/reftest/tests/content/media/test/crashtests/media-element-source-seek-1.html | (LOAD ONLY)
18:45:26     INFO -  REFTEST INFO | Loading a blank page
18:45:26     INFO -  REFTEST TEST-END | file:///C:/slave/test/build/tests/reftest/tests/content/media/test/crashtests/media-element-source-seek-1.html
18:45:26     INFO -  REFTEST TEST-START | file:///C:/slave/test/build/tests/reftest/tests/content/media/test/crashtests/oscillator-ended-1.html
18:45:26     INFO -  REFTEST TEST-LOAD | file:///C:/slave/test/build/tests/reftest/tests/content/media/test/crashtests/oscillator-ended-1.html | 447 / 2667 (16%)
18:45:27     INFO -  REFTEST TEST-PASS | file:///C:/slave/test/build/tests/reftest/tests/content/media/test/crashtests/oscillator-ended-1.html | (LOAD ONLY)
18:45:27     INFO -  REFTEST INFO | Loading a blank page
18:45:27     INFO -  REFTEST TEST-END | file:///C:/slave/test/build/tests/reftest/tests/content/media/test/crashtests/oscillator-ended-1.html
18:45:27     INFO -  REFTEST TEST-START | file:///C:/slave/test/build/tests/reftest/tests/content/media/test/crashtests/oscillator-ended-2.html
18:45:27     INFO -  REFTEST TEST-LOAD | file:///C:/slave/test/build/tests/reftest/tests/content/media/test/crashtests/oscillator-ended-2.html | 448 / 2667 (16%)
18:45:27     INFO -  REFTEST TEST-PASS | file:///C:/slave/test/build/tests/reftest/tests/content/media/test/crashtests/oscillator-ended-2.html | (LOAD ONLY)
18:45:27     INFO -  REFTEST INFO | Loading a blank page
18:45:27     INFO -  REFTEST TEST-END | file:///C:/slave/test/build/tests/reftest/tests/content/media/test/crashtests/oscillator-ended-2.html
18:45:27     INFO -  REFTEST TEST-START | file:///C:/slave/test/build/tests/reftest/tests/content/media/test/crashtests/1015662.html
18:45:27     INFO -  REFTEST TEST-LOAD | file:///C:/slave/test/build/tests/reftest/tests/content/media/test/crashtests/1015662.html | 449 / 2667 (16%)
18:45:27     INFO -  REFTEST TEST-PASS | file:///C:/slave/test/build/tests/reftest/tests/content/media/test/crashtests/1015662.html | (LOAD ONLY)
18:45:27     INFO -  REFTEST INFO | Loading a blank page
18:45:27     INFO -  REFTEST TEST-END | file:///C:/slave/test/build/tests/reftest/tests/content/media/test/crashtests/1015662.html
18:45:27     INFO -  REFTEST TEST-START | file:///C:/slave/test/build/tests/reftest/tests/content/media/mediasource/test/crashtests/926665.html
18:45:27     INFO -  SET PREFERENCE pref(media.mediasource.enabled,true)
18:45:27     INFO -  REFTEST TEST-LOAD | file:///C:/slave/test/build/tests/reftest/tests/content/media/mediasource/test/crashtests/926665.html | 450 / 2667 (16%)
18:45:27     INFO -  REFTEST TEST-PASS | file:///C:/slave/test/build/tests/reftest/tests/content/media/mediasource/test/crashtests/926665.html | (LOAD ONLY)
18:45:27     INFO -  REFTEST INFO | Loading a blank page
18:45:27     INFO -  REFTEST TEST-END | file:///C:/slave/test/build/tests/reftest/tests/content/media/mediasource/test/crashtests/926665.html
18:45:27     INFO -  REFTEST TEST-START | file:///C:/slave/test/build/tests/reftest/tests/content/media/mediasource/test/crashtests/1005366.html
18:45:27     INFO -  RESTORE PREFERENCE pref(media.mediasource.enabled,false)
18:45:27     INFO -  SET PREFERENCE pref(media.mediasource.enabled,true)
18:45:27     INFO -  REFTEST TEST-LOAD | file:///C:/slave/test/build/tests/reftest/tests/content/media/mediasource/test/crashtests/1005366.html | 451 / 2667 (16%)
18:45:27     INFO -  JavaScript error: file:///C:/slave/test/build/tests/reftest/tests/content/media/mediasource/test/crashtests/1005366.html, line 20: NS_ERROR_FAILURE:
18:45:27     INFO -  REFTEST TEST-PASS | file:///C:/slave/test/build/tests/reftest/tests/content/media/mediasource/test/crashtests/1005366.html | (LOAD ONLY)
18:45:27     INFO -  REFTEST INFO | Loading a blank page
18:45:27     INFO -  REFTEST TEST-END | file:///C:/slave/test/build/tests/reftest/tests/content/media/mediasource/test/crashtests/1005366.html
18:45:27     INFO -  REFTEST TEST-START | file:///C:/slave/test/build/tests/reftest/tests/content/media/test/crashtests/1028458.html
18:45:27     INFO -  RESTORE PREFERENCE pref(media.mediasource.enabled,false)
18:45:27     INFO -  SET PREFERENCE pref(media.navigator.permission.disabled,true)
18:50:27     INFO -  REFTEST TEST-LOAD | file:///C:/slave/test/build/tests/reftest/tests/content/media/test/crashtests/1028458.html | 452 / 2667 (16%)
18:50:27     INFO -  REFTEST TEST-UNEXPECTED-FAIL | file:///C:/slave/test/build/tests/reftest/tests/content/media/test/crashtests/1028458.html | load failed: timed out waiting for reftest-wait to be removed
18:50:27     INFO -  REFTEST INFO | Saved log: START file:///C:/slave/test/build/tests/reftest/tests/content/media/test/crashtests/1028458.html
18:50:27     INFO -  REFTEST INFO | Saved log: [CONTENT] OnDocumentLoad triggering WaitForTestEnd
18:50:27     INFO -  REFTEST INFO | Saved log: [CONTENT] WaitForTestEnd: Adding listeners
18:50:27     INFO -  REFTEST INFO | Saved log: Initializing canvas snapshot
18:50:27     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_TO_FIRE_INVALIDATE_EVENT
18:50:27     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: dispatching MozReftestInvalidate
18:50:27     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_FOR_REFTEST_WAIT_REMOVAL
18:50:27     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: waiting for reftest-wait to be removed
18:50:27     INFO -  REFTEST INFO | Saved log: [CONTENT] AfterPaintListener in file:///C:/slave/test/build/tests/reftest/tests/content/media/test/crashtests/1028458.html
18:50:27     INFO -  REFTEST INFO | Saved log: [CONTENT] SendUpdateCanvasForEvent with 1 rects
18:50:27     INFO -  REFTEST INFO | Saved log: [CONTENT] Rect: 0 0 800 1000
18:50:27     INFO -  REFTEST INFO | Saved log: Updating canvas for invalidation
18:50:27     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_FOR_REFTEST_WAIT_REMOVAL
18:50:27     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: waiting for reftest-wait to be removed
18:50:27     INFO -  REFTEST INFO | Loading a blank page
18:50:27     INFO -  REFTEST TEST-END | file:///C:/slave/test/build/tests/reftest/tests/content/media/test/crashtests/1028458.html
18:50:27     INFO -  REFTEST TEST-START | file:///C:/slave/test/build/tests/reftest/tests/docshell/base/crashtests/40929-1.html
18:50:27     INFO -  RESTORE PREFERENCE pref(media.navigator.permission.disabled,false)
18:50:27     INFO -  REFTEST TEST-LOAD | file:///C:/slave/test/build/tests/reftest/tests/docshell/base/crashtests/40929-1.html | 453 / 2667 (16%)
18:50:27     INFO -  REFTEST TEST-PASS | file:///C:/slave/test/build/tests/reftest/tests/docshell/base/crashtests/40929-1.html | (LOAD ONLY)
18:50:27     INFO -  REFTEST INFO | Loading a blank page
18:50:27     INFO -  REFTEST TEST-END | file:///C:/slave/test/build/tests/reftest/tests/docshell/base/crashtests/40929-1.html
18:50:27     INFO -  REFTEST TEST-START | file:///C:/slave/test/build/tests/reftest/tests/docshell/base/crashtests/369126-1.html
18:50:28     INFO -  REFTEST TEST-LOAD | file:///C:/slave/test/build/tests/reftest/tests/docshell/base/crashtests/369126-1.html | 454 / 2667 (17%)
18:50:28     INFO -  JavaScript error: data:text/html,<body%20onUnload="location%20=%20'http://www.mozilla.org/'">This%20frame's%20onunload%20tries%20to%20load%20another%20page., line 1: NS_ERROR_NOT_AVAILABLE: Component returned failure code: 0x80040111 (NS_ERROR_NOT_AVAILABLE) [nsIDOMLocation.href]
18:50:28     INFO -  REFTEST TEST-PASS | file:///C:/slave/test/build/tests/reftest/tests/docshell/base/crashtests/369126-1.html | (LOAD ONLY)
18:50:28     INFO -  REFTEST INFO | Loading a blank page
18:50:28     INFO -  REFTEST TEST-END | file:///C:/slave/test/build/tests/reftest/tests/docshell/base/crashtests/369126-1.html
18:50:28     INFO -  REFTEST TEST-START | file:///C:/slave/test/build/tests/reftest/tests/docshell/base/crashtests/403574-1.xhtml
18:50:28     INFO -  REFTEST TEST-LOAD | file:///C:/slave/test/build/tests/reftest/tests/docshell/base/crashtests/403574-1.xhtml | 455 / 2667 (17%)
18:50:28     INFO -  REFTEST TEST-PASS | file:///C:/slave/test/build/tests/reftest/tests/docshell/base/crashtests/403574-1.xhtml | (LOAD ONLY)
18:50:28     INFO -  REFTEST INFO | Loading a blank page
18:50:28     INFO -  REFTEST TEST-END | file:///C:/slave/test/build/tests/reftest/tests/docshell/base/crashtests/403574-1.xhtml
18:50:28     INFO -  REFTEST TEST-START | file:///C:/slave/test/build/tests/reftest/tests/docshell/base/crashtests/430124-1.html
18:50:28     INFO -  REFTEST TEST-LOAD | file:///C:/slave/test/build/tests/reftest/tests/docshell/base/crashtests/430124-1.html | 456 / 2667 (17%)
18:50:28     INFO -  REFTEST TEST-PASS | file:///C:/slave/test/build/tests/reftest/tests/docshell/base/crashtests/430124-1.html | (LOAD ONLY)
18:50:28     INFO -  REFTEST INFO | Loading a blank page
18:50:28     INFO -  REFTEST TEST-END | file:///C:/slave/test/build/tests/reftest/tests/docshell/base/crashtests/430124-1.html
18:50:28     INFO -  REFTEST TEST-START | file:///C:/slave/test/build/tests/reftest/tests/docshell/base/crashtests/430628-1.html
Tweaking the summary a bit to follow our usual standards :)
Blocks: 1028458
Summary: INTERMITTENT REFTEST TEST-UNEXPECTED-FAIL | content/media/test/crashtests/1028458.html | load failed: timed out waiting for reftest-wait to be removed → Intermittent 1028458.html | load failed: timed out waiting for reftest-wait to be removed
JW -- Does this test look correct, or do you believe this test has problems?  (Roc, cpearce, padenot -- Please feel free to chime in if you have opinions on this.)  Thanks!
Flags: needinfo?(jwwang)
The test case looks OK to me provided a disabled track will not block the stream. Paul should know better about the detail.
Flags: needinfo?(jwwang) → needinfo?(paul)
Funny thing is that's mostly windows 7 only with a dash of b2g emulator. We should try to put some instrumentation for some time to check what's up.
Flags: needinfo?(paul)
Paul's writing a patch now to add instrumentation so we can get better visibility into what's going on here.
Assignee: nobody → paul
https://hg.mozilla.org/mozilla-central/rev/3904c720efa4
Status: NEW → RESOLVED
Closed: 10 years ago
Flags: in-testsuite+
Resolution: --- → FIXED
Target Milestone: --- → mozilla33
(In reply to TBPL Robot from comment #108)
> RyanVM
> https://tbpl.mozilla.org/php/getParsedLog.php?id=43295382&tree=Mozilla-
> Central
> Windows 7 32-bit mozilla-central opt test crashtest on 2014-07-07 17:38:37
> revision: 7f9db2379b3f
> slave: t-w732-ix-038
> 
> REFTEST TEST-UNEXPECTED-FAIL |
> file:///C:/slave/test/build/tests/reftest/tests/content/media/test/
> crashtests/1028458.html | load failed: timed out waiting for reftest-wait to
> be removed

This is post-merge. Hopefully the logging helps.
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
Target Milestone: mozilla33 → ---
It says:

> HARDWARE_UNAVAILABLE

which is not a suprise, given that Windows 7 audio stack on the output side is good, but its reliability is a joke when it comes to open a new stream [1]. Apparently the same problem exists on the input side as well.

Since this is a known issue, and we can't do much about it, I'm simply going to catch explicitly the exception and remove reftest-wait. We will get coverage most of the time, but this will stop the oranges. This is okay, because testing if we can open a stream is done in dozens of other tests, we are specifically testing the behavior of disabled tracks, here.

[1]: bug 992238
Comment on attachment 8452249 [details] [diff] [review]
Make content/media/test/crashtests/1028458.html pass if audio input hardware is unavailable. r=

This patch is empty.
Attachment #8452249 - Attachment is obsolete: true
Attachment #8452249 - Flags: review?(rjesup)
It is, apparently my mq thing is broken. Thanks for noticing thing Ryan!
Attachment #8452254 - Flags: review?(rjesup)
Attachment #8452254 - Flags: review?(rjesup) → review+
https://hg.mozilla.org/mozilla-central/rev/cd8e323d27c3
https://hg.mozilla.org/mozilla-central/rev/a2432accf35c
Status: REOPENED → RESOLVED
Closed: 10 years ago → 10 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla33
Better than it was, but still happening :(
Status: RESOLVED → REOPENED
status-b2g-v2.0: fixed → affected
status-b2g-v2.1: fixed → affected
status-firefox32: fixed → affected
status-firefox33: fixed → affected
Resolution: FIXED → ---
Target Milestone: mozilla33 → ---
OK, so it only fails on the emulator, with this in the log:

> JavaScript error: chrome://b2g/content/shell.js, line 560: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIXPCComponents_Utils.cloneInto]

and I'm afraid I know nothing about this xpconnect magic.
JW -- It looks like Paul was able to fix this for everything except the b2g emulator.  Any idea what the remaining issue is?   (See Comment 151 for the last info from Paul.)
Flags: needinfo?(jwwang)
I'm wondering if we should spin off a second bug for the B2G emulator failure
I have no idea about the XPConnect either. It surely will help to spin off a bug and ask for help from XPCOM guys.
Flags: needinfo?(jwwang)
(In reply to Maire Reavy [:mreavy] (Plz needinfo me) from comment #164)
> I'm wondering if we should spin off a second bug for the B2G emulator failure

Agreed. Filed bug 1048863.
Status: REOPENED → RESOLVED
Closed: 10 years ago → 10 years ago
status-b2g-v2.0: affected → fixed
status-b2g-v2.1: affected → fixed
status-firefox32: affected → fixed
status-firefox33: affected → fixed
status-firefox-esr31: --- → unaffected
Resolution: --- → FIXED
Target Milestone: --- → mozilla33
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: