Intermittent test_seek.html "ASSERTION: Page read cursor should be inside range: 'mPageOffset <= endOffset'" followed by an infinite number of "ASSERTION: Guess should be differnt to previous: 'guess != previousGuess'"

RESOLVED FIXED in mozilla8

Status

()

Core
Audio/Video
RESOLVED FIXED
6 years ago
3 years ago

People

(Reporter: philor, Assigned: cpearce)

Tracking

({assertion, intermittent-failure})

Trunk
mozilla8
assertion, intermittent-failure
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(Not tracked)

Details

(Whiteboard: [test which aborts the suite][inbound])

Attachments

(2 attachments)

(Reporter)

Description

6 years ago
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1298297412.1298299903.15232.gz
Rev3 MacOSX Snow Leopard 10.6.2 mozilla-central debug test mochitests-1/5 on 2011/02/21 06:10:12
s: talos-r3-snow-038

SEEK-TEST: Started seek.ogv seek test 7
WARNING: NS_ENSURE_TRUE(mIsPending) failed: file /builds/slave/cen-osx64-dbg/build/netwerk/protocol/http/nsHttpChannel.cpp, line 3546
WARNING: NS_ENSURE_TRUE(mSuspendCount > 0) failed: file /builds/slave/cen-osx64-dbg/build/netwerk/protocol/http/nsHttpChannel.cpp, line 3563
59271 INFO TEST-PASS | /tests/content/media/test/test_seek.html | seek.ogv seek test 7: Setting currentTime to invalid value of NaN
59272 INFO TEST-PASS | /tests/content/media/test/test_seek.html | seek.ogv seek test 7: Setting currentTime to invalid value of a function
SEEK-TEST: Finished seek.ogv seek test 7
###!!! ASSERTION: Page read cursor should be inside range: 'mPageOffset <= endOffset', file /builds/slave/cen-osx64-dbg/build/content/media/ogg/nsOggReader.cpp, line 1510
nsOggReader::SeekBisection [content/media/ogg/nsOggReader.cpp:1512]
nsOggReader::SeekInBufferedRange [content/media/ogg/nsOggReader.cpp:1117]
nsOggReader::Seek [content/media/ogg/nsOggReader.cpp:1253]
nsBuiltinDecoderStateMachine::Run [content/media/nsBuiltinDecoderStateMachine.cpp:1095]
nsThread::ProcessNextEvent [xpcom/threads/nsThread.cpp:633]
NS_ProcessNextEvent_P [nsThreadUtils.cpp:250]
nsThread::ThreadFunc [xpcom/threads/nsThread.cpp:277]
_pt_root [nsprpub/pr/src/pthreads/ptthread.c:190]
libSystem.B.dylib + 0x3a536
###!!! ASSERTION: Guess should be differnt to previous: 'guess != previousGuess', file /builds/slave/cen-osx64-dbg/build/content/media/ogg/nsOggReader.cpp, line 1436
nsOggReader::SeekBisection [content/media/ogg/nsOggReader.cpp:1437]
nsOggReader::SeekInBufferedRange [content/media/ogg/nsOggReader.cpp:1117]
nsOggReader::Seek [content/media/ogg/nsOggReader.cpp:1253]
nsBuiltinDecoderStateMachine::Run [content/media/nsBuiltinDecoderStateMachine.cpp:1095]
nsThread::ProcessNextEvent [xpcom/threads/nsThread.cpp:633]
NS_ProcessNextEvent_P [nsThreadUtils.cpp:250]
nsThread::ThreadFunc [xpcom/threads/nsThread.cpp:277]
_pt_root [nsprpub/pr/src/pthreads/ptthread.c:190]
libSystem.B.dylib + 0x3a536
###!!! ASSERTION: Guess should be differnt to previous: 'guess != previousGuess', file /builds/slave/cen-osx64-dbg/build/content/media/ogg/nsOggReader.cpp, line 1436
nsOggReader::SeekBisection [content/media/ogg/nsOggReader.cpp:1437]
nsOggReader::SeekInBufferedRange [content/media/ogg/nsOggReader.cpp:1117]
nsOggReader::Seek [content/media/ogg/nsOggReader.cpp:1253]
nsBuiltinDecoderStateMachine::Run [content/media/nsBuiltinDecoderStateMachine.cpp:1095]
nsThread::ProcessNextEvent [xpcom/threads/nsThread.cpp:633]
NS_ProcessNextEvent_P [nsThreadUtils.cpp:250]
nsThread::ThreadFunc [xpcom/threads/nsThread.cpp:277]
_pt_root [nsprpub/pr/src/pthreads/ptthread.c:190]
libSystem.B.dylib + 0x3a536
###!!! ASSERTION: Guess should be differnt to previous: 'guess != previousGuess', file /builds/slave/cen-osx64-dbg/build/content/media/ogg/nsOggReader.cpp, line 1436
nsOggReader::SeekBisection [content/media/ogg/nsOggReader.cpp:1437]
nsOggReader::SeekInBufferedRange [content/media/ogg/nsOggReader.cpp:1117]
nsOggReader::Seek [content/media/ogg/nsOggReader.cpp:1253]
nsBuiltinDecoderStateMachine::Run [content/media/nsBuiltinDecoderStateMachine.cpp:1095]
nsThread::ProcessNextEvent [xpcom/threads/nsThread.cpp:633]
NS_ProcessNextEvent_P [nsThreadUtils.cpp:250]
nsThread::ThreadFunc [xpcom/threads/nsThread.cpp:277]
_pt_root [nsprpub/pr/src/pthreads/ptthread.c:190]
libSystem.B.dylib + 0x3a536
...
SEEK-TEST: Started seek.ogv seek test 7
WARNING: NS_ENSURE_TRUE(mIsPending) failed: file /builds/slave/cen-osx64-dbg/build/netwerk/protocol/http/nsHttpChannel.cpp, line 3546
WARNING: NS_ENSURE_TRUE(mSuspendCount > 0) failed: file /builds/slave/cen-osx64-dbg/build/netwerk/protocol/http/nsHttpChannel.cpp, line 3563
59271 INFO TEST-PASS | /tests/content/media/test/test_seek.html | seek.ogv seek test 7: Setting currentTime to invalid value of NaN
59272 INFO TEST-PASS | /tests/content/media/test/test_seek.html | seek.ogv seek test 7: Setting currentTime to invalid value of a function
SEEK-TEST: Finished seek.ogv seek test 7
###!!! ASSERTION: Page read cursor should be inside range: 'mPageOffset <= endOffset', file /builds/slave/cen-osx64-dbg/build/content/media/ogg/nsOggReader.cpp, line 1510
nsOggReader::SeekBisection [content/media/ogg/nsOggReader.cpp:1512]
nsOggReader::SeekInBufferedRange [content/media/ogg/nsOggReader.cpp:1117]
nsOggReader::Seek [content/media/ogg/nsOggReader.cpp:1253]
nsBuiltinDecoderStateMachine::Run [content/media/nsBuiltinDecoderStateMachine.cpp:1095]
nsThread::ProcessNextEvent [xpcom/threads/nsThread.cpp:633]
NS_ProcessNextEvent_P [nsThreadUtils.cpp:250]
nsThread::ThreadFunc [xpcom/threads/nsThread.cpp:277]
_pt_root [nsprpub/pr/src/pthreads/ptthread.c:190]
libSystem.B.dylib + 0x3a536
###!!! ASSERTION: Guess should be differnt to previous: 'guess != previousGuess', file /builds/slave/cen-osx64-dbg/build/content/media/ogg/nsOggReader.cpp, line 1436
nsOggReader::SeekBisection [content/media/ogg/nsOggReader.cpp:1437]
nsOggReader::SeekInBufferedRange [content/media/ogg/nsOggReader.cpp:1117]
nsOggReader::Seek [content/media/ogg/nsOggReader.cpp:1253]
nsBuiltinDecoderStateMachine::Run [content/media/nsBuiltinDecoderStateMachine.cpp:1095]
nsThread::ProcessNextEvent [xpcom/threads/nsThread.cpp:633]
NS_ProcessNextEvent_P [nsThreadUtils.cpp:250]
nsThread::ThreadFunc [xpcom/threads/nsThread.cpp:277]
_pt_root [nsprpub/pr/src/pthreads/ptthread.c:190]
libSystem.B.dylib + 0x3a536
###!!! ASSERTION: Guess should be differnt to previous: 'guess != previousGuess', file /builds/slave/cen-osx64-dbg/build/content/media/ogg/nsOggReader.cpp, line 1436
nsOggReader::SeekBisection [content/media/ogg/nsOggReader.cpp:1437]
nsOggReader::SeekInBufferedRange [content/media/ogg/nsOggReader.cpp:1117]
nsOggReader::Seek [content/media/ogg/nsOggReader.cpp:1253]
nsBuiltinDecoderStateMachine::Run [content/media/nsBuiltinDecoderStateMachine.cpp:1095]
nsThread::ProcessNextEvent [xpcom/threads/nsThread.cpp:633]
NS_ProcessNextEvent_P [nsThreadUtils.cpp:250]
nsThread::ThreadFunc [xpcom/threads/nsThread.cpp:277]
_pt_root [nsprpub/pr/src/pthreads/ptthread.c:190]
libSystem.B.dylib + 0x3a536
###!!! ASSERTION: Guess should be differnt to previous: 'guess != previousGuess', file /builds/slave/cen-osx64-dbg/build/content/media/ogg/nsOggReader.cpp, line 1436
nsOggReader::SeekBisection [content/media/ogg/nsOggReader.cpp:1437]
nsOggReader::SeekInBufferedRange [content/media/ogg/nsOggReader.cpp:1117]
nsOggReader::Seek [content/media/ogg/nsOggReader.cpp:1253]
nsBuiltinDecoderStateMachine::Run [content/media/nsBuiltinDecoderStateMachine.cpp:1095]
nsThread::ProcessNextEvent [xpcom/threads/nsThread.cpp:633]
NS_ProcessNextEvent_P [nsThreadUtils.cpp:250]
nsThread::ThreadFunc [xpcom/threads/nsThread.cpp:277]
_pt_root [nsprpub/pr/src/pthreads/ptthread.c:190]
libSystem.B.dylib + 0x3a536
(Reporter)

