Closed Bug 845676 Opened 7 years ago Closed 7 years ago

frequent assertions in media mochitests on Windows

Categories

(Core :: Audio/Video, defect)

x86
Windows 7
defect
Not set

Tracking

()

RESOLVED FIXED
mozilla22

People

(Reporter: dbaron, Assigned: padenot)

References

Details

(Keywords: assertion, regression)

Attachments

(2 files, 2 obsolete files)

https://hg.mozilla.org/integration/mozilla-inbound/rev/0d0eadfaa41d caused a significant number of new assertions in media mochitests on Windows only.  (This is making my life a bit difficult in terms of trying to land bug 404077.)

Based on the tinderbox builds on mozilla-inbound, the assertions started within this range:
https://hg.mozilla.org/integration/mozilla-inbound/pushloghtml?fromchange=743eb982010a&tochange=0d0eadfaa41d
and based on this try push:
https://tbpl.mozilla.org/?tree=Try&rev=d55274ba38fb
which did not show the assertions, I determined that they are regression from https://hg.mozilla.org/integration/mozilla-inbound/rev/0d0eadfaa41d in particular.

In particular, I believe these assertions are a regression from that changeset:

[ WIN ] /tests/content/media/test/test_a4_tone.html | Assertion count 0-2 is greater than expected range 0-0 assertions.
[ WIN ] /tests/content/media/test/test_framebuffer.html | Assertion count 0-2 is greater than expected range 0-0 assertions.
[ WIN ] /tests/content/media/test/test_invalid_reject.html | Assertion count 0-20 is greater than expected range 0-0 assertions.
[ WIN ] /tests/content/media/test/test_loop.html | Assertion count 0-16 is greater than expected range 0-0 assertions.
[ WIN ] /tests/content/media/test/test_paused_after_ended.html | Assertion count 0-20 is greater than expected range 0-0 assertions.
[ WIN ] /tests/content/media/test/test_play_events.html | Assertion count 0-16 is greater than expected range 0-0 assertions.
[ WIN ] /tests/content/media/test/test_play_events_2.html | Assertion count 0-16 is greater than expected range 0-0 assertions.
[ WIN ] /tests/content/media/test/test_play_twice.html | Assertion count 0-18 is greater than expected range 0-0 assertions.
[ WIN ] /tests/content/media/test/test_playback.html | Assertion count 0-84 is greater than expected range 0-0 assertions.
[ WIN ] /tests/content/media/test/test_playback_errors.html | Assertion count 0-16 is greater than expected range 0-0 assertions.
[ WIN ] /tests/content/media/test/test_preload_actions.html | Assertion count 0-8 is greater than expected range 0-0 assertions.
[ WIN ] /tests/content/media/test/test_too_many_elements.html | Assertion count 0-2 is greater than expected range 0-0 assertions.

The actual assertions are many occurrences of:

 ###!!! ASSERTION: Should have state machine.: 'mDecoderStateMachine != nullptr', file e:/builds/moz2_slave/m-in-w32-d-0000000000000000000/build/content/media/MediaDecoder.cpp, line 520

 ###!!! ASSERTION: Must have state machine to start state machine thread: 'mDecoderStateMachine', file e:/builds/moz2_slave/m-in-w32-d-0000000000000000000/build/content/media/MediaDecoder.cpp, line 505

which always seem to come in that pair.
Do you think this is fixable soon (or should be reverted), or should I annotate these mochitest with SimpleTest.expectAssertions() in order to progress with bug 404077?
Flags: needinfo?(paul)
I annotated the tests in https://hg.mozilla.org/integration/mozilla-inbound/rev/c7cedc21bdf2 (along with other bugs).  The failures in that commit annotated with this bug number should be removed when this bug is fixed.
This fixes both assertions (and in fact fixes a potential bug).

dbaron, sorry about that, I'll remove the annotations when this lands, and I'll
try to keep an eye open for new assertions.
Attachment #719124 - Flags: review?(kinetik)
Flags: needinfo?(paul)
Assignee: nobody → paul
Comment on attachment 719124 [details] [diff] [review]
Initialize mPauseForPlaybackRateNull in MediaDecoder constructor to prevent an assertion. r=

mPauseForPlaybackRateNull in the comment should be mPausedForPlaybackRateNull.
Attachment #719124 - Flags: review?(kinetik) → review+
Since the bug that made the assertion fire is fixed, I believe we can remove most
of the annotations in content/media mochitests. The only one remaining is in
content/media/test/test_seek.html, that will be addressed in bug 846320.
Attachment #719480 - Flags: review?(dbaron)
Comment on attachment 719480 [details] [diff] [review]
Remove most of the assertion annotations in the content/media mochitests. r=

