Intermittent test_playback_rate_playpause.html | Assertion count 2 is greater than expected range 0-1 assertions (Clock should go forwards if the playback rate is > 0, Should have positive clock time.: 'clock_time >= mStartTime')

RESOLVED WORKSFORME

Status

()

RESOLVED WORKSFORME
5 years ago
5 years ago

People

(Reporter: RyanVM, Unassigned)

Tracking

({intermittent-failure})

Trunk
x86
Windows XP
intermittent-failure
Points:
---

Firefox Tracking Flags

(firefox24 unaffected, firefox25 affected, firefox26 affected)

Details

(Reporter)

Description

5 years ago
https://tbpl.mozilla.org/php/getParsedLog.php?id=25818045&tree=Mozilla-Inbound

Windows 7 32-bit mozilla-inbound debug test mochitest-1 on 2013-07-27 08:28:04 PDT for push 36326783bd82
slave: t-w732-ix-022

08:56:19     INFO -                       uncaugh155183 INFO TEST-START | /tests/content/media/test/test_playback_rate_playpause.html
08:56:19     INFO -  ++DOMWINDOW == 22 (14AFD3D0) [serial = 4635] [outer = 098C80C8]
08:56:19     INFO -  [Parent 1608] WARNING: No permission to access camera: file e:/builds/moz2_slave/m-in-w32-d-0000000000000000000/build/dom/camera/DOMCameraManager.cpp, line 84
08:56:19     INFO -  155184 INFO TEST-INFO | /tests/content/media/test/test_playback_rate_playpause.html | Started Sat Jul 27 2013 08:56:19 GMT-0700 (Pacific Standard Time) (1374940579.308s)
08:56:19     INFO -  155185 INFO TEST-PASS | /tests/content/media/test/test_playback_rate_playpause.html | [started big.wav-0] Length of array should match number of running tests
08:56:19     INFO -  155186 INFO TEST-PASS | /tests/content/media/test/test_playback_rate_playpause.html | [started seek.ogv-1] Length of array should match number of running tests
08:56:19     INFO -  big.wav-0 loadedmetadata
08:56:19     INFO -  big.wav-0 t.currentTime != 0.0.
08:56:19     INFO -  155187 INFO TEST-PASS | /tests/content/media/test/test_playback_rate_playpause.html | PlaybackRate should not have changed after pause.
08:56:19     INFO -  System JS : ERROR chrome://specialpowers/content/SpecialPowersObserverAPI.js:183
08:56:19     INFO -                       NS_ERROR_UNEXPECTED: Component returned failure code: 0x8000ffff (NS_ERROR_UNEXPECTED) [nsIPrefBranch.getBoolPref]
08:56:19     INFO -  [Parent 1608] WARNING: converted background area should not be empty: file e:/builds/moz2_slave/m-in-w32-d-0000000000000000000/build/layout/base/nsCSSRendering.cpp, line 1867
08:56:19     INFO -  big.wav-0 onpaused.
08:56:19     INFO -  155188 INFO TEST-PASS | /tests/content/media/test/test_playback_rate_playpause.html | PlaybackRate should not have changed after resuming playback.
08:56:19     INFO -  big.wav-0 finish_test.
08:56:19     INFO -  155189 INFO TEST-PASS | /tests/content/media/test/test_playback_rate_playpause.html | [finished big.wav-0] Length of array should match number of running tests
08:56:19     INFO -  155190 INFO TEST-PASS | /tests/content/media/test/test_playback_rate_playpause.html | [started seek.webm-2] Length of array should match number of running tests
08:56:19     INFO -  seek.webm-2 loadedmetadata
08:56:19     INFO -  [Parent 1608] ###!!! ASSERTION: Clock should go forwards if the playback rate is > 0.: 'mCurrentFrameTime <= clock_time || mPlaybackRate <= 0', file e:/builds/moz2_slave/m-in-w32-d-0000000000000000000/build/content/media/MediaDecoderStateMachine.cpp, line 2435
08:56:19     INFO -  mozilla::MediaDecoderStateMachine::AdvanceFrame() [content/media/MediaDecoderStateMachine.cpp:2461]
08:56:19     INFO -  mozilla::MediaDecoderStateMachine::RunStateMachine() [content/media/MediaDecoderStateMachine.cpp:2237]
08:56:19     INFO -  mozilla::MediaDecoderStateMachine::CallRunStateMachine() [content/media/MediaDecoderStateMachine.cpp:2741]
08:56:19     INFO -  mozilla::MediaDecoderStateMachine::Run() [content/media/MediaDecoderStateMachine.cpp:2715]
08:56:19     INFO -  nsThread::ProcessNextEvent(bool,bool *) [xpcom/threads/nsThread.cpp:622]
08:56:19     INFO -  NS_ProcessNextEvent(nsIThread *,bool) [obj-firefox/xpcom/build/nsThreadUtils.cpp:238]
08:56:19     INFO -  nsThread::Shutdown() [xpcom/threads/nsThread.cpp:463]
08:56:19     INFO -  mozilla::MediaDecoderStateMachine::StopAudioThread() [content/media/MediaDecoderStateMachine.cpp:1686]
08:56:19     INFO -  mozilla::MediaDecoderStateMachine::RunStateMachine() [content/media/MediaDecoderStateMachine.cpp:2145]
08:56:19     INFO -  mozilla::MediaDecoderStateMachine::CallRunStateMachine() [content/media/MediaDecoderStateMachine.cpp:2741]
08:56:19     INFO -  mozilla::MediaDecoderStateMachine::Run() [content/media/MediaDecoderStateMachine.cpp:2715]
08:56:19     INFO -  nsThread::ProcessNextEvent(bool,bool *) [xpcom/threads/nsThread.cpp:622]
08:56:19     INFO -  NS_ProcessNextEvent(nsIThread *,bool) [obj-firefox/xpcom/build/nsThreadUtils.cpp:238]
08:56:19     INFO -  nsThread::ThreadFunc(void *) [xpcom/threads/nsThread.cpp:250]
08:56:20     INFO -  _PR_NativeRunThread [nsprpub/pr/src/threads/combined/pruthr.c:397]
08:56:20     INFO -  pr_root [nsprpub/pr/src/md/windows/w95thred.c:90]
08:56:20     INFO -  MSVCR100D + 0x4a293
08:56:20     INFO -  MSVCR100D + 0x4a224
08:56:20     INFO -  kernel32 + 0x53c45
08:56:20     INFO -  ntdll + 0x637f5
08:56:20     INFO -  ntdll + 0x637c8
08:56:20     INFO -  [Parent 1608] ###!!! ASSERTION: Should have positive clock time.: 'clock_time >= mStartTime', file e:/builds/moz2_slave/m-in-w32-d-0000000000000000000/build/content/media/MediaDecoderStateMachine.cpp, line 2462
08:56:20     INFO -  seek.webm-2 t.currentTime != 0.0.
08:56:20     INFO -  155191 INFO TEST-PASS | /tests/content/media/test/test_playback_rate_playpause.html | PlaybackRate should not have changed after pause.
08:56:20     INFO -  seek.webm-2 onpaused.
08:56:20     INFO -  155192 INFO TEST-PASS | /tests/content/media/test/test_playback_rate_playpause.html | PlaybackRate should not have changed after resuming playback.
08:56:20     INFO -  seek.webm-2 finish_test.
08:56:20     INFO -  155193 INFO TEST-PASS | /tests/content/media/test/test_playback_rate_playpause.html | [finished seek.webm-2] Length of array should match number of running tests
08:56:20     INFO -  155194 INFO TEST-PASS | /tests/content/media/test/test_playback_rate_playpause.html | [started gizmo.mp4-3] Length of array should match number of running tests
08:56:20     INFO -  --DOMWINDOW == 21 (14AFE710) [serial = 4631] [outer = 00000000] [url = http://mochi.test:8888/tests/content/media/test/test_playback.html]
08:56:20     INFO -  --DOMWINDOW == 20 (14B044E8) [serial = 4632] [outer = 00000000] [url = http://mochi.test:8888/tests/SimpleTest/iframe-between-tests.html]
08:56:20     INFO -  --DOMWINDOW == 19 (14B02A70) [serial = 4634] [outer = 00000000] [url = http://mochi.test:8888/tests/SimpleTest/iframe-between-tests.html]
08:56:20     INFO -  gizmo.mp4-3 loadedmetadata
08:56:20     INFO -  gizmo.mp4-3 t.currentTime != 0.0.
08:56:20     INFO -  155195 INFO TEST-PASS | /tests/content/media/test/test_playback_rate_playpause.html | PlaybackRate should not have changed after pause.
08:56:20     INFO -  gizmo.mp4-3 onpaused.
08:56:20     INFO -  155196 INFO TEST-PASS | /tests/content/media/test/test_playback_rate_playpause.html | PlaybackRate should not have changed after resuming playback.
08:56:20     INFO -  gizmo.mp4-3 finish_test.
08:56:20     INFO -  155197 INFO TEST-PASS | /tests/content/media/test/test_playback_rate_playpause.html | [finished gizmo.mp4-3] Length of array should match number of running tests
08:56:20     INFO -  155198 INFO TEST-PASS | /tests/content/media/test/test_playback_rate_playpause.html | [started owl.mp3-4] Length of array should match number of running tests
08:56:20     INFO -  owl.mp3-4 loadedmetadata
08:56:20     INFO -  seek.ogv-1 loadedmetadata
08:56:20     INFO -  seek.ogv-1 t.currentTime == 0.0.
08:56:20     INFO -  owl.mp3-4 t.currentTime != 0.0.
08:56:20     INFO -  155199 INFO TEST-PASS | /tests/content/media/test/test_playback_rate_playpause.html | PlaybackRate should not have changed after pause.
08:56:20     INFO -  owl.mp3-4 onpaused.
08:56:20     INFO -  155200 INFO TEST-PASS | /tests/content/media/test/test_playback_rate_playpause.html | PlaybackRate should not have changed after resuming playback.
08:56:20     INFO -  owl.mp3-4 finish_test.
08:56:20     INFO -  155201 INFO TEST-PASS | /tests/content/media/test/test_playback_rate_playpause.html | [finished owl.mp3-4] Length of array should match number of running tests
08:56:21     INFO -  seek.ogv-1 t.currentTime != 0.0.
08:56:21     INFO -  155202 INFO TEST-PASS | /tests/content/media/test/test_playback_rate_playpause.html | PlaybackRate should not have changed after pause.
08:56:21     INFO -  seek.ogv-1 onpaused.
08:56:21     INFO -  155203 INFO TEST-PASS | /tests/content/media/test/test_playback_rate_playpause.html | PlaybackRate should not have changed after resuming playback.
08:56:21     INFO -  seek.ogv-1 finish_test.
08:56:21     INFO -  155204 INFO TEST-PASS | /tests/content/media/test/test_playback_rate_playpause.html | [finished seek.ogv-1] Length of array should match number of running tests
08:56:21     INFO -  155205 INFO TEST-INFO | /tests/content/media/test/test_playback_rate_playpause.html | Finished at Sat Jul 27 2013 08:56:21 GMT-0700 (Pacific Standard Time) (1374940581.917s)
08:56:21     INFO -  155206 INFO TEST-INFO | /tests/content/media/test/test_playback_rate_playpause.html | Running time: 2.609s
08:56:21     INFO -  155207 INFO TEST-END | /tests/content/media/test/test_playback_rate_playpause.html | finished in 2801ms
08:56:21     INFO -  ++DOMWINDOW == 20 (14AFE978) [serial = 4636] [outer = 098C80C8]
08:56:22     INFO -  155208 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_playback_rate_playpause.html | Assertion count 2 is greater than expected range 0-1 assertions.
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
(Reporter)

Updated

5 years ago
status-firefox24: --- → unaffected
status-firefox25: --- → affected
status-firefox26: --- → affected
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
(Reporter)

Comment 10

5 years ago
https://tbpl.mozilla.org/php/getParsedLog.php?id=27786906&tree=Mozilla-Inbound

FWIW, we seem to be hitting this *a lot* lately.
Flags: needinfo?(cpearce)
(Reporter)

Comment 12

5 years ago
Chris/Edwin, is it possible that the library update is making us hit this more?
Likely. All of the recent ones seem to be on linux, and it wouldn't surprise me if it were due to the new decoder.

I'm trying to reproduce a whole bunch of these linux media randoms now.
Flags: needinfo?(cpearce)
Closing inactive keywords:intermittent-failure bugs where the TBPLbot has previously commented and the test isn't marked as disabled; filter on orange-cleanup-201401.
Status: NEW → RESOLVED
Last Resolved: 5 years ago
Resolution: --- → WORKSFORME
You need to log in before you can comment on or make changes to this bug.