Comment 1

6 years ago
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox4.0/1301759869.1301762491.9926.gz
Rev3 MacOSX Leopard 10.5.8 mozilla-2.0 debug test mochitests-1/5 on 2011/04/02 08:57:49
s: talos-r3-leopard-050
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox4.0/1302730835.1302733588.20688.gz
http://tinderbox.mozilla.org/showlog.cgi?log=Mozilla-Aurora/1304640123.1304643123.15791.gz
Rev3 MacOSX Snow Leopard 10.6.2 mozilla-aurora debug test mochitests-1/5
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1305330605.1305333740.1448.gz
Rev3 MacOSX Snow Leopard 10.6.2 mozilla-central debug test mochitests-1/5 on 2011/05/13 16:50:05
s: talos-r3-snow-029

BTW, at least on my system, this bug's tinderbox logs (like the one I'm adding here) tend to hang firefox builds, since they're so long :-/  This one is a 51-meg text file, and it makes my firefox build spend forever in nsBidiPresUtils::ReorderFrames and effectively hang.
(In reply to comment #4)
> BTW, at least on my system, this bug's tinderbox logs (like the one I'm adding
> here) tend to hang firefox builds, since they're so long :-/  This one is a
> 51-meg text file, and it makes my firefox build spend forever in
> nsBidiPresUtils::ReorderFrames and effectively hang.