You don't want the test_seek.html change in here.

test_bug493187.html was for:
09:41:32     INFO -  ^G[Parent 2420] ###!!! ASSERTION: Page read cursor should be inside range: 'mPageOffset <= endOffset', file ../../../../content/media/ogg/OggReader.cpp, line 1675
so I don't think you want that change either, unless this patch fixes it.

test_playback_rate.html was for this happening 1 or 2 times:
###!!! ASSERTION: Should be on state machine thread or the decoder thread.: 'OnStateMachineThread() || OnDecodeThread()', file ../../../content/media/MediaDecoderStateMachine.cpp, line 1272
so you should also drop that change unless this patch fixes it.

r=dbaron with those changes dropped if necessary

(And if the tree stays closed for the rest of your afternoon, do you mind if I land this if you don't get to it first?)
Attachment #719480 - Flags: review?(dbaron) → review+
Yes, sorry, test_bug493187.html should not be in this patch. Here is a patch
that does not remove the assertion in this test.

You can land those patches when the tree reopens, yes, thanks.
Attachment #719480 - Attachment is obsolete: true
What about:

(1)
> You don't want the test_seek.html change in here.

(2)
> test_playback_rate.html was for this happening 1 or 2 times:
> ###!!! ASSERTION: Should be on state machine thread or the decoder thread.:
> 'OnStateMachineThread() || OnDecodeThread()', file
> ../../../content/media/MediaDecoderStateMachine.cpp, line 1272
> so you should also drop that change unless this patch fixes it.
Flags: needinfo?(paul)
Right, I should have read carefully. The test_seek.html failure is addressed by
bug 846320.  I'm going to address the test_playback_rate.html failure shortly.

This patch is identical to the previous one, but removes the
test_playback_rate.html and test_seek.html hunks.
Flags: needinfo?(paul)
Attachment #719506 - Attachment is obsolete: true
https://tbpl.mozilla.org/php/getParsedLog.php?id=20197702&tree=Mozilla-Inbound

Rev3 WINNT 6.1 mozilla-inbound debug test mochitest-1 on 2013-02-28 14:05:40 PST for push 65a2c1fd9d38
slave: talos-r3-w7-096

14:40:28     INFO -  187377 INFO TEST-PASS | /tests/content/media/test/test_bug495300.html | [finished detodos.opus-7] Length of array should match number of running tests
14:40:28     INFO -  187378 INFO TEST-PASS | /tests/content/media/test/test_bug495300.html | [started gizmo.mp4-8] Length of array should match number of running tests
14:40:29     INFO -  [Parent 2876] ###!!! ASSERTION: Seek target should lie inside the first frame after seek: 'video->mTime <= seekTime && seekTime <= video->mEndTime', file e:/builds/moz2_slave/m-in-w32-d-0000000000000000000/build/content/media/MediaDecoderStateMachine.cpp, line 1961
14:40:29     INFO -  187379 INFO TEST-PASS | /tests/content/media/test/test_bug495300.html | Got expected 'ended' event: gizmo.mp4
14:40:29     INFO -  187380 INFO TEST-PASS | /tests/content/media/test/test_bug495300.html | currentTime equals duration: gizmo.mp4
14:40:29     INFO -  187381 INFO TEST-PASS | /tests/content/media/test/test_bug495300.html | [finished gizmo.mp4-8] Length of array should match number of running tests
14:40:29     INFO -  187382 INFO TEST-PASS | /tests/content/media/test/test_bug495300.html | [started owl.mp3-9] Length of array should match number of running tests
14:40:29     INFO -  xul!webrtc::ViEBase::ViEBase+0x0000000000BCE129
14:40:29     INFO -  xul!webrtc::ViEBase::ViEBase+0x0000000000BC8EAB
14:40:29     INFO -  xul!webrtc::ViEBase::ViEBase+0x0000000001805821
14:40:29     INFO -  xul!webrtc::ViEBase::ViEBase+0x00000000017ABCF3
14:40:29     INFO -  xul!webrtc::ViEBase::ViEBase+0x0000000001804DBF
14:40:29     INFO -  nspr4!PRP_TryLock+0x000000000000061B
14:40:29     INFO -  MSVCR100D!beginthreadex+0x00000000000001D4
14:40:29     INFO -  kernel32!BaseThreadInitThunk+0x0000000000000012
14:40:29     INFO -  ntdll!RtlInitializeExceptionChain+0x0000000000000063
14:40:29     INFO -  ntdll!RtlInitializeExceptionChain+0x0000000000000036
14:40:29     INFO -  [Parent 2876] ###!!! ASSERTION: Page read cursor should be inside range: 'mPageOffset <= endOffset', file e:/builds/moz2_slave/m-in-w32-d-0000000000000000000/build/content/media/ogg/OggReader.cpp, line 1675
14:40:29     INFO -  xul!webrtc::ViEBase::ViEBase+0x0000000000BF827A
14:40:29     INFO -  xul!webrtc::ViEBase::ViEBase+0x0000000000BFACE5
14:40:29     INFO -  xul!webrtc::ViEBase::ViEBase+0x0000000000BCDBE4
14:40:29     INFO -  xul!webrtc::ViEBase::ViEBase+0x0000000000BCE129
14:40:29     INFO -  xul!webrtc::ViEBase::ViEBase+0x0000000000BC8EAB
14:40:29     INFO -  xul!webrtc::ViEBase::ViEBase+0x0000000001805821
14:40:29     INFO -  xul!webrtc::ViEBase::ViEBase+0x00000000017ABCF3
14:40:29     INFO -  xul!webrtc::ViEBase::ViEBase+0x0000000001804DBF
14:40:29     INFO -  nspr4!PRP_TryLock+0x000000000000061B
14:40:29     INFO -  MSVCR100D!beginthreadex+0x00000000000001D4
14:40:29     INFO -  kernel32!BaseThreadInitThunk+0x0000000000000012
14:40:29     INFO -  ntdll!RtlInitializeExceptionChain+0x0000000000000063
14:40:29     INFO -  ntdll!RtlInitializeExceptionChain+0x0000000000000036
14:40:29     INFO -  [Parent 2876] WARNING: NS_ENSURE_TRUE(SUCCEEDED(hr)) failed: file e:/builds/moz2_slave/m-in-w32-d-0000000000000000000/build/content/media/wmf/WMFReader.cpp, line 761
14:40:29     INFO -  187383 INFO TEST-PASS | /tests/content/media/test/test_bug495300.html | Got expected 'ended' event: owl.mp3
14:40:29     INFO -  187384 INFO TEST-PASS | /tests/content/media/test/test_bug495300.html | currentTime equals duration: owl.mp3
14:40:29     INFO -  187385 INFO TEST-PASS | /tests/content/media/test/test_bug495300.html | [finished owl.mp3-9] Length of array should match number of running tests
14:40:29     INFO -  [Parent 2876] ###!!! ASSERTION: Should know audio start time if we have audio.: '!HasAudio() || mAudioStartTime != -1', file e:/builds/moz2_slave/m-in-w32-d-0000000000000000000/build/content/media/MediaDecoderStateMachine.cpp, line 2346
14:40:29     INFO -  187386 INFO TEST-PASS | /tests/content/media/test/test_bug495300.html | Got expected 'ended' event: seek.ogv
14:40:29     INFO -  187387 INFO TEST-PASS | /tests/content/media/test/test_bug495300.html | currentTime equals duration: seek.ogv
14:40:29     INFO -  187388 INFO TEST-PASS | /tests/content/media/test/test_bug495300.html | [finished seek.ogv-2] Length of array should match number of running tests
14:40:30     INFO -  187389 INFO TEST-INFO | /tests/content/media/test/test_bug495300.html | Finished at Thu Feb 28 2013 14:40:30 GMT-0800 (Pacific Standard Time) (1362091230.414s)
14:40:30     INFO -  187390 INFO TEST-INFO | /tests/content/media/test/test_bug495300.html | Running time: 5.133s
14:40:30     INFO -  187391 INFO TEST-END | /tests/content/media/test/test_bug495300.html | finished in 5502ms
Blocks: 634747
https://hg.mozilla.org/mozilla-central/rev/bf6f98400fc2
https://hg.mozilla.org/mozilla-central/rev/36d9ba108f81
Status: NEW → RESOLVED
Closed: 7 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla22
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
I think that this bug as-filed has outlived its usefulness. Calling it fixed by bug 839650.
Status: REOPENED → RESOLVED
Closed: 7 years ago7 years ago
Depends on: 839650
Resolution: --- → FIXED
You need to log in before you can comment on or make changes to this bug.