Fix and re-enable test_playback_rate.html

RESOLVED FIXED in Firefox 33

Status

()

defect
RESOLVED FIXED
5 years ago
5 years ago

People

(Reporter: RyanVM, Assigned: jwwang)

Tracking

Trunk
mozilla33
Points:
---
Dependency tree / graph
Bug Flags:
in-testsuite +

Firefox Tracking Flags

(firefox31 wontfix, firefox32 wontfix, firefox33 fixed, firefox-esr24 wontfix, b2g-v1.4 wontfix, b2g-v2.0 wontfix, b2g-v2.1 fixed)

Details

Attachments

(4 attachments)

With bug 921622 fixed, I took a look at re-enabling test_playback_rate.html. It looks pretty green on opt builds, but debug builds still assert like crazy.

Android 4.0 Panda try debug test mochitest-3 on 2014-06-04 11:26:20 PDT for push 2fb25f5fc810

06-04 11:52:12.125 I/Gecko   ( 2250): [2250] ###!!! ASSERTION: Should be on state machine or decode thread.: 'OnStateMachineThread() || OnDecodeThread()', file /builds/slave/try-and-d-00000000000000000000/build/content/media/MediaDecoderStateMachine.cpp, line 559
06-04 11:52:16.203 I/Gecko   ( 2250): [2250] ###!!! ASSERTION: Clock should go forwards if the playback rate is > 0.: 'mCurrentFrameTime <= clock_time || mPlaybackRate <= 0', file /builds/slave/try-and-d-00000000000000000000/build/content/media/MediaDecoderStateMachine.cpp, line 2379

06-04 11:52:26.851 E/GeckoConsole( 2250): [JavaScript Warning: "Invalid URI. Load of media resource  failed." {file: "http://mochi.test:8888/tests/content/media/test/test_playback_rate.html" line: 0}]

I'm feeling inclined to re-enable test_playback_rate.html on opt builds once I get some more green retriggers, but debug builds are still going to need some help.
Windows 7/8 opt builds still hit bug 814533 as well.
Blocks: 814533
Summary: test_playback_rate.html asserts when re-enabled → Fix and re-enable test_playback_rate.html
The "Should be on state machine or decode thread" asserts happen on all platforms. Linux also hits the "Clock should go forwards if the playback rate is > 0" assert.