You should file a bug about that, and CC smontagu.
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1306439354.1306443658.24219.gz&fulltext=1
http://tinderbox.mozilla.org/showlog.cgi?log=Places/1307017639.1307020667.5330.gz
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1307990333.1307992912.25969.gz&fulltext=1
http://tinderbox.mozilla.org/showlog.cgi?log=Mozilla-Inbound/1308151026.1308153992.16598.gz
(Reporter)

Comment 10

6 years ago
http://tinderbox.mozilla.org/showlog.cgi?log=Jaegermonkey/1308196896.1308200784.14429.gz
OS: Mac OS X → All
Hardware: x86_64 → All
http://tinderbox.mozilla.org/showlog.cgi?log=Try/1308351090.1308353915.12193.gz&fulltext=1

http://dev.philringnalda.com/tbpl/?tree=Try&rev=a03554955ed0
(Reporter)

Comment 12

6 years ago
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1309690757.1309694352.14690.gz
(Reporter)

Comment 13

6 years ago
http://tinderbox.mozilla.org/showlog.cgi?log=Mozilla-Inbound/1309730078.1309733672.20330.gz
(Reporter)

Comment 14

6 years ago
http://tinderbox.mozilla.org/showlog.cgi?log=Mozilla-Inbound/1309733792.1309737527.1427.gz
(Reporter)

