Intermittent test_playback_rate.html | application timed out after 330 seconds with no output (after: "ASSERTION: Should have positive clock time.: 'clock_time >= mStartTime', file ..../build/content/media/MediaDecoderStateMachine.cpp, line 2277")

RESOLVED FIXED in mozilla20

Status

()

defect
--
critical
RESOLVED FIXED
7 years ago
6 years ago

People

(Reporter: emorley, Assigned: cpearce)

Tracking

({assertion, intermittent-failure})

Trunk
mozilla20
x86
Windows 7
Points:
---

Firefox Tracking Flags

(Not tracked)

Details

Attachments

(1 attachment)

(Reporter)

Description

7 years ago
Rev3 WINNT 6.1 mozilla-inbound debug test mochitest-1 on 2012-11-25 15:20:21 PST for push 4b816b309e52

slave: talos-r3-w7-088

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

{
...
...
...

[Parent 3480] ###!!! ASSERTION: Should have positive clock time.: 'clock_time >= mStartTime', file e:/builds/moz2_slave/m-in-w32-dbg/build/content/media/MediaDecoderStateMachine.cpp, line 2277
130379 INFO TEST-PASS | /tests/content/media/test/test_playback_rate.html | playbackRate should be initially 1.0
130380 INFO TEST-PASS | /tests/content/media/test/test_playback_rate.html | defaultPlaybackRate should be initially 1.0
130381 INFO TEST-PASS | /tests/content/media/test/test_playback_rate.html | PlaybackRate should be clamped to 0.25.
130382 INFO TEST-PASS | /tests/content/media/test/test_playback_rate.html | playbackRate should be reset to 1.0 on play() call
xul!JSD_AttemptUCScriptInStackFrame+0x0000000000AC3EBA
xul!JSD_AttemptUCScriptInStackFrame+0x0000000000AC4112
xul!JSD_AttemptUCScriptInStackFrame+0x000000000136FABF
xul!JSD_AttemptUCScriptInStackFrame+0x000000000136FCF1
xul!JSD_AttemptUCScriptInStackFrame+0x000000000136A8F8
xul!JSD_AttemptUCScriptInStackFrame+0x0000000001317FF0
xul!JSD_AttemptUCScriptInStackFrame+0x0000000001369F00
nspr4!PRP_TryLock+0x000000000000062B
MSVCR100D!beginthreadex+0x00000000000001D4
kernel32!BaseThreadInitThunk+0x0000000000000012
ntdll!RtlInitializeExceptionChain+0x0000000000000063
ntdll!RtlInitializeExceptionChain+0x0000000000000036
[Parent 3480] ###!!! ASSERTION: Should have positive clock time.: 'clock_time >= mStartTime', file e:/builds/moz2_slave/m-in-w32-dbg/build/content/media/MediaDecoderStateMachine.cpp, line 2277
TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_playback_rate.html | application timed out after 330 seconds with no output
}
Comment hidden (Legacy TBPL/Treeherder Robot)
(Assignee)

Comment 2

7 years ago
Paul, are you looking into this? I get a horrendous amount of assertion failure spam when I run this test on Windows, I haven't tried other platforms.

It looks like AudioClock::GetPosition() is returning a bogus value because AudioClock::mBasePosition is bogus.
(Assignee)

Comment 3

7 years ago
OK, I looked into this because it was causing tests to fail for me with my WMF backend...

The problem is that AudioClock::GetPosition() uses mOldOutRate to calculate the "position" variable [1], that gets stored in mPreviousPosition, which then later is stored in mBasePosition [2].

mOldOutRate is initialized by the constructor to 0, and it's set to mOutRate in one but not all code paths in AudioClock::SetPlaybackRate(). So I guess we're taking the path in SetPlaybackRate() that doesn't set mOldOutRate, and so mOldOutRate is then 0 when we come to all AudioClock::GetPosition(), which poisons all future calculations. We don't appear to be crashing, despite the fact that we're dividing by 0.

I'd guess the fix is to initialize mOldOutRate to mOutRate in AudioClock::Init().


[1] http://mxr.mozilla.org/mozilla-central/source/content/media/AudioStream.cpp#1088
[2] http://mxr.mozilla.org/mozilla-central/source/content/media/AudioStream.cpp#1096
(Assignee)

Comment 4

7 years ago
Posted patch Patch v1Splinter Review
Initialize mOldOutRate to mOutRate, and initialize mOldBasePosition to 0.

This seems like the right thing to do, and it stops the assertion spam and the current playback position now advances for me when playing MP4 videos using the Windows Media Foundation backend I'm working on.
Attachment #690157 - Flags: review?(paul)
Comment on attachment 690157 [details] [diff] [review]
Patch v1

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

Funnily enough, I've came to the same conclusion and was about to upload the same patch. Thanks!
Attachment #690157 - Flags: review?(paul) → review+
(Reporter)

Comment 7

6 years ago
https://hg.mozilla.org/mozilla-central/rev/4bd1cc9d98c5
Assignee: nobody → cpearce
Status: NEW → RESOLVED
Last Resolved: 6 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla20
You need to log in before you can comment on or make changes to this bug.