Closed Bug 1114682 Opened 5 years ago Closed 4 years ago

Intermittent test_eme_canvas_blocked.html | Assertion count 1 is greater than expected (ASSERTION: Range should end after start!: 'mStart < mEnd', file ../../dist/include/MediaResource.h, line 136)

Categories

(Core :: Audio/Video, defect)

x86
Linux
defect
Not set

Tracking

()

RESOLVED WORKSFORME

People

(Reporter: RyanVM, Assigned: ajones)

References

Details

(Keywords: assertion, intermittent-failure)

Attachments

(2 files)

Maybe from your recent work, Bobby?

06:38:22 INFO - 97 INFO TEST-START | dom/media/test/test_eme_canvas_blocked.html
06:38:22 INFO - ++DOMWINDOW == 18 (0x9946cc00) [pid = 2333] [serial = 134] [outer = 0x9b6d5e00]
06:38:22 INFO - -*-*- UserCustomizations (parent): document created: http://mochi.test:8888/tests/dom/media/test/test_eme_canvas_blocked.html
06:38:22 INFO - -*-*- UserCustomizations (parent): _injectInWindow
06:38:22 INFO - -*-*- UserCustomizations (parent): principal status: 0
06:38:22 INFO - [2333] WARNING: Silently denied access to property |results|: object is not safely Xrayable (@chrome://specialpowers/content/specialpowersAPI.js:289): file /builds/slave/fx-team-lx-d-00000000000000000/build/src/js/xpconnect/wrappers/XrayWrapper.cpp, line 191
06:38:22 INFO - [2333] WARNING: Silently denied access to property |results|: object is not safely Xrayable (@chrome://specialpowers/content/specialpowersAPI.js:290): file /builds/slave/fx-team-lx-d-00000000000000000/build/src/js/xpconnect/wrappers/XrayWrapper.cpp, line 191
06:38:22 INFO - I/SampleTable( 2333): There are reordered frames present.
06:38:22 INFO - E/MPEG4Extractor( 2333): No width or height, assuming worst case 1080p
06:38:22 INFO - [2950] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file /builds/slave/fx-team-lx-d-00000000000000000/build/src/xpcom/base/nsTraceRefcnt.cpp, line 143
06:38:22 INFO - [2950] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file /builds/slave/fx-team-lx-d-00000000000000000/build/src/xpcom/base/nsTraceRefcnt.cpp, line 143
06:38:22 INFO - [2950] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file /builds/slave/fx-team-lx-d-00000000000000000/build/src/xpcom/base/nsTraceRefcnt.cpp, line 143
06:38:22 INFO - [2950] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file /builds/slave/fx-team-lx-d-00000000000000000/build/src/xpcom/base/nsTraceRefcnt.cpp, line 143
06:38:22 INFO - [2950] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file /builds/slave/fx-team-lx-d-00000000000000000/build/src/xpcom/base/nsTraceRefcnt.cpp, line 143
06:38:22 INFO - ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpQKsAcS.mozrunner/runtests_leaks_geckomediaplugin_pid2950.log
06:38:22 INFO - [GMP 2950] WARNING: PreLoadSandboxVoucher can't find sandbox voucher file!: file /builds/slave/fx-team-lx-d-00000000000000000/build/src/dom/media/gmp/GMPChild.cpp, line 757
06:38:23 INFO - [2333] ###!!! ASSERTION: Range should end after start!: 'mStart < mEnd', file ../../dist/include/MediaResource.h, line 136
06:38:48 INFO - #01: mozilla::MediaByteRange::MediaByteRange(long long, long long) [dom/media/MediaResource.h:136]
06:38:48 INFO - #02: mp4_demuxer::MoofParser::BlockingReadNextMoof() [media/libstagefright/binding/MoofParser.cpp:84]
06:38:48 INFO - #03: mp4_demuxer::SampleIterator::Get() [media/libstagefright/binding/Index.cpp:146]
06:38:48 INFO - #04: mp4_demuxer::SampleIterator::GetNext() [media/libstagefright/binding/Index.cpp:89]
06:38:48 INFO - #05: mp4_demuxer::MP4Demuxer::DemuxAudioSample() [media/libstagefright/binding/mp4_demuxer.cpp:189]
06:38:48 INFO - #06: mozilla::MP4Reader::PopSample(mp4_demuxer::TrackType) [dom/media/fmp4/MP4Reader.cpp:637]
06:38:48 INFO - #07: mozilla::MP4Reader::Update(mp4_demuxer::TrackType) [dom/media/fmp4/MP4Reader.cpp:586]
06:38:48 INFO - #08: nsRunnableMethodImpl<void (mozilla::MP4Reader::*)(mp4_demuxer::TrackType), mp4_demuxer::TrackType, true>::Run() [xpcom/glue/nsThreadUtils.h:363]
06:38:48 INFO - #09: mozilla::MediaTaskQueue::Runner::Run() [mfbt/RefPtr.h:284]
06:38:48 INFO - #10: nsThreadPool::Run() [xpcom/threads/nsThreadPool.cpp:225]
06:38:48 INFO - #11: nsThread::ProcessNextEvent(bool, bool*) [xpcom/threads/nsThread.cpp:855]
06:38:48 INFO - #12: NS_ProcessNextEvent(nsIThread*, bool) [xpcom/glue/nsThreadUtils.cpp:265]
06:38:48 INFO - #13: mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate*) [ipc/glue/MessagePump.cpp:340]
06:38:48 INFO - #14: MessageLoop::RunInternal() [ipc/chromium/src/base/message_loop.cc:233]
06:38:48 INFO - #15: MessageLoop::Run() [ipc/chromium/src/base/message_loop.cc:508]
06:38:48 INFO - #16: nsThread::ThreadFunc(void*) [xpcom/threads/nsThread.cpp:358]
06:38:48 INFO - #17: _pt_root [nsprpub/pr/src/pthreads/ptthread.c:215]
06:38:48 INFO - #18: libpthread.so.0 + 0x6d4c
06:38:48 INFO - --DOMWINDOW == 17 (0x908e8400) [pid = 2333] [serial = 123] [outer = (nil)] [url = chrome://browser/content/browser.xul]
06:38:48 INFO - --DOMWINDOW == 16 (0x9dfd4e00) [pid = 2333] [serial = 127] [outer = (nil)] [url = about:blank]
06:38:48 INFO - --DOMWINDOW == 15 (0x908e9800) [pid = 2333] [serial = 124] [outer = (nil)] [url = about:blank]
06:38:48 INFO - --DOMWINDOW == 14 (0x9946a000) [pid = 2333] [serial = 122] [outer = (nil)] [url = http://mochi.test:8888/tests/dom/media/test/test_delay_load.html]
06:38:48 INFO - --DOMWINDOW == 13 (0x991fc200) [pid = 2333] [serial = 133] [outer = (nil)] [url = http://mochi.test:8888/tests/SimpleTest/iframe-between-tests.html]
06:38:48 INFO - --DOMWINDOW == 12 (0x9e4a7a00) [pid = 2333] [serial = 132] [outer = (nil)] [url = about:blank]
06:38:48 INFO - 98 INFO TEST-OK | dom/media/test/test_eme_canvas_blocked.html | took 3160ms
06:38:48 INFO - ###!!! [Child][OnMaybeDequeueOne] Error: Channel closing: too late to send/recv, messages will be lost
06:38:48 INFO - ++DOMWINDOW == 13 (0x99469e00) [pid = 2333] [serial = 135] [outer = 0x9b6d5e00]
06:38:48 INFO - -*-*- UserCustomizations (parent): document created: http://mochi.test:8888/tests/SimpleTest/iframe-between-tests.html
06:38:48 INFO - -*-*- UserCustomizations (parent): _injectInWindow
06:38:48 INFO - -*-*- UserCustomizations (parent): principal status: 0
06:38:48 INFO - 99 INFO TEST-UNEXPECTED-ERROR | dom/media/test/test_eme_canvas_blocked.html | Assertion count 1 is greater than expected range 0-0 assertions.
Flags: needinfo?(bobbyholley)
This looks like a bug in the moof parser. Any thoughts anthony?
Flags: needinfo?(bobbyholley) → needinfo?(ajones)
This is caused by not having a mutex. box.Range().mStart is actually equal to mOffset when we initialise box.mRange so it must be being modified elsewhere.
Flags: needinfo?(ajones)
(In reply to Anthony Jones (:kentuckyfriedtakahe, :k17e) from comment #11)
> This is caused by not having a mutex. box.Range().mStart is actually equal
> to mOffset when we initialise box.mRange so it must be being modified
> elsewhere.

If they are equal, then that would trip the assertion, because it asserts strict equality.
Flags: needinfo?(ajones)
(In reply to Bobby Holley (Busy with media, don't ask for DOM/JS/XPConnect things) from comment #23)
> (In reply to Anthony Jones (:kentuckyfriedtakahe, :k17e) from comment #11)
> > This is caused by not having a mutex. box.Range().mStart is actually equal
> > to mOffset when we initialise box.mRange so it must be being modified
> > elsewhere.
> 
> If they are equal, then that would trip the assertion, because it asserts
> strict equality.

What I was trying to say before was that if box.mRange is valid then the offending won't fail to assert unless mOffset is changed in the background. Given that we didn't fail when box.mRange was initialised, mOffset must have been modified behind our back.
I was hoping bug 1115749 would help. Looks like it didn't.
Flags: needinfo?(ajones)
Assignee: nobody → ajones
Status: NEW → ASSIGNED
The issue appears to be caused by the read in Box() unlocking the monitor and allowing mOffset to be updated.
This patch is asserting for me locally. I'm investigating.
Depends on: 1119456
Comment on attachment 8545408 [details] [diff] [review]
Fix MoofParser race condition that was causing an assert

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

We need bug 1119456 for this.
Attachment #8545408 - Flags: review?(bobbyholley) → review-
Inactive; closing (see bug 1180138).
Status: ASSIGNED → RESOLVED
Closed: 4 years ago
Resolution: --- → WORKSFORME
You need to log in before you can comment on or make changes to this bug.