Comment 15

6 years ago
http://tinderbox.mozilla.org/showlog.cgi?log=Mozilla-Inbound/1309728378.1309731913.13358.gz
(Reporter)

Comment 16

6 years ago
Oops, comment 12 through comment 15 aren't actually test_seek.html's entirely too frequent but intermittent hitting of it, they were bug 462959 making it happen at least once per push in its test_played.html. Backin' out.
(Assignee)

Updated

6 years ago
Assignee: nobody → chris
Status: NEW → ASSIGNED
(Assignee)

Comment 17

6 years ago
Created attachment 543733 [details] [diff] [review]
Patch 1

This patch stops the assertion "Must get a granuletime: 'granuleTime > 0'" at nsOggReader.cpp:1382 from firing. The problem is the seek timestamp code assumes that all ogg page with a non -1 granulepos are data pages. This is false, as header pages have a 0 granulepos. This confuses our timestamping code, and triggers the assertion.

This patch ensures that our seek timestamp decoding code assumes that data pages with a valid granulepos must have a granulepos > 0 (i.e. we no longer assume header pages with 0 granulepos are data pages!).
Attachment #543733 - Flags: review?(chris.double)
(Assignee)

Comment 18

6 years ago
Created attachment 543735 [details] [diff] [review]
Patch 2

When our seek bisection hits the end of data while trying to determine the timestamp at the end of a data range, it backs off from the end exponentially until it can determine a timestamp.

However if the range we're bisecting is narrowed to only include the end of the initial input range, and that is an incomplete page, we end up getting stuck in a loop backing off to before the start of the range, trying to read a page but failing and reaching the end of the range, so backing off to the start of the range, and so on, forever. We get stuck in a loop.

This patch breaks the out of loop by terminating bisection if we backoff to before the start of the narrowed range. The reason being if we were unable to find a timestamp for the end of the range, we may as well start decoding from the start of the range, since we can't continue to bisect.

This patch applies on top of Patch 1.
Attachment #543735 - Flags: review?(chris.double)
(Assignee)

Comment 19

6 years ago
We'll need to land this before we can re-land bug 462959, since its tests fail very frequently without this fix.
Blocks: 462959

Comment 20

6 years ago
Comment on attachment 543733 [details] [diff] [review]
Patch 1

Review of attachment 543733 [details] [diff] [review]:
-----------------------------------------------------------------
Attachment #543733 - Flags: review?(chris.double) → review+

Comment 21

6 years ago
Comment on attachment 543735 [details] [diff] [review]
Patch 2

Review of attachment 543735 [details] [diff] [review]:
-----------------------------------------------------------------
Attachment #543735 - Flags: review?(chris.double) → review+
(Assignee)

Comment 22

6 years ago
http://hg.mozilla.org/integration/mozilla-inbound/rev/4d17b74a1df2
http://hg.mozilla.org/integration/mozilla-inbound/rev/2b2d322e4241
Whiteboard: [orange][test which aborts the suite] → [orange][test which aborts the suite][inbound]
http://hg.mozilla.org/mozilla-central/rev/4d17b74a1df2
http://hg.mozilla.org/mozilla-central/rev/2b2d322e4241
Status: ASSIGNED → RESOLVED
Last Resolved: 6 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla8
Keywords: intermittent-failure
Whiteboard: [orange][test which aborts the suite][inbound] → [test which aborts the suite][inbound]
You need to log in before you can comment on or make changes to this bug.