Closed Bug 1075980 Opened 10 years ago Closed 10 years ago

Intermittent test_FrameSelection.html | videoWidth has incorrect final value - got 320, expected 160 | videoHeight has incorrect final value - got 240, expected 120 | application crashed [@ mozilla::WebMBufferedState::Release()]

Categories

(Core :: Audio/Video, defect)

defect
Not set
normal

Tracking

()

RESOLVED FIXED
mozilla35
Tracking Status
firefox33 --- unaffected
firefox34 --- unaffected
firefox35 --- fixed
firefox-esr31 --- unaffected

People

(Reporter: RyanVM, Assigned: kinetik)

References

(Blocks 1 open bug)

Details

(Keywords: crash, intermittent-failure)

Attachments

(1 file, 1 obsolete file)

+++ This bug was initially created as a clone of Bug #1064826 +++

https://tbpl.mozilla.org/php/getParsedLog.php?id=49307262&tree=Fx-Team

Windows 7 32-bit fx-team debug test mochitest-1 on 2014-10-01 07:49:11 PDT for push a68bd654661c
slave: t-w732-ix-107

08:06:09     INFO -  1660 INFO TEST-START | /tests/content/media/mediasource/test/test_FrameSelection.html
08:06:09     INFO -  ++DOMWINDOW == 117 (0C759A00) [pid = 1868] [serial = 3975] [outer = 17F4DA00]
08:06:09     INFO -  [Parent 1868] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80520012: file c:/builds/moz2_slave/fx-team-w32-d-0000000000000000/build/widget/windows/WinUtils.cpp, line 1330
08:06:09     INFO -  [Parent 1868] WARNING: NS_ENSURE_TRUE(selCon) failed: file c:\builds\moz2_slave\fx-team-w32-d-0000000000000000\build\editor\libeditor\nsEditor.cpp, line 609
08:06:09     INFO -  [Parent 1868] WARNING: NS_ENSURE_TRUE(selcon) failed: file c:\builds\moz2_slave\fx-team-w32-d-0000000000000000\build\editor\libeditor\nsEditor.cpp, line 631
08:06:09     INFO -  --DOMWINDOW == 116 (10DA5E00) [pid = 1868] [serial = 3893] [outer = 00000000] [url = http://mochi.test:8888/tests/content/html/document/test/bug499092.html]
08:06:09     INFO -  --DOMWINDOW == 115 (0CD86E00) [pid = 1868] [serial = 3891] [outer = 00000000] [url = http://mochi.test:8888/tests/content/html/document/test/bug499092.xml]
08:06:09     INFO -  --DOMWINDOW == 114 (138E5400) [pid = 1868] [serial = 3929] [outer = 00000000] [url = about:blank]
08:06:09     INFO -  --DOMWINDOW == 113 (131A2000) [pid = 1868] [serial = 3919] [outer = 00000000] [url = about:blank]
08:06:09     INFO -  --DOMWINDOW == 112 (18034000) [pid = 1868] [serial = 3920] [outer = 00000000] [url = about:blank]
08:06:09     INFO -  --DOMWINDOW == 111 (19CD3000) [pid = 1868] [serial = 3930] [outer = 00000000] [url = about:blank]
08:06:09     INFO -  Hit MOZ_CRASH(WebMBufferedState not thread-safe) at c:\builds\moz2_slave\fx-team-w32-d-0000000000000000\build\content\media\webm\WebMBufferedParser.h:219
08:06:09     INFO -  mozilla::WebMReader::~WebMReader() [content/media/webm/WebMReader.cpp:221]
08:06:09     INFO -  mozilla::MediaDecoderReader::Release() [content/media/MediaDecoderReader.h:32]
08:06:09     INFO -  mozilla::SourceBufferDecoder::~SourceBufferDecoder() [content/media/mediasource/SourceBufferDecoder.cpp:49]
08:06:09     INFO -  mozilla::SourceBufferDecoder::Release() [content/media/mediasource/SourceBufferDecoder.cpp:33]
08:06:09     INFO -  nsRunnableMethodReceiver<mozilla::TrackBuffer,nsRefPtr<mozilla::SourceBufferDecoder>,1>::~nsRunnableMethodReceiver<mozilla::TrackBuffer,nsRefPtr<mozilla::SourceBufferDecoder>,1>() [xpcom/glue/nsThreadUtils.h:282]
08:06:09     INFO -  nsRunnable::Release() [xpcom/glue/nsThreadUtils.cpp:32]
08:06:09     INFO -  mozilla::MediaTaskQueue::Runner::Run() [content/media/MediaTaskQueue.cpp:204]
08:06:09     INFO -  nsThreadPool::Run() [xpcom/threads/nsThreadPool.cpp:222]
08:06:09     INFO -  nsThread::ProcessNextEvent(bool,bool *) [xpcom/threads/nsThread.cpp:830]
08:06:09     INFO -  NS_ProcessNextEvent(nsIThread *,bool) [xpcom/glue/nsThreadUtils.cpp:265]
08:06:09     INFO -  mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate *) [ipc/glue/MessagePump.cpp:368]
08:06:09     INFO -  MessageLoop::RunInternal() [ipc/chromium/src/base/message_loop.cc:230]
08:06:09     INFO -  MessageLoop::RunHandler() [ipc/chromium/src/base/message_loop.cc:224]
08:06:09     INFO -  MessageLoop::Run() [ipc/chromium/src/base/message_loop.cc:198]
08:06:09     INFO -  nsThread::ThreadFunc(void *) [xpcom/threads/nsThread.cpp:359]
08:06:10     INFO -  _PR_NativeRunThread [nsprpub/pr/src/threads/combined/pruthr.c:397]
08:06:10     INFO -  pr_root [nsprpub/pr/src/md/windows/w95thred.c:90]
08:06:10     INFO -  MSVCR100 + 0x5c6de
08:06:10     INFO -  MSVCR100 + 0x5c788
08:06:10     INFO -  kernel32 + 0x53c45
08:06:10     INFO -  ntdll + 0x637f5
08:06:10     INFO -  ntdll + 0x637c8
08:06:11     INFO -  dumping last 6 message(s)
08:06:11     INFO -  if you need more context, please use SimpleTest.requestCompleteLog() in your test
08:06:11     INFO -  1661 INFO TEST-PASS | /tests/content/media/mediasource/test/test_FrameSelection.html | fetchWithXHR load uri='seek.webm' status=200
08:06:11     INFO -  1662 INFO TEST-PASS | /tests/content/media/mediasource/test/test_FrameSelection.html | currentTime has incorrect initial value
08:06:11     INFO -  1663 INFO TEST-PASS | /tests/content/media/mediasource/test/test_FrameSelection.html | videoWidth has incorrect initial value
08:06:11     INFO -  1664 INFO TEST-PASS | /tests/content/media/mediasource/test/test_FrameSelection.html | videoHeight has incorrect initial value
08:06:11     INFO -  1665 INFO TEST-PASS | /tests/content/media/mediasource/test/test_FrameSelection.html | fetchWithXHR load uri='seek_lowres.webm' status=200
08:06:11     INFO -  1666 INFO TEST-PASS | /tests/content/media/mediasource/test/test_FrameSelection.html | Video currentTime not at target
08:06:11     INFO -  1667 INFO TEST-UNEXPECTED-FAIL | /tests/content/media/mediasource/test/test_FrameSelection.html | videoWidth has incorrect final value - got 320, expected 160
08:06:11     INFO -  1668 INFO TEST-UNEXPECTED-FAIL | /tests/content/media/mediasource/test/test_FrameSelection.html | videoHeight has incorrect final value - got 240, expected 120
08:06:11     INFO -  TEST-INFO | Main app process: exit status 80000003
08:06:11     INFO -  1669 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/mediasource/test/test_FrameSelection.html | application terminated with exit code 2147483651
08:06:11     INFO -  runtests.py | Application ran for: 0:15:19.210000
08:06:11     INFO -  zombiecheck | Reading PID log: c:\users\cltbld\appdata\local\temp\tmplcpv5mpidlog
08:06:11     INFO -  ==> process 1868 launched child process 2628 ("C:\slave\test\build\application\firefox\plugin-container.exe" --channel=1868.ec2a140.137855627 "c:\users\cltbld\appdata\local\temp\tmpfk33jz.mozrunner\plugins\nptest.dll" -greomni "C:\slave\test\build\application\firefox\omni.ja" -appomni "C:\slave\test\build\application\firefox\browser\omni.ja" -appdir "C:\slave\test\build\application\firefox\browser" - 1868 "\\.\pipe\gecko-crash-server-pipe.1868" plugin)
08:06:11     INFO -  ==> process 1868 launched child process 3316 ("C:\slave\test\build\application\firefox\plugin-container.exe" --channel=1868.ca029c0.1008542962 -greomni "C:\slave\test\build\application\firefox\omni.ja" -appomni "C:\slave\test\build\application\firefox\browser\omni.ja" -appdir "C:\slave\test\build\application\firefox\browser"  1868 "\\.\pipe\gecko-crash-server-pipe.1868" tab)
08:06:11     INFO -  ==> process 1868 launched child process 2832 ("C:\slave\test\build\application\firefox\plugin-container.exe" --channel=1868.9b9dc00.1570382964 "c:\users\cltbld\appdata\local\temp\tmpfk33jz.mozrunner\plugins\nptest.dll" -greomni "C:\slave\test\build\application\firefox\omni.ja" -appomni "C:\slave\test\build\application\firefox\browser\omni.ja" -appdir "C:\slave\test\build\application\firefox\browser" - 1868 "\\.\pipe\gecko-crash-server-pipe.1868" plugin)
08:06:11     INFO -  ==> process 1868 launched child process 2200 ("C:\slave\test\build\application\firefox\plugin-container.exe" --channel=1868.9b9e740.350587401 "c:\users\cltbld\appdata\local\temp\tmpfk33jz.mozrunner\plugins\nptest.dll" -greomni "C:\slave\test\build\application\firefox\omni.ja" -appomni "C:\slave\test\build\application\firefox\browser\omni.ja" -appdir "C:\slave\test\build\application\firefox\browser" - 1868 "\\.\pipe\gecko-crash-server-pipe.1868" plugin)
08:06:11     INFO -  ==> process 1868 launched child process 2628 ("C:\slave\test\build\application\firefox\plugin-container.exe" --channel=1868.12f15840.1218829029 "c:\users\cltbld\appdata\local\temp\tmpfk33jz.mozrunner\plugins\nptest.dll" -greomni "C:\slave\test\build\application\firefox\omni.ja" -appomni "C:\slave\test\build\application\firefox\browser\omni.ja" -appdir "C:\slave\test\build\application\firefox\browser" - 1868 "\\.\pipe\gecko-crash-server-pipe.1868" plugin)
08:06:11     INFO -  ==> process 1868 launched child process 2012 ("C:\slave\test\build\application\firefox\plugin-container.exe" --channel=1868.9b9dfc0.544114789 "c:\users\cltbld\appdata\local\temp\tmpfk33jz.mozrunner\plugins\nptest.dll" -greomni "C:\slave\test\build\application\firefox\omni.ja" -appomni "C:\slave\test\build\application\firefox\browser\omni.ja" -appdir "C:\slave\test\build\application\firefox\browser" - 1868 "\\.\pipe\gecko-crash-server-pipe.1868" plugin)
08:06:20     INFO -  mozcrash Saved minidump as C:\slave\test\build\blobber_upload_dir\1f51bd7d-c34c-4861-9346-16e193e80017.dmp
08:06:20     INFO -  mozcrash Saved app info as C:\slave\test\build\blobber_upload_dir\1f51bd7d-c34c-4861-9346-16e193e80017.extra
08:06:20  WARNING -  PROCESS-CRASH | /tests/content/media/mediasource/test/test_FrameSelection.html | application crashed [@ mozilla::WebMBufferedState::Release()]
08:06:20     INFO -  Crash dump filename: c:\users\cltbld\appdata\local\temp\tmpfk33jz.mozrunner\minidumps\1f51bd7d-c34c-4861-9346-16e193e80017.dmp
08:06:20     INFO -  Operating system: Windows NT
08:06:20     INFO -                    6.1.7601 Service Pack 1
08:06:20     INFO -  CPU: x86
08:06:20     INFO -       GenuineIntel family 6 model 30 stepping 5
08:06:20     INFO -       8 CPUs
08:06:20     INFO -  Crash reason:  EXCEPTION_BREAKPOINT
08:06:20     INFO -  Crash address: 0x65b9b31d
08:06:20     INFO -  Thread 73 (crashed)
08:06:20     INFO -   0  xul.dll!mozilla::WebMBufferedState::Release() [WebMBufferedParser.h:a68bd654661c : 219 + 0x25]
08:06:20     INFO -      eip = 0x65b9b31d   esp = 0x0d4df58c   ebp = 0x0d4df598   ebx = 0x0180f140
08:06:20     INFO -      esi = 0x0c4049a0   edi = 0x62d91660   eax = 0x00000000   ecx = 0x67a7ff12
08:06:20     INFO -      edx = 0x76fb70b4   efl = 0x00000202
08:06:20     INFO -      Found by: given as instruction pointer in context
08:06:20     INFO -   1  xul.dll!mozilla::WebMReader::~WebMReader() [WebMReader.cpp:a68bd654661c : 221 + 0x12]
08:06:20     INFO -      eip = 0x65b9b8c5   esp = 0x0d4df5a0   ebp = 0x0d4df5b8
08:06:20     INFO -      Found by: call frame info
08:06:20     INFO -   2  xul.dll!mozilla::WebMReader::`vector deleting destructor'(unsigned int) + 0xa
08:06:20     INFO -      eip = 0x65b9c274   esp = 0x0d4df5b4   ebp = 0x0d4df5b8
08:06:20     INFO -      Found by: call frame info
08:06:20     INFO -   3  xul.dll!mozilla::MediaDecoderReader::Release() [MediaDecoderReader.h:a68bd654661c : 32 + 0x64]
08:06:20     INFO -      eip = 0x65b22802   esp = 0x0d4df5c0   ebp = 0x0d4df5cc
08:06:20     INFO -      Found by: call frame info
08:06:20     INFO -   4  xul.dll!mozilla::SourceBufferDecoder::~SourceBufferDecoder() [SourceBufferDecoder.cpp:a68bd654661c : 49 + 0xf]
08:06:20     INFO -      eip = 0x65b5baf9   esp = 0x0d4df5d4   ebp = 0x0d4df5e4
08:06:20     INFO -      Found by: call frame info
08:06:20     INFO -   5  xul.dll!mozilla::SourceBufferDecoder::`scalar deleting destructor'(unsigned int) + 0xa
08:06:20     INFO -      eip = 0x65b5d448   esp = 0x0d4df5e0   ebp = 0x0d4df5e4
08:06:20     INFO -      Found by: call frame info
08:06:20     INFO -   6  xul.dll!mozilla::SourceBufferDecoder::Release() [SourceBufferDecoder.cpp:a68bd654661c : 33 + 0x6f]
08:06:20     INFO -      eip = 0x65b5aba6   esp = 0x0d4df5ec   ebp = 0x0d4df5fc
08:06:20     INFO -      Found by: call frame info
08:06:20     INFO -   7  xul.dll!nsRunnableMethodReceiver<mozilla::TrackBuffer,nsRefPtr<mozilla::SourceBufferDecoder>,1>::~nsRunnableMethodReceiver<mozilla::TrackBuffer,nsRefPtr<mozilla::SourceBufferDecoder>,1>() [nsThreadUtils.h:a68bd654661c : 282 + 0x1e]
08:06:20     INFO -      eip = 0x65b5e946   esp = 0x0d4df604   ebp = 0x0d4df614
08:06:20     INFO -      Found by: call frame info
08:06:20     INFO -   8  xul.dll!nsRunnableMethodImpl<void ( mozilla::TrackBuffer::*)(nsRefPtr<mozilla::SourceBufferDecoder>),nsRefPtr<mozilla::SourceBufferDecoder>,1>::`scalar deleting destructor'(unsigned int) + 0xd
08:06:20     INFO -      eip = 0x65b5ee9b   esp = 0x0d4df610   ebp = 0x0d4df614
08:06:20     INFO -      Found by: call frame info
Blocks: MSE
It's possible for the event dispatched to the main thread by RemoveDecoder to execute before the event dispatched to the TrackBuffer task queue is destroyed.  Because the latter event holds a reference to the SourceBufferDecoder being removed, it's possible for the final Release to occur on the wrong thread.
Assignee: nobody → kinetik
Status: NEW → ASSIGNED
Attached patch bug1075980_v0.patch (obsolete) — Splinter Review
- Main fix: don't hold a reference to the SourceBufferDecoder in the nsIRunnable used to call InitializeDecoder
- Ensure mCurrentDecoder is cleared in RemoveDecoder if we are removing that decoder
- Pass a raw SourceBufferDecoder pointer into QueueInitializeDecoder, InitializeDecoder, RegisterDecoder, RemoveDecoder, and the single-decoder constructor for ReleaseDecoderTask to make ownership clearer
- Clear SourceBufferDecoder's task queue as soon as it's finished ReadMetadata, rather than doing it in multiple places slightly later
- Null mTaskQueue under the monitor (cleaner, doesn't matter for this issue)
- Also, fix some logically inverted messages in two tests

https://tbpl.mozilla.org/?tree=Try&rev=a15894bfff1b
Attachment #8498647 - Flags: review?(karlt)
(In reply to Matthew Gregan [:kinetik] from comment #4)
> It's possible for the event dispatched to the main thread by RemoveDecoder
> to execute before the event dispatched to the TrackBuffer task queue is
> destroyed.  Because the latter event holds a reference to the
> SourceBufferDecoder being removed, it's possible for the final Release to
> occur on the wrong thread.

Note: this bug becomes super obvious if you make RemoveDecoder's dispatch synchronous.
Comment on attachment 8498647 [details] [diff] [review]
bug1075980_v0.patch

> bool
>-TrackBuffer::QueueInitializeDecoder(nsRefPtr<SourceBufferDecoder> aDecoder)
>+TrackBuffer::QueueInitializeDecoder(SourceBufferDecoder* aDecoder)
> {
>+  mParentDecoder->GetReentrantMonitor().AssertCurrentThreadIn();
>   RefPtr<nsIRunnable> task =
>-    NS_NewRunnableMethodWithArg<nsRefPtr<SourceBufferDecoder>>(this,
>-                                                               &TrackBuffer::InitializeDecoder,
>-                                                               aDecoder);
>+    NS_NewRunnableMethodWithArg<SourceBufferDecoder*>(this,
>+                                                      &TrackBuffer::InitializeDecoder,
>+                                                      aDecoder);
>   aDecoder->SetTaskQueue(mTaskQueue);
>   if (NS_FAILED(mTaskQueue->Dispatch(task))) {
>     MSE_DEBUG("MediaSourceReader(%p): Failed to enqueue decoder initialization task", this);
>+    RemoveDecoder(aDecoder);
>     return false;
>   }
>   return true;
> }

Why must mParentDecoder->GetReentrantMonitor() be held here?

(In reply to Matthew Gregan [:kinetik] from comment #5)
> - Null mTaskQueue under the monitor (cleaner, doesn't matter for this issue)

>   mTaskQueue->Shutdown();
>-  mTaskQueue = nullptr;
> 
>   ReentrantMonitorAutoEnter mon(mParentDecoder->GetReentrantMonitor());
>+  mTaskQueue = nullptr;

Please leave this as it was.

mTaskQueue is set in the constructor and not changed until it is destroyed in
Shutdown() on the MDStateMachine mDecodeTaskQueue.  There is no need for it to
be destroyed with the monitor held, and it is better that it isn't;
~MediaTaskQueue or one of its members may do more things one day.

Everything else is good.
Attachment #8498647 - Flags: review?(karlt) → review-
Address review comments.
Attachment #8499323 - Flags: review?(karlt)
Attachment #8498647 - Attachment is obsolete: true
BTW I don't see any need for ref-counting of WebMBufferedState.
If removing that means that readers can be released on other threads, then that could simplify things.
(In reply to Karl Tomlinson (:karlt) from comment #13)
> BTW I don't see any need for ref-counting of WebMBufferedState.
> If removing that means that readers can be released on other threads, then
> that could simplify things.

http://mxr.mozilla.org/mozilla-central/source/content/media/webm/WebMReader.cpp#231
Attachment #8499323 - Flags: review?(karlt) → review+
https://hg.mozilla.org/mozilla-central/rev/d5eb688ed4a1
Status: ASSIGNED → RESOLVED
Closed: 10 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla35
You need to log in before you can comment on or make changes to this bug.