However, the test was already annotated on all platforms for assertions before, so maybe we just need to bump the allowed number (assuming it's the same asserts as before, just firing more often).
Occasional Android timeouts, but hard to say it's any worse than any other test in content/media in that respect...
https://tbpl.mozilla.org/php/getParsedLog.php?id=41054576&tree=Try
Pretty flaky on B2G emulator with the following happening frequently:

1453 INFO TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_playback_rate.html | Current time should not change when playbackRate is null (5.207732 4.88848).
1468 INFO TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_playback_rate.html | Current time should not change when playbackRate is null (3.233 2.8).
1522 INFO TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_playback_rate.html | The element should not be in paused state.

https://tbpl.mozilla.org/php/getParsedLog.php?id=41056722&tree=Try
Ouch, Android debug hit anywhere from 3-94 assertions. That's too wide for me to comfortably annotate it away.
Depends on: 1020707
I filed bug 1020707 for the Android timeouts. They're infrequent enough that they'd be tolerable IMO (given Android's already crappy orange rate for media tests).
Definitely not intended to be the final fix for this bug, but it gets the ball rolling anyway.

This patch re-enables test_playback_rate.html on Linux, OSX, and Android opt. It also updates the assertion annotations for all desktop platforms. Due to the aforementioned issues in this bug, Windows, B2G, and Android debug remain disabled.

Try runs:
https://tbpl.mozilla.org/?tree=Try&rev=588f84523a36
https://tbpl.mozilla.org/?tree=Try&rev=f9ae9b880cb0
Attachment #8434609 - Flags: review?(cpearce)
Attachment #8434609 - Flags: review?(cpearce) → review+
I got this assertion when running on my local Linux box.

#0  0x00007ffff2169597 in mozilla::MediaDecoderStateMachine::NeedToDecodeAudio (this=0x7fffbfc97840) at /home/jwwang/codebase/mozilla-central2/content/media/MediaDecoderStateMachine.cpp:685
#1  0x00007ffff21697ba in mozilla::MediaDecoderStateMachine::DispatchDecodeTasksIfNeeded (this=this@entry=0x7fffbfc97840)
    at /home/jwwang/codebase/mozilla-central2/content/media/MediaDecoderStateMachine.cpp:1580
#2  0x00007ffff2169b82 in mozilla::MediaDecoderStateMachine::StopPlayback (this=this@entry=0x7fffbfc97840) at /home/jwwang/codebase/mozilla-central2/content/media/MediaDecoderStateMachine.cpp:1107
#3  0x00007ffff2169c8d in mozilla::MediaDecoderStateMachine::StartBuffering (this=0x7fffbfc97840) at /home/jwwang/codebase/mozilla-central2/content/media/MediaDecoderStateMachine.cpp:2684
#4  0x00007ffff2162bbf in mozilla::MediaDecoder::Resume (this=0x7fffc452d4e0, aForceBuffering=<optimized out>) at /home/jwwang/codebase/mozilla-central2/content/media/MediaDecoder.cpp:1373
#5  0x00007ffff20c6974 in mozilla::dom::HTMLMediaElement::Play (this=0x7fffbfeb5400, aRv=...) at /home/jwwang/codebase/mozilla-central2/content/html/content/src/HTMLMediaElement.cpp:2124
#6  0x00007ffff1840412 in mozilla::dom::HTMLMediaElementBinding::play (cx=0x7fffcd0176a0, obj=..., self=<optimized out>, args=...)
    at /home/jwwang/codebase/mozilla-central2/obj-x86_64-unknown-linux-gnu/dom/bindings/HTMLMediaElementBinding.cpp:930


I don't understand why MediaDecoderStateMachine::NeedToDecodeVideo|NeedToDecodeAudio should only be called on state or decode threads.
https://hg.mozilla.org/integration/mozilla-inbound/rev/12e8837e166a
Assignee: nobody → ryanvm
Flags: in-testsuite+
Whiteboard: [leave open]
Assignee: ryanvm → nobody
(In reply to JW Wang [:jwwang] from comment #8)
> I don't understand why
> MediaDecoderStateMachine::NeedToDecodeVideo|NeedToDecodeAudio should only be
> called on state or decode threads.

Given that the decoder monitor should be held here, I agree, these functions should be safe to call on any thread.
FYI, we see the "Clock should go forwards if the playback rate is > 0" asserts quite a bit in test_playback_rate_playpause.html.
Blocks: 1022453
Assignee: nobody → jwwang
I've fixed all failures on all platforms except the B2G emualtor.

https://tbpl.mozilla.org/php/getParsedLog.php?id=42030206&tree=Try&full=1#error2
TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_playback_rate.html | Current time should not change when playbackRate is null (2.681958 2.058891).

MediaDecoder::PlaybackPositionChanged() updates the official playback position (mCurrentTime) and dispatches 'timeupdate' event asynchronously. It is possible for the current playback position to change again before 'timeupdate' is fired.

It is observed on B2G emulator that the official playback position is 2.058891 and current playback position is 2.667270 when 'timeupdate' is fired. The check fails at http://hg.mozilla.org/mozilla-central/file/f78e532e8a10/content/media/test/test_playback_rate.html#l96  for the difference is over 0.3 sec.

It is also observed on B2G emulator that the latency between 'timeupdate' is dispatched and fired could go as high as 2.46867 sec for B2G emulator sometimes is very slow.

I think we could either have a higher tolerance on B2G or update the official playback position again before 'timeupdate' is fired to minimize the difference between current/official playback position.
Flags: needinfo?(cpearce)
I'd suggest we increase the latency tolerance on B2G. Timeupdate isn't supposed to be highly accurate.

'timeupdate' is defined to fire loosely, approx 4 times per second during playback. MediaDecoder::PlaybackPositionChanged() passes "true" to MediaDecoderOwner::FireTimeUpdate to signal a "periodic" time update, i.e. to only fire a 'timeupdate' if one hasn't fired in the last ~250ms. We could be hitting that, and then our task to dispatch the 'timeupdate' event to HTML could be getting delayed in the event queues.
Flags: needinfo?(cpearce)
Fix the position calculation algorithm in MediaDecoderStateMachine::GetVideoStreamPosition().
Attachment #8444917 - Flags: review?(cpearce)
Fix frame position adjustment algorithm in AudioStream.
Enable test_playback_rate.html.
Attachment #8444919 - Flags: review?(cpearce)
Comment on attachment 8444918 [details] [diff] [review]
1020538_fix_test_playback_rate_part2-v1.patch

Review of attachment 8444918 [details] [diff] [review]:
-----------------------------------------------------------------

::: content/media/AudioStream.cpp
@@ +979,5 @@
>    }
>  
>    uint8_t* wpos = reinterpret_cast<uint8_t*>(aBuffer);
>    double playbackRate = static_cast<double>(mInRate) / mOutRate;
> +  uint32_t toPopBytes = FramesToBytes(ceil(aFrames * playbackRate));

When playback rate is 0.5, libSoundTouch will turn 100 frames into 200 frames. Therefore we should only pop 200 * 0.5 = 100 frames. However it doesn't really matter for the while loop below will ensure we've process enough frames.
Attachment #8444918 - Flags: review?(kinetik)
Blocks: 897108
Comment on attachment 8444918 [details] [diff] [review]
1020538_fix_test_playback_rate_part2-v1.patch

Review of attachment 8444918 [details] [diff] [review]:
-----------------------------------------------------------------

This is much nicer than the existing code.
Attachment #8444918 - Flags: review?(kinetik) → review+
Blocks: 948269
Note that the following assertion count needs to be corrected before these patches can land:

22:46:51     INFO -  5130 ERROR TEST-UNEXPECTED-PASS | /tests/content/media/test/test_playback_rate_playpause.html | Assertion count 0 is less than expected range 2-7 assertions.
(In reply to Matthew Gregan [:kinetik] from comment #20)
> Note that the following assertion count needs to be corrected before these
> patches can land:
> 
> 22:46:51     INFO -  5130 ERROR TEST-UNEXPECTED-PASS |
> /tests/content/media/test/test_playback_rate_playpause.html | Assertion
> count 0 is less than expected range 2-7 assertions.

They will be removed in bug 897108.
Okay, then this can't land until after bug 897108.
No longer blocks: 897108
Depends on: 897108
Attachment #8444917 - Flags: review?(cpearce) → review+
Attachment #8444919 - Flags: review?(cpearce) → review+
Bug 1020538 and bug 897108 should be landed at the same time.
If we land bug 1020538 first, we will hit comment 20. If we land bug 897108 first, test_playback_rate_playpause.html will fail from assertions count > 0. Is there any way to tell Sheriff to land these patches altogether?
Oh, the dependency is circular? In that case, it's better to post all the patches in a single bug (or perhaps even roll the fixes together, otherwise bisect becomes painful).  There's probably some way to signal this in the whiteboard for needs-landing too, but I don't know what it is.  I'll land them now, anyway.
Thanks, Matthew. 1020538_fix_test_playback_rate_enable_test-v1.patch and 897108_fix_test_playback_rate_playpause_html_timeout-v1.patch were originally one patch which was split for easier review. Next time I should take both review and check-in into account when merge/split patches.
Not sure what the backport situation is here. Please request approval on whatever branches you feel this is safe for.
The patches can't apply cleanly. The code changed quite a bit even since then. Since this bug fixes the problem in playback rate changes which most user will not encounter, I guess we are fine with not uplifting to aurora/beta.
You need to log in before you can comment on or make changes to this bug.