845676 - frequent assertions in media mochitests on Windows

Status: RESOLVED FIXED

(Core :: Audio/Video, defect)

Description

[David Baron :dbaron: (⌚️UTC-4, no longer working on Mozilla)]

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.

Comment 1

[David Baron :dbaron: (⌚️UTC-4, no longer working on Mozilla)]

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?

Comment 2

[David Baron :dbaron: (⌚️UTC-4, no longer working on Mozilla)]

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.

Comment 3

[Paul Adenot (:padenot)]

Attachment: Initialize mPauseForPlaybackRateNull in MediaDecoder constructor to prevent an assertion. r=

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.

Comment 4

[Matthew Gregan [:kinetik]]

Comment on attachment 719124 [details] [diff] [review]
Initialize mPauseForPlaybackRateNull in MediaDecoder constructor to prevent an assertion. r=

mPauseForPlaybackRateNull in the comment should be mPausedForPlaybackRateNull.

Comment 5

[Paul Adenot (:padenot)]

Attachment: Remove most of the assertion annotations in the content/media mochitests. r=

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.

Comment 6

[David Baron :dbaron: (⌚️UTC-4, no longer working on Mozilla)]

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?)

Comment 7

[Paul Adenot (:padenot)]

Attachment: Remove most of the assertion annotations in the content/media mochitests.

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.

Comment 8

[David Baron :dbaron: (⌚️UTC-4, no longer working on Mozilla)]

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.

Comment 9

[Paul Adenot (:padenot)]

Attachment: Remove most of the assertion annotations in the content/media mochitests.

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.

Comment 10

[David Baron :dbaron: (⌚️UTC-4, no longer working on Mozilla)]

remote:   https://hg.mozilla.org/integration/mozilla-inbound/rev/bf6f98400fc2
remote:   https://hg.mozilla.org/integration/mozilla-inbound/rev/36d9ba108f81

Comment 11

[Ryan VanderMeulen [:RyanVM]]

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

Comment 12

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/bf6f98400fc2
https://hg.mozilla.org/mozilla-central/rev/36d9ba108f81

Comment 13

[Ryan VanderMeulen [:RyanVM]]

https://tbpl.mozilla.org/php/getParsedLog.php?id=21184932&tree=Mozilla-Inbound&full=1#error0

Comment 14

[David Baron :dbaron: (⌚️UTC-4, no longer working on Mozilla)]

Fixed by:
https://hg.mozilla.org/mozilla-central/rev/82441eb369e8
and prior patches in that bug?

Comment 15

[Ryan VanderMeulen [:RyanVM]]

I think that this bug as-filed has outlived its usefulness. Calling it fixed by bug 839650.